[11:26:00.403] INFO: *** Welcome to pxar ***
[11:26:00.403] INFO: *** Today: 2016/09/30
[11:26:01.221] INFO: *** Version: v1.9.0-818-g96727
[11:26:01.222] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//dacParameters35_C15.dat
[11:26:01.222] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:26:01.222] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[11:26:01.222] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[11:26:01.293] INFO: clk: 4
[11:26:01.293] INFO: ctr: 4
[11:26:01.293] INFO: sda: 19
[11:26:01.293] INFO: tin: 9
[11:26:01.293] INFO: level: 15
[11:26:01.293] INFO: triggerdelay: 0
[11:26:01.293] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:26:01.293] INFO: Log level: INFO
[11:26:01.305] QUIET: Connection to board DTB_WREKRL opened.
[11:26:01.308] 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:
------------------------------------------------------
[11:26:01.311] INFO: RPC call hashes of host and DTB match: 398089610
[11:26:02.849] INFO: DUT info:
[11:26:02.849] INFO: The DUT currently contains the following objects:
[11:26:02.849] INFO: 2 TBM Cores tbm08c (2 ON)
[11:26:02.849] INFO: TBM Core alpha (0): 7 registers set
[11:26:02.849] INFO: TBM Core beta (1): 7 registers set
[11:26:02.849] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:26:02.849] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.849] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.849] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:02.850] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:26:03.253] INFO: enter 'restricted' command line mode
[11:26:03.253] INFO: enter test to run
[11:26:13.990] INFO: test: PixelAlive no parameter change
[11:26:13.990] INFO: running: pixelalive
[11:26:13.999] INFO: ----------------------------------------------------------------------
[11:26:13.999] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:26:13.999] INFO: ----------------------------------------------------------------------
[11:26:14.379] INFO: Expecting 41600 events.
[11:26:18.827] INFO: 41600 events read in total (3729ms).
[11:26:18.972] INFO: Test took 4930ms.
[11:26:18.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:19.262] INFO: PixTestAlive::aliveTest() done
[11:26:19.262] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[11:26:19.295] INFO: enter test to run
[11:26:22.494] INFO: test: timing no parameter change
[11:26:22.494] INFO: running: timing
[11:26:22.498] INFO: ######################################################################
[11:26:22.498] INFO: PixTestTiming::doTest()
[11:26:22.498] INFO: ######################################################################
[11:26:22.498] INFO: ----------------------------------------------------------------------
[11:26:22.498] INFO: PixTestTiming::TBMPhaseScan()
[11:26:22.498] INFO: ----------------------------------------------------------------------
[11:31:30.917] INFO: TBM Phase Settings: 208
[11:31:30.917] INFO: 400MHz Phase: 4
[11:31:30.917] INFO: 160MHz Phase: 6
[11:31:30.917] INFO: Functional Phase Area: 4
[11:31:30.921] INFO: Test took 308423 ms.
[11:31:30.921] INFO: PixTestTiming::TBMPhaseScan() done.
[11:31:30.921] INFO: ----------------------------------------------------------------------
[11:31:30.921] INFO: PixTestTiming::ROCDelayScan()
[11:31:30.921] INFO: ----------------------------------------------------------------------
[11:33:47.697] INFO: ROC Delay Settings: 219
[11:33:47.697] INFO: ROC Header-Trailer/Token Delay: 11
[11:33:47.697] INFO: ROC Port 0 Delay: 3
[11:33:47.697] INFO: ROC Port 1 Delay: 3
[11:33:47.697] INFO: Functional ROC Area: 3
[11:33:47.700] INFO: Test took 136779 ms.
[11:33:47.700] INFO: PixTestTiming::ROCDelayScan() done.
[11:33:47.700] INFO: ----------------------------------------------------------------------
[11:33:47.700] INFO: PixTestTiming::TimingTest()
[11:33:47.700] INFO: ----------------------------------------------------------------------
[11:34:03.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:18.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:33.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:48.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:03.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:18.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:33.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:48.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:03.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:18.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:19.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: Read back bit status: 1
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: Timings are good!
[11:36:19.291] INFO: ----------------------------------------------------------------------
[11:36:19.291] INFO: Test took 151591 ms.
[11:36:19.291] INFO: PixTestTiming::TimingTest() done.
[11:36:19.291] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:36:19.292] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:36:19.292] INFO: PixTestTiming::doTest took 596797 ms.
[11:36:19.292] INFO: PixTestTiming::doTest() done
[11:36:19.292] INFO: Write out TBMPhaseScan_0_V0
[11:36:19.292] INFO: Write out TBMPhaseScan_1_V0
[11:36:19.292] INFO: Write out CombinedTBMPhaseScan_V0
[11:36:19.293] INFO: Write out ROCDelayScan3_V0
[11:36:19.293] INFO: enter test to run
[11:37:17.642] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:37:17.642] INFO: running: highrate
[11:37:17.642] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:37:18.243] INFO: ----------------------------------------------------------------------
[11:37:18.243] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:37:18.243] INFO: ----------------------------------------------------------------------
[11:37:18.243] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:37:18.243] INFO: edge/corner pixel THR is adjusted
[11:37:18.243] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:37:19.201] INFO: Collecting data for 5 seconds...
[11:37:24.219] INFO: Done with hot pixel readout
[11:37:35.325] INFO: PixTest:: pg_setup set to default.
[11:37:35.325] INFO: 2 hot pixels found in step 0
[11:37:36.316] INFO: Collecting data for 5 seconds...
[11:37:41.335] INFO: Done with hot pixel readout
[11:37:52.783] INFO: PixTest:: pg_setup set to default.
[11:37:52.784] INFO: 0 hot pixels found in step 1
[11:37:52.820] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:37:52.824] INFO: PixTest::trimHotPixels() done
[11:37:52.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat
[11:37:52.830] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C1.dat
[11:37:52.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C2.dat
[11:37:52.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C3.dat
[11:37:52.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C4.dat
[11:37:52.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C5.dat
[11:37:52.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C6.dat
[11:37:52.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C7.dat
[11:37:52.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C8.dat
[11:37:52.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C9.dat
[11:37:52.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C10.dat
[11:37:52.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C11.dat
[11:37:52.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C12.dat
[11:37:52.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C13.dat
[11:37:52.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C14.dat
[11:37:52.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[11:37:52.938] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[11:37:52.949] INFO: enter test to run
[11:38:16.561] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:38:16.561] INFO: running: highrate
[11:38:16.566] INFO: ----------------------------------------------------------------------
[11:38:16.566] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:38:16.566] INFO: ----------------------------------------------------------------------
[11:38:16.566] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:38:16.566] INFO: edge/corner pixel THR is adjusted
[11:38:16.566] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:38:17.523] INFO: Collecting data for 1 seconds...
[11:38:18.527] INFO: Done with hot pixel readout
[11:38:22.465] INFO: PixTest:: pg_setup set to default.
[11:38:22.466] INFO: 0 hot pixels found in step 0
[11:38:22.472] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:38:22.558] INFO: PixTest::trimHotPixels() done
[11:38:22.558] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat
[11:38:22.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C1.dat
[11:38:22.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C2.dat
[11:38:22.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C3.dat
[11:38:22.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C4.dat
[11:38:22.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C5.dat
[11:38:22.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C6.dat
[11:38:22.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C7.dat
[11:38:22.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C8.dat
[11:38:22.609] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C9.dat
[11:38:22.614] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C10.dat
[11:38:22.620] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C11.dat
[11:38:22.625] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C12.dat
[11:38:22.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C13.dat
[11:38:22.636] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C14.dat
[11:38:22.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[11:38:22.648] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-28_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[11:38:22.657] INFO: enter test to run
[11:38:50.001] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:38:50.001] INFO: running: xray
[11:38:50.002] INFO: ----------------------------------------------------------------------
[11:38:50.002] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:38:50.002] INFO: ----------------------------------------------------------------------
[11:38:51.965] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:39:03.776] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:39:33.546] INFO: Resuming triggers.
[11:39:45.349] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:40:16.026] INFO: Resuming triggers.
[11:40:27.836] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:40:58.296] INFO: Resuming triggers.
[11:41:10.104] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:41:40.549] INFO: Resuming triggers.
[11:41:52.356] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[11:42:23.192] INFO: Resuming triggers.
[11:42:34.998] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[11:43:05.071] INFO: Resuming triggers.
[11:43:16.880] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[11:43:46.386] INFO: Resuming triggers.
[11:43:58.196] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:44:27.757] INFO: Resuming triggers.
[11:44:33.662] INFO: data taking finished, elapsed time: 100 seconds.
[11:44:48.798] INFO: PixTest:: pg_setup set to default.
[11:44:48.801] INFO: PixTestXray::doPhRun() done
[11:44:48.968] INFO: enter test to run
[11:45:19.527] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:45:19.527] INFO: running: xray
[11:45:19.528] INFO: ----------------------------------------------------------------------
[11:45:19.528] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:45:19.528] INFO: ----------------------------------------------------------------------
[11:45:20.492] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:45:27.552] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[11:45:58.376] INFO: Resuming triggers.
[11:46:05.436] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[11:46:36.115] INFO: Resuming triggers.
[11:46:43.173] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:47:13.860] INFO: Resuming triggers.
[11:47:20.922] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[11:47:51.530] INFO: Resuming triggers.
[11:47:58.588] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:48:29.032] INFO: Resuming triggers.
[11:48:36.092] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[11:49:06.482] INFO: Resuming triggers.
[11:49:13.547] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[11:49:44.372] INFO: Resuming triggers.
[11:49:51.439] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:50:22.409] INFO: Resuming triggers.
[11:50:29.473] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[11:51:00.316] INFO: Resuming triggers.
[11:51:07.378] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[11:51:38.137] INFO: Resuming triggers.
[11:51:45.204] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[11:52:16.274] INFO: Resuming triggers.
[11:52:23.340] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[11:52:54.270] INFO: Resuming triggers.
[11:53:01.332] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:53:33.700] INFO: Resuming triggers.
[11:53:40.759] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[11:54:11.244] INFO: Resuming triggers.
[11:54:12.726] INFO: data taking finished, elapsed time: 100 seconds.
[11:54:19.699] INFO: PixTest:: pg_setup set to default.
[11:54:19.702] INFO: PixTestXray::doPhRun() done
[11:54:19.856] INFO: enter test to run
[11:55:21.474] INFO: test: HighRate no parameter change
[11:55:21.475] INFO: running: highrate
[11:55:21.493] INFO: ----------------------------------------------------------------------
[11:55:21.493] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:55:21.493] INFO: ----------------------------------------------------------------------
[11:55:21.676] INFO: Expecting 768 events.
[11:55:22.828] INFO: 768 events read in total (437ms).
[11:55:22.828] INFO: Test took 1307ms.
[11:55:23.631] INFO: Expecting 41600 events.
[11:55:26.759] INFO: 41600 events read in total (2601ms).
[11:55:26.760] INFO: Test took 3911ms.
[11:55:26.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:27.525] INFO: Expecting 41600 events.
[11:55:30.715] INFO: 41600 events read in total (2664ms).
[11:55:30.716] INFO: Test took 3907ms.
[11:55:30.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:31.472] INFO: Expecting 41600 events.
[11:55:34.704] INFO: 41600 events read in total (2705ms).
[11:55:34.705] INFO: Test took 3940ms.
[11:55:34.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:35.464] INFO: Expecting 41600 events.
[11:55:38.722] INFO: 41600 events read in total (2731ms).
[11:55:38.723] INFO: Test took 3969ms.
[11:55:38.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:39.480] INFO: Expecting 41600 events.
[11:55:42.727] INFO: 41600 events read in total (2720ms).
[11:55:42.728] INFO: Test took 3955ms.
[11:55:42.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:43.475] INFO: Expecting 41600 events.
[11:55:46.773] INFO: 41600 events read in total (2771ms).
[11:55:46.774] INFO: Test took 3997ms.
[11:55:46.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:47.529] INFO: Expecting 41600 events.
[11:55:50.774] INFO: 41600 events read in total (2718ms).
[11:55:50.775] INFO: Test took 3951ms.
[11:55:50.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:51.534] INFO: Expecting 41600 events.
[11:55:54.791] INFO: 41600 events read in total (2730ms).
[11:55:54.792] INFO: Test took 3968ms.
[11:55:54.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:55.551] INFO: Expecting 41600 events.
[11:55:58.931] INFO: 41600 events read in total (2855ms).
[11:55:58.932] INFO: Test took 4090ms.
[11:55:58.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:59.682] INFO: Expecting 41600 events.
[11:56:02.951] INFO: 41600 events read in total (2742ms).
[11:56:02.951] INFO: Test took 3964ms.
[11:56:02.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:03.703] INFO: Expecting 41600 events.
[11:56:06.936] INFO: 41600 events read in total (2706ms).
[11:56:06.937] INFO: Test took 3936ms.
[11:56:06.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:07.697] INFO: Expecting 41600 events.
[11:56:10.917] INFO: 41600 events read in total (2694ms).
[11:56:10.918] INFO: Test took 3932ms.
[11:56:10.951] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:11.673] INFO: Expecting 41600 events.
[11:56:15.082] INFO: 41600 events read in total (2882ms).
[11:56:15.083] INFO: Test took 4115ms.
[11:56:15.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:15.839] INFO: Expecting 41600 events.
[11:56:19.054] INFO: 41600 events read in total (2688ms).
[11:56:19.055] INFO: Test took 3921ms.
[11:56:19.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:19.816] INFO: Expecting 41600 events.
[11:56:23.050] INFO: 41600 events read in total (2708ms).
[11:56:23.051] INFO: Test took 3947ms.
[11:56:23.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:23.809] INFO: Expecting 41600 events.
[11:56:27.050] INFO: 41600 events read in total (2714ms).
[11:56:27.051] INFO: Test took 3950ms.
[11:56:27.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:27.813] INFO: Expecting 41600 events.
[11:56:31.034] INFO: 41600 events read in total (2694ms).
[11:56:31.035] INFO: Test took 3933ms.
[11:56:31.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:31.795] INFO: Expecting 41600 events.
[11:56:35.014] INFO: 41600 events read in total (2692ms).
[11:56:35.015] INFO: Test took 3925ms.
[11:56:35.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:35.775] INFO: Expecting 41600 events.
[11:56:38.986] INFO: 41600 events read in total (2684ms).
[11:56:38.987] INFO: Test took 3921ms.
[11:56:39.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:39.747] INFO: Expecting 41600 events.
[11:56:42.790] INFO: 41600 events read in total (2517ms).
[11:56:42.791] INFO: Test took 3755ms.
[11:56:42.822] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:43.198] INFO: enter test to run
[11:56:51.426] INFO: test: HighRate no parameter change
[11:56:51.426] INFO: running: highrate
[11:56:51.427] INFO: ----------------------------------------------------------------------
[11:56:51.427] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:56:51.427] INFO: ----------------------------------------------------------------------
[11:56:52.059] INFO: Expecting 208000 events.
[11:57:03.848] INFO: 208000 events read in total (11262ms).
[11:57:03.851] INFO: Test took 12402ms.
[11:57:03.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:04.231] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[11:57:04.232] INFO: number of red-efficiency pixels: 79 41 72 116 131 118 92 63 106 126 150 89 91 66 24 25
[11:57:04.232] INFO: number of X-ray hits detected: 63745 40972 58758 88804 92437 99485 92175 65971 74804 98997 102539 81126 90025 54559 21093 23565
[11:57:04.232] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:57:04.232] INFO: number of Vcal hits detected: 207918 207958 207927 207881 207866 207879 207907 207936 207894 207872 207848 207909 207860 207934 207975 207975
[11:57:04.232] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:57:04.232] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[11:57:04.232] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.0 17.2 26.0 27.1 29.2 27.0 19.3 21.9 29.0 30.1 23.8 26.4 16.0 6.2 6.9
[11:57:04.232] INFO: PixTestHighRate::doXPixelAlive() done
[11:57:04.282] INFO: PixTest:: pg_setup set to default.
[11:57:04.292] INFO: enter test to run
[11:57:37.385] INFO: test: HighRate no parameter change
[11:57:37.385] INFO: running: highrate
[11:57:37.387] INFO: ----------------------------------------------------------------------
[11:57:37.387] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:57:37.387] INFO: ----------------------------------------------------------------------
[11:57:37.003] INFO: Expecting 208000 events.
[11:57:51.337] INFO: 208000 events read in total (12807ms).
[11:57:51.342] INFO: Test took 13947ms.
[11:57:51.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:51.913] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[11:57:51.913] INFO: number of red-efficiency pixels: 212 122 155 268 391 392 291 218 286 316 480 316 329 239 67 66
[11:57:51.913] INFO: number of X-ray hits detected: 131178 84538 120364 183761 191746 205492 191049 135409 154734 203815 212524 168402 187015 111994 44323 49129
[11:57:51.913] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:57:51.913] INFO: number of Vcal hits detected: 207772 207876 207831 207707 207577 207573 207692 207775 207699 207669 207480 207669 207583 207741 207933 207932
[11:57:51.914] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.9 99.8 99.9 99.8 99.9 100.0 100.0
[11:57:51.914] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:57:51.914] INFO: X-ray hit rate [MHz/cm2]: 38.4 24.8 35.3 53.9 56.2 60.2 56.0 39.7 45.4 59.7 62.3 49.4 54.8 32.8 13.0 14.4
[11:57:51.914] INFO: PixTestHighRate::doXPixelAlive() done
[11:57:51.961] INFO: PixTest:: pg_setup set to default.
[11:57:51.977] INFO: enter test to run
[11:58:13.849] INFO: test: HighRate no parameter change
[11:58:13.849] INFO: running: highrate
[11:58:13.850] INFO: ----------------------------------------------------------------------
[11:58:13.850] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:58:13.850] INFO: ----------------------------------------------------------------------
[11:58:14.469] INFO: Expecting 208000 events.
[11:58:29.534] INFO: 208000 events read in total (14538ms).
[11:58:29.541] INFO: Test took 15680ms.
[11:58:29.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:30.280] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[11:58:30.280] INFO: number of red-efficiency pixels: 506 258 411 592 866 890 704 482 607 761 1116 746 762 496 111 97
[11:58:30.280] INFO: number of X-ray hits detected: 197204 126946 181508 276753 288069 308552 286558 204098 233331 307436 318995 255244 280439 169536 67408 73916
[11:58:30.280] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:58:30.280] INFO: number of Vcal hits detected: 207410 207726 207517 207319 206977 206917 207177 207442 207310 207115 206587 207137 207081 207405 207885 207900
[11:58:30.280] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.7 99.6 99.5 99.6 99.8 99.7 99.6 99.4 99.6 99.6 99.7 99.9 100.0
[11:58:30.280] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.7 99.5 99.5 99.6 99.7 99.7 99.6 99.3 99.6 99.6 99.7 99.9 100.0
[11:58:30.280] INFO: X-ray hit rate [MHz/cm2]: 57.8 37.2 53.2 81.1 84.4 90.4 84.0 59.8 68.4 90.1 93.5 74.8 82.2 49.7 19.8 21.7
[11:58:30.280] INFO: PixTestHighRate::doXPixelAlive() done
[11:58:30.328] INFO: PixTest:: pg_setup set to default.
[11:58:30.343] INFO: enter test to run
[11:59:12.481] INFO: test: exit no parameter change
[11:59:12.949] QUIET: Connection to board 33 closed.
[11:59:13.040] INFO: pXar: this is the end, my friend