[15:32:08.367] INFO: *** Welcome to pxar ***
[15:32:08.367] INFO: *** Today: 2016/07/11
[15:32:08.384] INFO: *** Version: v1.9.0-814-g7497
[15:32:08.384] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//dacParameters35_C15.dat
[15:32:08.385] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:32:08.386] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[15:32:08.386] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[15:32:08.460] INFO: clk: 4
[15:32:08.460] INFO: ctr: 4
[15:32:08.460] INFO: sda: 19
[15:32:08.460] INFO: tin: 9
[15:32:08.460] INFO: level: 15
[15:32:08.460] INFO: triggerdelay: 0
[15:32:08.460] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:32:08.460] INFO: Log level: INFO
[15:32:08.479] QUIET: Connection to board DTB_WREKRL opened.
[15:32:08.482] 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:
------------------------------------------------------
[15:32:08.485] INFO: RPC call hashes of host and DTB match: 398089610
[15:32:10.020] INFO: DUT info:
[15:32:10.020] INFO: The DUT currently contains the following objects:
[15:32:10.020] INFO: 2 TBM Cores tbm08c (2 ON)
[15:32:10.020] INFO: TBM Core alpha (0): 7 registers set
[15:32:10.020] INFO: TBM Core beta (1): 7 registers set
[15:32:10.020] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:32:10.020] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.020] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.021] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:32:10.424] INFO: enter 'restricted' command line mode
[15:32:10.424] INFO: enter test to run
[15:32:11.489] INFO: test: timing no parameter change
[15:32:11.489] INFO: running: timing
[15:32:11.498] INFO: ######################################################################
[15:32:11.498] INFO: PixTestTiming::doTest()
[15:32:11.498] INFO: ######################################################################
[15:32:11.499] INFO: ----------------------------------------------------------------------
[15:32:11.499] INFO: PixTestTiming::TBMPhaseScan()
[15:32:11.499] INFO: ----------------------------------------------------------------------
[15:38:39.267] INFO: TBM Phase Settings: 240
[15:38:39.267] INFO: 400MHz Phase: 4
[15:38:39.267] INFO: 160MHz Phase: 7
[15:38:39.267] INFO: Functional Phase Area: 4
[15:38:39.270] INFO: Test took 387772 ms.
[15:38:39.270] INFO: PixTestTiming::TBMPhaseScan() done.
[15:38:39.270] INFO: ----------------------------------------------------------------------
[15:38:39.270] INFO: PixTestTiming::ROCDelayScan()
[15:38:39.270] INFO: ----------------------------------------------------------------------
[15:42:04.483] INFO: ROC Delay Settings: 228
[15:42:04.483] INFO: ROC Header-Trailer/Token Delay: 11
[15:42:04.483] INFO: ROC Port 0 Delay: 4
[15:42:04.483] INFO: ROC Port 1 Delay: 4
[15:42:04.483] INFO: Functional ROC Area: 5
[15:42:04.486] INFO: Test took 205216 ms.
[15:42:04.486] INFO: PixTestTiming::ROCDelayScan() done.
[15:42:04.487] INFO: ----------------------------------------------------------------------
[15:42:04.487] INFO: PixTestTiming::TimingTest()
[15:42:04.487] INFO: ----------------------------------------------------------------------
[15:42:20.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:35.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:50.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:05.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:20.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:35.479] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:50.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:05.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:20.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:35.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:35.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: Read back bit status: 1
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: Timings are good!
[15:44:35.722] INFO: ----------------------------------------------------------------------
[15:44:35.722] INFO: Test took 151235 ms.
[15:44:35.722] INFO: PixTestTiming::TimingTest() done.
[15:44:35.722] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:44:35.722] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:44:35.722] INFO: PixTestTiming::doTest took 744228 ms.
[15:44:35.722] INFO: PixTestTiming::doTest() done
[15:44:35.722] INFO: Write out TBMPhaseScan_0_V0
[15:44:35.749] INFO: Write out TBMPhaseScan_1_V0
[15:44:35.749] INFO: Write out CombinedTBMPhaseScan_V0
[15:44:35.749] INFO: Write out ROCDelayScan3_V0
[15:44:35.750] INFO: enter test to run
[15:44:40.405] INFO: test: PixelAlive no parameter change
[15:44:40.405] INFO: running: pixelalive
[15:44:40.409] INFO: ----------------------------------------------------------------------
[15:44:40.409] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:44:40.409] INFO: ----------------------------------------------------------------------
[15:44:40.726] INFO: Expecting 41600 events.
[15:44:45.062] INFO: 41600 events read in total (3620ms).
[15:44:45.063] INFO: Test took 4651ms.
[15:44:45.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:45.472] INFO: PixTestAlive::aliveTest() done
[15:44:45.473] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:44:45.476] INFO: enter test to run
[15:45:16.588] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:45:16.588] INFO: running: highrate
[15:45:16.589] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:45:16.741] INFO: ----------------------------------------------------------------------
[15:45:16.741] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:45:16.741] INFO: ----------------------------------------------------------------------
[15:45:16.741] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:45:16.741] INFO: edge/corner pixel THR is adjusted
[15:45:16.741] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:45:17.700] INFO: Collecting data for 5 seconds...
[15:45:22.716] INFO: Done with hot pixel readout
[15:45:34.115] INFO: PixTest:: pg_setup set to default.
[15:45:34.116] INFO: 0 hot pixels found in step 0
[15:45:34.147] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:45:34.150] INFO: PixTest::trimHotPixels() done
[15:45:34.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat
[15:45:34.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C1.dat
[15:45:34.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C2.dat
[15:45:34.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C3.dat
[15:45:34.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C4.dat
[15:45:34.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C5.dat
[15:45:34.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C6.dat
[15:45:34.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C7.dat
[15:45:34.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C8.dat
[15:45:34.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C9.dat
[15:45:34.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C10.dat
[15:45:34.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C11.dat
[15:45:34.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C12.dat
[15:45:34.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C13.dat
[15:45:34.225] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C14.dat
[15:45:34.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[15:45:34.236] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[15:45:34.246] INFO: enter test to run
[15:45:51.484] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:45:51.484] INFO: running: highrate
[15:45:51.488] INFO: ----------------------------------------------------------------------
[15:45:51.488] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:45:51.488] INFO: ----------------------------------------------------------------------
[15:45:51.489] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:45:51.489] INFO: edge/corner pixel THR is adjusted
[15:45:51.489] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:45:52.446] INFO: Collecting data for 1 seconds...
[15:45:53.450] INFO: Done with hot pixel readout
[15:45:57.171] INFO: PixTest:: pg_setup set to default.
[15:45:57.172] INFO: 0 hot pixels found in step 0
[15:45:57.177] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:45:57.277] INFO: PixTest::trimHotPixels() done
[15:45:57.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat
[15:45:57.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C1.dat
[15:45:57.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C2.dat
[15:45:57.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C3.dat
[15:45:57.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C4.dat
[15:45:57.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C5.dat
[15:45:57.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C6.dat
[15:45:57.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C7.dat
[15:45:57.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C8.dat
[15:45:57.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C9.dat
[15:45:57.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C10.dat
[15:45:57.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C11.dat
[15:45:57.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C12.dat
[15:45:57.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C13.dat
[15:45:57.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C14.dat
[15:45:57.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[15:45:57.368] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-18_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[15:45:57.377] INFO: enter test to run
[15:46:26.996] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:46:26.996] INFO: running: xray
[15:46:26.998] INFO: ----------------------------------------------------------------------
[15:46:26.998] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:46:26.998] INFO: ----------------------------------------------------------------------
[15:46:27.961] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:46:39.899] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:47:09.130] INFO: Resuming triggers.
[15:47:21.074] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:47:50.386] INFO: Resuming triggers.
[15:48:02.328] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:48:31.576] INFO: Resuming triggers.
[15:48:43.521] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:49:12.750] INFO: Resuming triggers.
[15:49:24.693] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:49:53.900] INFO: Resuming triggers.
[15:50:05.846] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:50:35.057] INFO: Resuming triggers.
[15:50:47.005] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:51:16.290] INFO: Resuming triggers.
[15:51:28.235] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:51:57.493] INFO: Resuming triggers.
[15:52:02.276] INFO: data taking finished, elapsed time: 100 seconds.
[15:52:14.300] INFO: PixTest:: pg_setup set to default.
[15:52:14.304] INFO: PixTestXray::doPhRun() done
[15:52:14.439] INFO: enter test to run
[15:52:38.177] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:52:38.177] INFO: running: xray
[15:52:38.179] INFO: ----------------------------------------------------------------------
[15:52:38.179] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:52:38.179] INFO: ----------------------------------------------------------------------
[15:52:39.142] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:52:46.477] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:53:16.689] INFO: Resuming triggers.
[15:53:24.025] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[15:53:54.127] INFO: Resuming triggers.
[15:54:01.457] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:54:31.560] INFO: Resuming triggers.
[15:54:38.892] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[15:55:09.059] INFO: Resuming triggers.
[15:55:16.394] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:55:46.591] INFO: Resuming triggers.
[15:55:53.922] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:56:24.082] INFO: Resuming triggers.
[15:56:31.412] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:57:01.514] INFO: Resuming triggers.
[15:57:08.845] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:57:38.971] INFO: Resuming triggers.
[15:57:46.309] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:58:16.435] INFO: Resuming triggers.
[15:58:23.768] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:58:53.925] INFO: Resuming triggers.
[15:59:01.262] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:59:31.468] INFO: Resuming triggers.
[15:59:38.803] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:00:09.013] INFO: Resuming triggers.
[16:00:16.350] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:00:46.378] INFO: Resuming triggers.
[16:00:51.366] INFO: data taking finished, elapsed time: 100 seconds.
[16:01:12.151] INFO: PixTest:: pg_setup set to default.
[16:01:12.154] INFO: PixTestXray::doPhRun() done
[16:01:12.301] INFO: enter test to run
[16:01:31.310] INFO: test: HighRate no parameter change
[16:01:31.310] INFO: running: highrate
[16:01:31.311] INFO: ----------------------------------------------------------------------
[16:01:31.311] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:01:31.311] INFO: ----------------------------------------------------------------------
[16:01:31.452] INFO: Expecting 768 events.
[16:01:32.586] INFO: 768 events read in total (418ms).
[16:01:32.587] INFO: Test took 1269ms.
[16:01:33.390] INFO: Expecting 41600 events.
[16:01:36.449] INFO: 41600 events read in total (2532ms).
[16:01:36.450] INFO: Test took 3855ms.
[16:01:36.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:37.212] INFO: Expecting 41600 events.
[16:01:40.375] INFO: 41600 events read in total (2637ms).
[16:01:40.376] INFO: Test took 3879ms.
[16:01:40.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:41.137] INFO: Expecting 41600 events.
[16:01:44.352] INFO: 41600 events read in total (2689ms).
[16:01:44.352] INFO: Test took 3928ms.
[16:01:44.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:45.117] INFO: Expecting 41600 events.
[16:01:48.308] INFO: 41600 events read in total (2664ms).
[16:01:48.309] INFO: Test took 3909ms.
[16:01:48.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:49.068] INFO: Expecting 41600 events.
[16:01:52.272] INFO: 41600 events read in total (2677ms).
[16:01:52.273] INFO: Test took 3916ms.
[16:01:52.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:53.037] INFO: Expecting 41600 events.
[16:01:56.242] INFO: 41600 events read in total (2678ms).
[16:01:56.243] INFO: Test took 3923ms.
[16:01:56.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:57.006] INFO: Expecting 41600 events.
[16:02:00.211] INFO: 41600 events read in total (2678ms).
[16:02:00.212] INFO: Test took 3921ms.
[16:02:00.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:00.970] INFO: Expecting 41600 events.
[16:02:04.173] INFO: 41600 events read in total (2676ms).
[16:02:04.174] INFO: Test took 3914ms.
[16:02:04.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:04.935] INFO: Expecting 41600 events.
[16:02:08.134] INFO: 41600 events read in total (2672ms).
[16:02:08.135] INFO: Test took 3914ms.
[16:02:08.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:08.898] INFO: Expecting 41600 events.
[16:02:12.103] INFO: 41600 events read in total (2678ms).
[16:02:12.104] INFO: Test took 3922ms.
[16:02:12.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:12.862] INFO: Expecting 41600 events.
[16:02:16.065] INFO: 41600 events read in total (2676ms).
[16:02:16.066] INFO: Test took 3915ms.
[16:02:16.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:16.827] INFO: Expecting 41600 events.
[16:02:20.047] INFO: 41600 events read in total (2693ms).
[16:02:20.048] INFO: Test took 3935ms.
[16:02:20.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:20.806] INFO: Expecting 41600 events.
[16:02:24.019] INFO: 41600 events read in total (2686ms).
[16:02:24.020] INFO: Test took 3924ms.
[16:02:24.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:24.778] INFO: Expecting 41600 events.
[16:02:27.979] INFO: 41600 events read in total (2674ms).
[16:02:27.980] INFO: Test took 3912ms.
[16:02:28.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:28.738] INFO: Expecting 41600 events.
[16:02:31.929] INFO: 41600 events read in total (2664ms).
[16:02:31.930] INFO: Test took 3901ms.
[16:02:31.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:32.689] INFO: Expecting 41600 events.
[16:02:35.900] INFO: 41600 events read in total (2684ms).
[16:02:35.901] INFO: Test took 3922ms.
[16:02:35.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:36.660] INFO: Expecting 41600 events.
[16:02:39.864] INFO: 41600 events read in total (2677ms).
[16:02:39.865] INFO: Test took 3917ms.
[16:02:39.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:40.629] INFO: Expecting 41600 events.
[16:02:43.834] INFO: 41600 events read in total (2678ms).
[16:02:43.835] INFO: Test took 3921ms.
[16:02:43.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:44.598] INFO: Expecting 41600 events.
[16:02:47.794] INFO: 41600 events read in total (2669ms).
[16:02:47.795] INFO: Test took 3913ms.
[16:02:47.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:48.557] INFO: Expecting 41600 events.
[16:02:51.610] INFO: 41600 events read in total (2526ms).
[16:02:51.611] INFO: Test took 3770ms.
[16:02:51.641] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:52.017] INFO: enter test to run
[16:02:57.909] INFO: test: HighRate no parameter change
[16:02:57.909] INFO: running: highrate
[16:02:57.910] INFO: ----------------------------------------------------------------------
[16:02:57.911] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:57.911] INFO: ----------------------------------------------------------------------
[16:02:58.521] INFO: Expecting 208000 events.
[16:03:10.146] INFO: 208000 events read in total (11098ms).
[16:03:10.148] INFO: Test took 12231ms.
[16:03:10.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:10.519] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:03:10.520] INFO: number of red-efficiency pixels: 48 35 49 89 85 109 101 76 93 136 133 94 89 50 18 24
[16:03:10.520] INFO: number of X-ray hits detected: 53587 33842 52374 82602 84853 95782 94300 71882 79985 98047 98839 78615 81328 48815 18447 20360
[16:03:10.520] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:03:10.520] INFO: number of Vcal hits detected: 207952 207965 207950 207909 207914 207890 207898 207921 207905 207861 207864 207905 207910 207950 207982 207976
[16:03:10.520] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[16:03:10.520] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[16:03:10.520] INFO: X-ray hit rate [MHz/cm2]: 15.7 9.9 15.4 24.2 24.9 28.1 27.6 21.1 23.4 28.7 29.0 23.0 23.8 14.3 5.4 6.0
[16:03:10.520] INFO: PixTestHighRate::doXPixelAlive() done
[16:03:10.567] INFO: PixTest:: pg_setup set to default.
[16:03:10.584] INFO: enter test to run
[16:03:32.541] INFO: test: HighRate no parameter change
[16:03:32.541] INFO: running: highrate
[16:03:32.542] INFO: ----------------------------------------------------------------------
[16:03:32.542] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:03:32.542] INFO: ----------------------------------------------------------------------
[16:03:33.155] INFO: Expecting 208000 events.
[16:03:46.280] INFO: 208000 events read in total (12598ms).
[16:03:46.285] INFO: Test took 13733ms.
[16:03:46.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:46.836] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:03:46.836] INFO: number of red-efficiency pixels: 147 100 179 315 252 375 365 199 265 443 415 276 210 160 46 53
[16:03:46.836] INFO: number of X-ray hits detected: 111166 69938 107419 170875 174389 198283 195235 147664 165759 203185 205007 162997 170026 101033 38787 42038
[16:03:46.836] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:03:46.836] INFO: number of Vcal hits detected: 207846 207897 207812 207665 207735 207587 207613 207791 207712 207529 207553 207710 207782 207830 207953 207946
[16:03:46.836] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:03:46.836] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:03:46.836] INFO: X-ray hit rate [MHz/cm2]: 32.6 20.5 31.5 50.1 51.1 58.1 57.2 43.3 48.6 59.6 60.1 47.8 49.8 29.6 11.4 12.3
[16:03:46.836] INFO: PixTestHighRate::doXPixelAlive() done
[16:03:46.886] INFO: PixTest:: pg_setup set to default.
[16:03:46.901] INFO: enter test to run
[16:04:05.261] INFO: test: HighRate no parameter change
[16:04:05.261] INFO: running: highrate
[16:04:05.262] INFO: ----------------------------------------------------------------------
[16:04:05.262] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:04:05.262] INFO: ----------------------------------------------------------------------
[16:04:05.876] INFO: Expecting 208000 events.
[16:04:20.567] INFO: 208000 events read in total (14164ms).
[16:04:20.573] INFO: Test took 15301ms.
[16:04:20.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:21.282] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:04:21.282] INFO: number of red-efficiency pixels: 269 192 376 628 557 875 806 405 613 873 907 631 481 361 85 91
[16:04:21.282] INFO: number of X-ray hits detected: 163498 104085 159828 253621 259269 293276 288022 218949 245865 300608 302961 241609 249836 149861 57678 62865
[16:04:21.282] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:04:21.282] INFO: number of Vcal hits detected: 207713 207793 207573 207294 207392 206964 207074 207556 207300 206961 206909 207276 207453 207580 207909 207909
[16:04:21.282] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.5 99.6 99.8 99.7 99.6 99.5 99.7 99.8 99.8 100.0 100.0
[16:04:21.282] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.5 99.6 99.8 99.7 99.5 99.5 99.7 99.7 99.8 100.0 100.0
[16:04:21.282] INFO: X-ray hit rate [MHz/cm2]: 47.9 30.5 46.8 74.3 76.0 86.0 84.4 64.2 72.1 88.1 88.8 70.8 73.2 43.9 16.9 18.4
[16:04:21.282] INFO: PixTestHighRate::doXPixelAlive() done
[16:04:21.331] INFO: PixTest:: pg_setup set to default.
[16:04:21.344] INFO: enter test to run
[16:04:41.180] INFO: test: exit no parameter change
[16:04:41.632] QUIET: Connection to board 33 closed.
[16:04:41.633] INFO: pXar: this is the end, my friend