[14:18:46.651] INFO: *** Welcome to pxar ***
[14:18:46.652] INFO: *** Today: 2016/05/27
[14:18:46.673] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:18:46.673] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//dacParameters35_C15.dat
[14:18:46.674] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:18:46.674] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[14:18:46.675] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[14:18:46.745] INFO: clk: 4
[14:18:46.745] INFO: ctr: 4
[14:18:46.745] INFO: sda: 19
[14:18:46.745] INFO: tin: 9
[14:18:46.745] INFO: level: 15
[14:18:46.745] INFO: triggerdelay: 0
[14:18:46.745] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:18:46.745] INFO: Log level: INFO
[14:18:46.763] QUIET: Connection to board DTB_WREKRL opened.
[14:18:46.766] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:18:46.769] INFO: RPC call hashes of host and DTB match: 398089610
[14:18:48.299] INFO: DUT info:
[14:18:48.299] INFO: The DUT currently contains the following objects:
[14:18:48.299] INFO: 2 TBM Cores tbm08c (2 ON)
[14:18:48.300] INFO: TBM Core alpha (0): 7 registers set
[14:18:48.300] INFO: TBM Core beta (1): 7 registers set
[14:18:48.300] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:18:48.300] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.300] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:48.704] INFO: enter 'restricted' command line mode
[14:18:48.704] INFO: enter test to run
[14:18:49.944] INFO: test: timing no parameter change
[14:18:49.944] INFO: running: timing
[14:18:49.978] INFO: ######################################################################
[14:18:49.978] INFO: PixTestTiming::doTest()
[14:18:49.982] INFO: ######################################################################
[14:18:49.982] INFO: ----------------------------------------------------------------------
[14:18:49.982] INFO: PixTestTiming::TBMPhaseScan()
[14:18:49.982] INFO: ----------------------------------------------------------------------
[14:24:43.491] INFO: TBM Phase Settings: 228
[14:24:43.491] INFO: 400MHz Phase: 1
[14:24:43.491] INFO: 160MHz Phase: 7
[14:24:43.491] INFO: Functional Phase Area: 4
[14:24:43.500] INFO: Test took 353518 ms.
[14:24:43.500] INFO: PixTestTiming::TBMPhaseScan() done.
[14:24:43.501] INFO: ----------------------------------------------------------------------
[14:24:43.501] INFO: PixTestTiming::ROCDelayScan()
[14:24:43.501] INFO: ----------------------------------------------------------------------
[14:27:41.467] INFO: ROC Delay Settings: 228
[14:27:41.468] INFO: ROC Header-Trailer/Token Delay: 11
[14:27:41.468] INFO: ROC Port 0 Delay: 4
[14:27:41.468] INFO: ROC Port 1 Delay: 4
[14:27:41.468] INFO: Functional ROC Area: 5
[14:27:41.471] INFO: Test took 177970 ms.
[14:27:41.471] INFO: PixTestTiming::ROCDelayScan() done.
[14:27:41.471] INFO: ----------------------------------------------------------------------
[14:27:41.471] INFO: PixTestTiming::TimingTest()
[14:27:41.471] INFO: ----------------------------------------------------------------------
[14:27:57.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:12.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:27.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:42.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:57.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:12.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:27.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:42.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:57.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:12.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:12.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: Read back bit status: 1
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: Timings are good!
[14:30:12.980] INFO: ----------------------------------------------------------------------
[14:30:12.980] INFO: Test took 151509 ms.
[14:30:12.980] INFO: PixTestTiming::TimingTest() done.
[14:30:12.990] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:30:12.990] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:30:12.990] INFO: PixTestTiming::doTest took 683017 ms.
[14:30:12.990] INFO: PixTestTiming::doTest() done
[14:30:12.991] INFO: Write out TBMPhaseScan_0_V0
[14:30:13.016] INFO: Write out TBMPhaseScan_1_V0
[14:30:13.016] INFO: Write out CombinedTBMPhaseScan_V0
[14:30:13.036] INFO: Write out ROCDelayScan3_V0
[14:30:13.037] INFO: enter test to run
[14:30:58.811] INFO: test: PixelAlive no parameter change
[14:30:58.811] INFO: running: pixelalive
[14:30:58.815] INFO: ----------------------------------------------------------------------
[14:30:58.815] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:30:58.815] INFO: ----------------------------------------------------------------------
[14:30:59.133] INFO: Expecting 41600 events.
[14:31:03.458] INFO: 41600 events read in total (3609ms).
[14:31:03.459] INFO: Test took 4640ms.
[14:31:03.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:03.862] INFO: PixTestAlive::aliveTest() done
[14:31:03.862] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0
[14:31:03.866] INFO: enter test to run
[14:31:34.058] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:31:34.059] INFO: running: highrate
[14:31:34.059] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:31:34.211] INFO: ----------------------------------------------------------------------
[14:31:34.211] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:31:34.211] INFO: ----------------------------------------------------------------------
[14:31:34.211] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:31:34.211] INFO: edge/corner pixel THR is adjusted
[14:31:34.211] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:31:35.170] INFO: Collecting data for 5 seconds...
[14:31:40.188] INFO: Done with hot pixel readout
[14:31:51.938] INFO: PixTest:: pg_setup set to default.
[14:31:51.939] INFO: 3 hot pixels found in step 0
[14:31:52.932] INFO: Collecting data for 5 seconds...
[14:31:57.950] INFO: Done with hot pixel readout
[14:32:09.742] INFO: PixTest:: pg_setup set to default.
[14:32:09.742] INFO: 2 hot pixels found in step 1
[14:32:10.735] INFO: Collecting data for 5 seconds...
[14:32:15.753] INFO: Done with hot pixel readout
[14:32:27.538] INFO: PixTest:: pg_setup set to default.


[14:32:27.539] INFO: 7 hot pixels found in step 2
[14:32:28.531] INFO: Collecting data for 5 seconds...
[14:32:33.548] INFO: Done with hot pixel readout
[14:32:45.359] INFO: PixTest:: pg_setup set to default.


[14:32:45.359] INFO: 6 hot pixels found in step 3
[14:32:46.353] INFO: Collecting data for 5 seconds...
[14:32:51.371] INFO: Done with hot pixel readout
[14:33:03.114] INFO: PixTest:: pg_setup set to default.



[14:33:03.115] INFO: 4 hot pixels found in step 4
[14:33:04.107] INFO: Collecting data for 5 seconds...
[14:33:09.125] INFO: Done with hot pixel readout
[14:33:20.912] INFO: PixTest:: pg_setup set to default.

[14:33:20.913] INFO: 2 hot pixels found in step 5
[14:33:21.905] INFO: Collecting data for 5 seconds...
[14:33:26.923] INFO: Done with hot pixel readout
[14:33:38.723] INFO: PixTest:: pg_setup set to default.


[14:33:38.724] INFO: 7 hot pixels found in step 6
[14:33:39.717] INFO: Collecting data for 5 seconds...
[14:33:44.735] INFO: Done with hot pixel readout
[14:33:56.507] INFO: PixTest:: pg_setup set to default.

[14:33:56.508] INFO: 3 hot pixels found in step 7
[14:33:57.500] INFO: Collecting data for 5 seconds...
[14:34:02.519] INFO: Done with hot pixel readout
[14:34:14.251] INFO: PixTest:: pg_setup set to default.



[14:34:14.252] INFO: 4 hot pixels found in step 8
[14:34:15.244] INFO: Collecting data for 5 seconds...
[14:34:20.262] INFO: Done with hot pixel readout
[14:34:32.024] INFO: PixTest:: pg_setup set to default.
[14:34:32.025] INFO: 0 hot pixels found in step 9
[14:34:32.062] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:34:32.065] INFO: PixTest::trimHotPixels() done
[14:34:32.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat
[14:34:32.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C1.dat
[14:34:32.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C2.dat
[14:34:32.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C3.dat
[14:34:32.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C4.dat
[14:34:32.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C5.dat
[14:34:32.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C6.dat
[14:34:32.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C7.dat
[14:34:32.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C8.dat
[14:34:32.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C9.dat
[14:34:32.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C10.dat
[14:34:32.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C11.dat
[14:34:32.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C12.dat
[14:34:32.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C13.dat
[14:34:32.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C14.dat
[14:34:32.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:32.151] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:32.161] INFO: enter test to run
[14:34:52.105] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:34:52.105] INFO: running: highrate
[14:34:52.109] INFO: ----------------------------------------------------------------------
[14:34:52.109] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:34:52.109] INFO: ----------------------------------------------------------------------
[14:34:52.109] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:34:52.109] INFO: edge/corner pixel THR is adjusted
[14:34:52.109] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:34:53.067] INFO: Collecting data for 1 seconds...
[14:34:54.071] INFO: Done with hot pixel readout
[14:34:58.080] INFO: PixTest:: pg_setup set to default.
[14:34:58.081] INFO: 0 hot pixels found in step 0
[14:34:58.086] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:34:58.177] INFO: PixTest::trimHotPixels() done
[14:34:58.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat
[14:34:58.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C1.dat
[14:34:58.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C2.dat
[14:34:58.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C3.dat
[14:34:58.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C4.dat
[14:34:58.211] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C5.dat
[14:34:58.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C6.dat
[14:34:58.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C7.dat
[14:34:58.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C8.dat
[14:34:58.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C9.dat
[14:34:58.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C10.dat
[14:34:58.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C11.dat
[14:34:58.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C12.dat
[14:34:58.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C13.dat
[14:34:58.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C14.dat
[14:34:58.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:58.268] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-18_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:58.277] INFO: enter test to run
[14:36:26.248] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:36:26.248] INFO: running: xray
[14:36:26.250] INFO: ----------------------------------------------------------------------
[14:36:26.250] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:36:26.250] INFO: ----------------------------------------------------------------------
[14:36:27.212] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:36:38.624] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:37:07.988] INFO: Resuming triggers.
[14:37:19.404] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:37:48.374] INFO: Resuming triggers.
[14:37:59.789] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:38:29.826] INFO: Resuming triggers.
[14:38:41.240] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:39:11.303] INFO: Resuming triggers.
[14:39:22.714] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:39:52.081] INFO: Resuming triggers.
[14:40:03.494] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:40:32.520] INFO: Resuming triggers.
[14:40:43.936] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:41:13.393] INFO: Resuming triggers.
[14:41:24.812] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:41:54.065] INFO: Resuming triggers.
[14:42:03.114] INFO: data taking finished, elapsed time: 100 seconds.
[14:42:26.596] INFO: PixTest:: pg_setup set to default.
[14:42:26.599] INFO: PixTestXray::doPhRun() done
[14:42:26.734] INFO: enter test to run
[14:44:13.037] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:44:13.037] INFO: running: xray
[14:44:13.038] INFO: ----------------------------------------------------------------------
[14:44:13.038] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:44:13.038] INFO: ----------------------------------------------------------------------
[14:44:14.011] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:44:20.645] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:44:50.761] INFO: Resuming triggers.
[14:44:57.413] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:45:27.471] INFO: Resuming triggers.
[14:45:34.121] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:46:04.316] INFO: Resuming triggers.
[14:46:10.967] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:46:41.102] INFO: Resuming triggers.
[14:46:47.753] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:47:17.923] INFO: Resuming triggers.
[14:47:24.572] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:47:55.396] INFO: Resuming triggers.
[14:48:02.046] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:48:32.861] INFO: Resuming triggers.
[14:48:39.511] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:49:10.329] INFO: Resuming triggers.
[14:49:16.978] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:49:47.952] INFO: Resuming triggers.
[14:49:54.602] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:50:25.242] INFO: Resuming triggers.
[14:50:31.892] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:51:02.014] INFO: Resuming triggers.
[14:51:08.667] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:51:38.751] INFO: Resuming triggers.
[14:51:45.399] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:52:15.960] INFO: Resuming triggers.
[14:52:22.610] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:52:52.591] INFO: Resuming triggers.
[14:52:59.243] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:53:29.225] INFO: Resuming triggers.
[14:53:29.844] INFO: data taking finished, elapsed time: 100 seconds.
[14:53:32.997] INFO: PixTest:: pg_setup set to default.
[14:53:32.000] INFO: PixTestXray::doPhRun() done
[14:53:33.150] INFO: enter test to run
[14:54:45.880] INFO: test: HighRate no parameter change
[14:54:45.880] INFO: running: highrate
[14:54:45.899] INFO: ----------------------------------------------------------------------
[14:54:45.899] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:54:45.899] INFO: ----------------------------------------------------------------------
[14:54:46.039] INFO: Expecting 768 events.
[14:54:47.173] INFO: 768 events read in total (418ms).
[14:54:47.174] INFO: Test took 1269ms.
[14:54:47.977] INFO: Expecting 41600 events.
[14:54:51.092] INFO: 41600 events read in total (2588ms).
[14:54:51.093] INFO: Test took 3911ms.
[14:54:51.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:51.853] INFO: Expecting 41600 events.
[14:54:55.066] INFO: 41600 events read in total (2686ms).
[14:54:55.067] INFO: Test took 3924ms.
[14:54:55.102] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:55.824] INFO: Expecting 41600 events.
[14:54:59.050] INFO: 41600 events read in total (2699ms).
[14:54:59.051] INFO: Test took 3931ms.
[14:54:59.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:59.806] INFO: Expecting 41600 events.
[14:55:03.046] INFO: 41600 events read in total (2713ms).
[14:55:03.047] INFO: Test took 3944ms.
[14:55:03.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:03.802] INFO: Expecting 41600 events.
[14:55:07.044] INFO: 41600 events read in total (2715ms).
[14:55:07.045] INFO: Test took 3946ms.
[14:55:07.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:07.804] INFO: Expecting 41600 events.
[14:55:11.050] INFO: 41600 events read in total (2720ms).
[14:55:11.051] INFO: Test took 3953ms.
[14:55:11.087] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:11.808] INFO: Expecting 41600 events.
[14:55:15.050] INFO: 41600 events read in total (2716ms).
[14:55:15.051] INFO: Test took 3946ms.
[14:55:15.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:15.807] INFO: Expecting 41600 events.
[14:55:19.067] INFO: 41600 events read in total (2733ms).
[14:55:19.068] INFO: Test took 3962ms.
[14:55:19.102] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:19.824] INFO: Expecting 41600 events.
[14:55:22.910] INFO: 41600 events read in total (2559ms).
[14:55:22.911] INFO: Test took 3790ms.
[14:55:22.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:23.669] INFO: Expecting 41600 events.
[14:55:26.907] INFO: 41600 events read in total (2711ms).
[14:55:26.908] INFO: Test took 3943ms.
[14:55:26.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:27.668] INFO: Expecting 41600 events.
[14:55:30.913] INFO: 41600 events read in total (2718ms).
[14:55:30.914] INFO: Test took 3953ms.
[14:55:30.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:31.673] INFO: Expecting 41600 events.
[14:55:34.917] INFO: 41600 events read in total (2717ms).
[14:55:34.918] INFO: Test took 3952ms.
[14:55:34.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:35.673] INFO: Expecting 41600 events.
[14:55:38.905] INFO: 41600 events read in total (2705ms).
[14:55:38.906] INFO: Test took 3935ms.
[14:55:38.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:39.665] INFO: Expecting 41600 events.
[14:55:42.926] INFO: 41600 events read in total (2734ms).
[14:55:42.927] INFO: Test took 3968ms.
[14:55:42.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:43.687] INFO: Expecting 41600 events.
[14:55:46.943] INFO: 41600 events read in total (2729ms).
[14:55:46.944] INFO: Test took 3963ms.
[14:55:46.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:47.700] INFO: Expecting 41600 events.
[14:55:50.966] INFO: 41600 events read in total (2740ms).
[14:55:50.967] INFO: Test took 3970ms.
[14:55:51.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:51.726] INFO: Expecting 41600 events.
[14:55:54.963] INFO: 41600 events read in total (2710ms).
[14:55:54.964] INFO: Test took 3944ms.
[14:55:54.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:55.724] INFO: Expecting 41600 events.
[14:55:58.979] INFO: 41600 events read in total (2728ms).
[14:55:58.980] INFO: Test took 3964ms.
[14:55:59.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:59.736] INFO: Expecting 41600 events.
[14:56:02.917] INFO: 41600 events read in total (2654ms).
[14:56:02.918] INFO: Test took 3885ms.
[14:56:02.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:03.678] INFO: Expecting 41600 events.
[14:56:06.729] INFO: 41600 events read in total (2525ms).
[14:56:06.730] INFO: Test took 3759ms.
[14:56:06.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:07.127] INFO: enter test to run
[14:56:32.111] INFO: test: HighRate no parameter change
[14:56:32.112] INFO: running: highrate
[14:56:32.113] INFO: ----------------------------------------------------------------------
[14:56:32.113] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:56:32.113] INFO: ----------------------------------------------------------------------
[14:56:32.730] INFO: Expecting 208000 events.
[14:56:44.597] INFO: 208000 events read in total (11341ms).
[14:56:44.600] INFO: Test took 12479ms.
[14:56:44.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:45.002] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0
[14:56:45.003] INFO: number of red-efficiency pixels: 69 52 90 180 123 125 127 92 99 171 102 95 110 54 29 25
[14:56:45.003] INFO: number of X-ray hits detected: 66831 46824 66861 109364 111565 106450 102701 81040 83425 105453 103479 90812 94729 53315 23730 26370
[14:56:45.003] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:56:45.003] INFO: number of Vcal hits detected: 207931 207947 207910 207817 207876 207872 207870 207905 207901 207824 207846 207853 207887 207944 207970 207975
[14:56:45.003] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[14:56:45.003] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:56:45.003] INFO: X-ray hit rate [MHz/cm2]: 19.6 13.7 19.6 32.1 32.7 31.2 30.1 23.8 24.5 30.9 30.3 26.6 27.8 15.6 7.0 7.7
[14:56:45.003] INFO: PixTestHighRate::doXPixelAlive() done
[14:56:45.048] INFO: PixTest:: pg_setup set to default.
[14:56:45.063] INFO: enter test to run
[14:57:54.727] INFO: test: HighRate no parameter change
[14:57:54.727] INFO: running: highrate
[14:57:54.728] INFO: ----------------------------------------------------------------------
[14:57:54.728] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:57:54.728] INFO: ----------------------------------------------------------------------
[14:57:55.347] INFO: Expecting 208000 events.
[14:58:08.948] INFO: 208000 events read in total (13074ms).
[14:58:08.954] INFO: Test took 14218ms.
[14:58:09.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:09.556] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0
[14:58:09.556] INFO: number of red-efficiency pixels: 194 139 289 493 454 343 414 313 311 466 354 332 294 152 56 74
[14:58:09.556] INFO: number of X-ray hits detected: 134893 95378 136072 220935 224949 215990 207626 163865 168896 212940 208021 184131 192452 109453 49062 53568
[14:58:09.556] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:58:09.556] INFO: number of Vcal hits detected: 207797 207856 207675 207460 207515 207633 207538 207662 207672 207496 207565 207597 207691 207837 207941 207925
[14:58:09.556] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:58:09.556] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:58:09.556] INFO: X-ray hit rate [MHz/cm2]: 39.5 28.0 39.9 64.8 65.9 63.3 60.9 48.0 49.5 62.4 61.0 54.0 56.4 32.1 14.4 15.7
[14:58:09.556] INFO: PixTestHighRate::doXPixelAlive() done
[14:58:09.605] INFO: PixTest:: pg_setup set to default.
[14:58:09.618] INFO: enter test to run
[14:58:29.231] INFO: test: HighRate no parameter change
[14:58:29.231] INFO: running: highrate
[14:58:29.232] INFO: ----------------------------------------------------------------------
[14:58:29.232] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:58:29.232] INFO: ----------------------------------------------------------------------
[14:58:29.850] INFO: Expecting 208000 events.
[14:58:45.513] INFO: 208000 events read in total (15136ms).
[14:58:45.521] INFO: Test took 16281ms.
[14:58:45.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:46.331] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0
[14:58:46.331] INFO: number of red-efficiency pixels: 393 297 640 1187 1030 751 956 664 661 1050 786 771 646 307 92 104
[14:58:46.331] INFO: number of X-ray hits detected: 202768 144064 204932 333419 337425 325941 313362 247299 254181 319688 313935 277767 289799 164137 73488 81598
[14:58:46.331] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:58:46.331] INFO: number of Vcal hits detected: 207571 207683 207186 206525 206746 207132 206850 207218 207252 206705 207029 207039 207277 207660 207903 207895
[14:58:46.331] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.5 99.6 99.5 99.7 99.7 99.4 99.6 99.6 99.7 99.8 100.0 100.0
[14:58:46.331] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.6 99.3 99.4 99.6 99.4 99.6 99.6 99.4 99.5 99.5 99.7 99.8 100.0 99.9
[14:58:46.331] INFO: X-ray hit rate [MHz/cm2]: 59.4 42.2 60.1 97.7 98.9 95.5 91.8 72.5 74.5 93.7 92.0 81.4 84.9 48.1 21.5 23.9
[14:58:46.331] INFO: PixTestHighRate::doXPixelAlive() done
[14:58:46.379] INFO: PixTest:: pg_setup set to default.
[14:58:46.390] INFO: enter test to run
[14:58:56.806] INFO: test: exit no parameter change
[14:58:57.204] QUIET: Connection to board 33 closed.
[14:58:57.205] INFO: pXar: this is the end, my friend