[14:34:55.744] INFO: *** Welcome to pxar ***
[14:34:55.744] INFO: *** Today: 2016/10/05
[14:34:56.059] INFO: *** Version: v1.9.0-818-g96727
[14:34:56.059] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//dacParameters35_C15.dat
[14:34:56.083] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:34:56.083] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:56.089] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:56.174] INFO: clk: 4
[14:34:56.174] INFO: ctr: 4
[14:34:56.174] INFO: sda: 19
[14:34:56.175] INFO: tin: 9
[14:34:56.175] INFO: level: 15
[14:34:56.175] INFO: triggerdelay: 0
[14:34:56.175] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:34:56.175] INFO: Log level: INFO
[14:34:56.194] QUIET: Connection to board DTB_WREKRL opened.
[14:34:56.197] 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:34:56.200] INFO: RPC call hashes of host and DTB match: 398089610
[14:34:57.732] INFO: DUT info:
[14:34:57.732] INFO: The DUT currently contains the following objects:
[14:34:57.732] INFO: 2 TBM Cores tbm08c (2 ON)
[14:34:57.732] INFO: TBM Core alpha (0): 7 registers set
[14:34:57.732] INFO: TBM Core beta (1): 7 registers set
[14:34:57.732] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:34:57.732] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.732] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.732] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:57.733] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:58.136] INFO: enter 'restricted' command line mode
[14:34:58.137] INFO: enter test to run
[14:35:07.093] INFO: test: PixelAlive no parameter change
[14:35:07.093] INFO: running: pixelalive
[14:35:07.102] INFO: ----------------------------------------------------------------------
[14:35:07.102] 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:35:07.102] INFO: ----------------------------------------------------------------------
[14:35:07.423] INFO: Expecting 41600 events.
[14:35:11.753] INFO: 41600 events read in total (3612ms).
[14:35:11.922] INFO: Test took 4816ms.
[14:35:11.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:12.428] INFO: PixTestAlive::aliveTest() done
[14:35:12.428] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:35:12.486] INFO: enter test to run
[14:35:18.548] INFO: test: timing no parameter change
[14:35:18.549] INFO: running: timing
[14:35:18.552] INFO: ######################################################################
[14:35:18.552] INFO: PixTestTiming::doTest()
[14:35:18.552] INFO: ######################################################################
[14:35:18.552] INFO: ----------------------------------------------------------------------
[14:35:18.552] INFO: PixTestTiming::TBMPhaseScan()
[14:35:18.552] INFO: ----------------------------------------------------------------------
[14:41:06.654] INFO: TBM Phase Settings: 192
[14:41:06.654] INFO: 400MHz Phase: 0
[14:41:06.654] INFO: 160MHz Phase: 6
[14:41:06.654] INFO: Functional Phase Area: 4
[14:41:06.657] INFO: Test took 348105 ms.
[14:41:06.657] INFO: PixTestTiming::TBMPhaseScan() done.
[14:41:06.657] INFO: ----------------------------------------------------------------------
[14:41:06.657] INFO: PixTestTiming::ROCDelayScan()
[14:41:06.658] INFO: ----------------------------------------------------------------------
[14:43:06.758] INFO: ROC Delay Settings: 220
[14:43:06.758] INFO: ROC Header-Trailer/Token Delay: 11
[14:43:06.758] INFO: ROC Port 0 Delay: 4
[14:43:06.758] INFO: ROC Port 1 Delay: 3
[14:43:06.758] INFO: Functional ROC Area: 4
[14:43:06.761] INFO: Test took 120104 ms.
[14:43:06.761] INFO: PixTestTiming::ROCDelayScan() done.
[14:43:06.762] INFO: ----------------------------------------------------------------------
[14:43:06.762] INFO: PixTestTiming::TimingTest()
[14:43:06.762] INFO: ----------------------------------------------------------------------
[14:43:22.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:37.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:52.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:07.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:22.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:37.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:52.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:07.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:22.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:37.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:37.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: Read back bit status: 1
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: Timings are good!
[14:45:37.947] INFO: ----------------------------------------------------------------------
[14:45:37.947] INFO: Test took 151186 ms.
[14:45:37.947] INFO: PixTestTiming::TimingTest() done.
[14:45:37.947] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:45:37.948] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:45:37.948] INFO: PixTestTiming::doTest took 619399 ms.
[14:45:37.948] INFO: PixTestTiming::doTest() done
[14:45:37.948] INFO: Write out TBMPhaseScan_0_V0
[14:45:37.948] INFO: Write out TBMPhaseScan_1_V0
[14:45:37.948] INFO: Write out CombinedTBMPhaseScan_V0
[14:45:37.949] INFO: Write out ROCDelayScan3_V0
[14:45:37.949] INFO: enter test to run
[14:49:36.359] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:49:36.359] INFO: running: highrate
[14:49:36.359] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:49:36.565] INFO: ----------------------------------------------------------------------
[14:49:36.565] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:49:36.565] INFO: ----------------------------------------------------------------------
[14:49:36.565] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:49:36.565] INFO: edge/corner pixel THR is adjusted
[14:49:36.566] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:49:37.525] INFO: Collecting data for 5 seconds...
[14:49:42.541] INFO: Done with hot pixel readout
[14:49:53.958] INFO: PixTest:: pg_setup set to default.
[14:49:53.959] INFO: 1 hot pixels found in step 0
[14:49:54.950] INFO: Collecting data for 5 seconds...
[14:49:59.966] INFO: Done with hot pixel readout
[14:50:11.170] INFO: PixTest:: pg_setup set to default.
[14:50:11.171] INFO: 1 hot pixels found in step 1
[14:50:12.163] INFO: Collecting data for 5 seconds...
[14:50:17.179] INFO: Done with hot pixel readout
[14:50:28.507] INFO: PixTest:: pg_setup set to default.

[14:50:28.508] INFO: 3 hot pixels found in step 2
[14:50:29.500] INFO: Collecting data for 5 seconds...
[14:50:34.516] INFO: Done with hot pixel readout
[14:50:45.881] INFO: PixTest:: pg_setup set to default.
[14:50:45.881] INFO: 0 hot pixels found in step 3
[14:50:45.916] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:50:45.919] INFO: PixTest::trimHotPixels() done
[14:50:45.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat
[14:50:45.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C1.dat
[14:50:45.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C2.dat
[14:50:45.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C3.dat
[14:50:45.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C4.dat
[14:50:45.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C5.dat
[14:50:45.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C6.dat
[14:50:45.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C7.dat
[14:50:45.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C8.dat
[14:50:45.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C9.dat
[14:50:45.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C10.dat
[14:50:45.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C11.dat
[14:50:45.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C12.dat
[14:50:45.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C13.dat
[14:50:45.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C14.dat
[14:50:45.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[14:50:45.005] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[14:50:46.016] INFO: enter test to run
[14:56:31.828] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:56:31.828] INFO: running: highrate
[14:56:31.832] INFO: ----------------------------------------------------------------------
[14:56:31.832] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:56:31.832] INFO: ----------------------------------------------------------------------
[14:56:31.832] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:56:31.832] INFO: edge/corner pixel THR is adjusted
[14:56:31.832] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:56:32.790] INFO: Collecting data for 1 seconds...
[14:56:33.794] INFO: Done with hot pixel readout
[14:56:37.560] INFO: PixTest:: pg_setup set to default.
[14:56:37.561] INFO: 0 hot pixels found in step 0
[14:56:37.567] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:56:37.656] INFO: PixTest::trimHotPixels() done
[14:56:37.656] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C0.dat
[14:56:37.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C1.dat
[14:56:37.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C2.dat
[14:56:37.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C3.dat
[14:56:37.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C4.dat
[14:56:37.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C5.dat
[14:56:37.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C6.dat
[14:56:37.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C7.dat
[14:56:37.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C8.dat
[14:56:37.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C9.dat
[14:56:37.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C10.dat
[14:56:37.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C11.dat
[14:56:37.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C12.dat
[14:56:37.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C13.dat
[14:56:37.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C14.dat
[14:56:37.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//trimParameters35_C15.dat
[14:56:37.748] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-19_FPIXTest-17C-FNAL-160927-1236-150V_2016-09-27_12h36m_1474997785/000_FPIXTest_p17//defaultMaskFile.dat
[14:56:37.760] INFO: enter test to run
[14:57:51.988] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:57:51.988] INFO: running: xray
[14:57:51.989] INFO: ----------------------------------------------------------------------
[14:57:51.989] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:57:51.989] INFO: ----------------------------------------------------------------------
[14:57:52.952] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:58:04.746] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:58:34.056] INFO: Resuming triggers.
[14:58:45.847] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:59:15.180] INFO: Resuming triggers.
[14:59:26.973] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:59:56.038] INFO: Resuming triggers.
[15:00:07.835] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:00:35.510] INFO: Resuming triggers.
[15:00:47.306] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:01:16.486] INFO: Resuming triggers.
[15:01:28.282] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:01:57.510] INFO: Resuming triggers.
[15:02:09.300] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:02:38.475] INFO: Resuming triggers.
[15:02:50.267] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:03:19.558] INFO: Resuming triggers.
[15:03:25.530] INFO: data taking finished, elapsed time: 100 seconds.
[15:03:40.633] INFO: PixTest:: pg_setup set to default.
[15:03:40.637] INFO: PixTestXray::doPhRun() done
[15:03:40.826] INFO: enter test to run
[15:05:33.672] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:05:33.672] INFO: running: xray
[15:05:33.673] INFO: ----------------------------------------------------------------------
[15:05:33.673] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:05:33.673] INFO: ----------------------------------------------------------------------
[15:05:34.638] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:05:41.627] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:06:12.626] INFO: Resuming triggers.
[15:06:19.619] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:06:50.261] INFO: Resuming triggers.
[15:06:57.253] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:07:28.931] INFO: Resuming triggers.
[15:07:35.922] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:08:07.553] INFO: Resuming triggers.
[15:08:14.546] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:08:46.353] INFO: Resuming triggers.
[15:08:53.347] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:09:23.645] INFO: Resuming triggers.
[15:09:30.640] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:10:00.952] INFO: Resuming triggers.
[15:10:07.950] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:10:38.305] INFO: Resuming triggers.
[15:10:45.301] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:11:15.787] INFO: Resuming triggers.
[15:11:22.781] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:11:53.147] INFO: Resuming triggers.
[15:12:00.141] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:12:30.184] INFO: Resuming triggers.
[15:12:37.180] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:13:07.438] INFO: Resuming triggers.
[15:13:14.431] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:13:44.719] INFO: Resuming triggers.
[15:13:51.712] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:14:21.805] INFO: Resuming triggers.
[15:14:24.235] INFO: data taking finished, elapsed time: 100 seconds.
[15:14:35.046] INFO: PixTest:: pg_setup set to default.
[15:14:35.049] INFO: PixTestXray::doPhRun() done
[15:14:35.200] INFO: enter test to run
[15:17:08.748] INFO: test: HighRate no parameter change
[15:17:08.748] INFO: running: highrate
[15:17:08.761] INFO: ----------------------------------------------------------------------
[15:17:08.761] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:17:08.761] INFO: ----------------------------------------------------------------------
[15:17:08.916] INFO: Expecting 768 events.
[15:17:10.050] INFO: 768 events read in total (419ms).
[15:17:10.050] INFO: Test took 1269ms.
[15:17:10.853] INFO: Expecting 41600 events.
[15:17:13.902] INFO: 41600 events read in total (2522ms).
[15:17:13.903] INFO: Test took 3846ms.
[15:17:13.936] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:14.664] INFO: Expecting 41600 events.
[15:17:17.944] INFO: 41600 events read in total (2753ms).
[15:17:17.945] INFO: Test took 3992ms.
[15:17:17.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:18.690] INFO: Expecting 41600 events.
[15:17:21.957] INFO: 41600 events read in total (2740ms).
[15:17:21.958] INFO: Test took 3952ms.
[15:17:21.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:22.715] INFO: Expecting 41600 events.
[15:17:26.018] INFO: 41600 events read in total (2776ms).
[15:17:26.019] INFO: Test took 4011ms.
[15:17:26.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:26.779] INFO: Expecting 41600 events.
[15:17:30.070] INFO: 41600 events read in total (2764ms).
[15:17:30.071] INFO: Test took 4003ms.
[15:17:30.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:30.827] INFO: Expecting 41600 events.
[15:17:33.996] INFO: 41600 events read in total (2642ms).
[15:17:33.997] INFO: Test took 3875ms.
[15:17:34.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:34.761] INFO: Expecting 41600 events.
[15:17:37.896] INFO: 41600 events read in total (2608ms).
[15:17:37.897] INFO: Test took 3849ms.
[15:17:37.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:38.656] INFO: Expecting 41600 events.
[15:17:41.854] INFO: 41600 events read in total (2672ms).
[15:17:41.855] INFO: Test took 3908ms.
[15:17:41.888] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:42.612] INFO: Expecting 41600 events.
[15:17:45.821] INFO: 41600 events read in total (2682ms).
[15:17:45.822] INFO: Test took 3917ms.
[15:17:45.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:46.574] INFO: Expecting 41600 events.
[15:17:49.753] INFO: 41600 events read in total (2652ms).
[15:17:49.754] INFO: Test took 3883ms.
[15:17:49.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:50.514] INFO: Expecting 41600 events.
[15:17:53.733] INFO: 41600 events read in total (2692ms).
[15:17:53.734] INFO: Test took 3930ms.
[15:17:53.804] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:54.488] INFO: Expecting 41600 events.
[15:17:57.718] INFO: 41600 events read in total (2704ms).
[15:17:57.719] INFO: Test took 3897ms.
[15:17:57.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:58.477] INFO: Expecting 41600 events.
[15:18:01.741] INFO: 41600 events read in total (2737ms).
[15:18:01.742] INFO: Test took 3972ms.
[15:18:01.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:02.502] INFO: Expecting 41600 events.
[15:18:05.787] INFO: 41600 events read in total (2758ms).
[15:18:05.788] INFO: Test took 3996ms.
[15:18:05.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:06.548] INFO: Expecting 41600 events.
[15:18:09.835] INFO: 41600 events read in total (2760ms).
[15:18:09.836] INFO: Test took 3998ms.
[15:18:09.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:10.585] INFO: Expecting 41600 events.
[15:18:13.787] INFO: 41600 events read in total (2676ms).
[15:18:13.788] INFO: Test took 3902ms.
[15:18:13.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:14.547] INFO: Expecting 41600 events.
[15:18:17.734] INFO: 41600 events read in total (2661ms).
[15:18:17.735] INFO: Test took 3897ms.
[15:18:17.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:18.491] INFO: Expecting 41600 events.
[15:18:21.709] INFO: 41600 events read in total (2691ms).
[15:18:21.710] INFO: Test took 3925ms.
[15:18:21.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:22.470] INFO: Expecting 41600 events.
[15:18:25.712] INFO: 41600 events read in total (2715ms).
[15:18:25.713] INFO: Test took 3953ms.
[15:18:25.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:26.470] INFO: Expecting 41600 events.
[15:18:29.542] INFO: 41600 events read in total (2546ms).
[15:18:29.543] INFO: Test took 3779ms.
[15:18:29.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:29.948] INFO: enter test to run
[15:18:36.971] INFO: test: HighRate no parameter change
[15:18:36.971] INFO: running: highrate
[15:18:36.972] INFO: ----------------------------------------------------------------------
[15:18:36.972] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:18:36.972] INFO: ----------------------------------------------------------------------
[15:18:37.597] INFO: Expecting 208000 events.
[15:18:49.297] INFO: 208000 events read in total (11173ms).
[15:18:49.299] INFO: Test took 12320ms.
[15:18:49.435] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:49.685] INFO: number of dead pixels (per ROC): 0 0 0 0 1 11 0 0 0 0 0 0 0 0 0 0
[15:18:49.685] INFO: number of red-efficiency pixels: 77 36 67 128 151 312 154 95 65 116 92 66 80 59 10 27
[15:18:49.685] INFO: number of X-ray hits detected: 59462 39244 66889 101028 104900 107032 109294 76611 66927 89497 87615 73458 77792 45935 18106 22701
[15:18:49.685] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:18:49.685] INFO: number of Vcal hits detected: 207920 207963 207928 207870 207797 200276 207845 207904 207935 207884 207902 207934 207918 207939 207990 207973
[15:18:49.685] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 96.4 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:18:49.685] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 96.3 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[15:18:49.685] INFO: X-ray hit rate [MHz/cm2]: 17.4 11.5 19.6 29.6 30.7 31.4 32.0 22.5 19.6 26.2 25.7 21.5 22.8 13.5 5.3 6.7
[15:18:49.685] INFO: PixTestHighRate::doXPixelAlive() done
[15:18:49.730] INFO: PixTest:: pg_setup set to default.
[15:18:49.744] INFO: enter test to run
[15:19:06.675] INFO: test: HighRate no parameter change
[15:19:06.675] INFO: running: highrate
[15:19:06.676] INFO: ----------------------------------------------------------------------
[15:19:06.676] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:19:06.676] INFO: ----------------------------------------------------------------------
[15:19:07.297] INFO: Expecting 208000 events.
[15:19:20.822] INFO: 208000 events read in total (12998ms).
[15:19:20.827] INFO: Test took 14141ms.
[15:19:21.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:21.407] INFO: number of dead pixels (per ROC): 0 0 0 0 1 131 0 0 0 0 0 0 0 0 0 0
[15:19:21.407] INFO: number of red-efficiency pixels: 182 87 226 405 483 662 480 315 233 321 339 214 244 179 48 38
[15:19:21.407] INFO: number of X-ray hits detected: 124887 83494 138693 209176 218592 222925 229047 159795 139028 185751 183124 152665 162174 96719 37906 47745
[15:19:21.407] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:19:21.407] INFO: number of Vcal hits detected: 207812 207908 207753 207572 207437 199467 207475 207660 207756 207667 207644 207781 207737 207813 207952 207961
[15:19:21.407] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.0 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[15:19:21.408] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.7 95.9 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:19:21.408] INFO: X-ray hit rate [MHz/cm2]: 36.6 24.5 40.7 61.3 64.1 65.3 67.1 46.8 40.8 54.4 53.7 44.7 47.5 28.3 11.1 14.0
[15:19:21.408] INFO: PixTestHighRate::doXPixelAlive() done
[15:19:21.453] INFO: PixTest:: pg_setup set to default.
[15:19:21.471] INFO: enter test to run
[15:19:37.051] INFO: test: HighRate no parameter change
[15:19:37.051] INFO: running: highrate
[15:19:37.052] INFO: ----------------------------------------------------------------------
[15:19:37.052] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:19:37.052] INFO: ----------------------------------------------------------------------
[15:19:37.678] INFO: Expecting 208000 events.
[15:19:52.963] INFO: 208000 events read in total (14759ms).
[15:19:52.970] INFO: Test took 15908ms.
[15:19:53.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:53.753] INFO: number of dead pixels (per ROC): 0 0 0 0 1 155 0 0 0 0 0 0 0 0 0 0
[15:19:53.753] INFO: number of red-efficiency pixels: 330 198 509 1001 1104 1461 1273 739 458 695 754 410 517 350 62 82
[15:19:53.753] INFO: number of X-ray hits detected: 192281 129033 215211 326070 338913 344422 352731 247983 216316 287471 282024 235336 250694 149668 58813 74014
[15:19:53.753] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:19:53.753] INFO: number of Vcal hits detected: 207620 207788 207388 206758 206543 198252 206364 207091 207484 207211 207128 207544 207431 207605 207936 207917
[15:19:53.753] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.4 99.1 99.3 99.6 99.8 99.7 99.6 99.8 99.7 99.8 100.0 100.0
[15:19:53.753] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.3 95.3 99.2 99.6 99.8 99.6 99.6 99.8 99.7 99.8 100.0 100.0
[15:19:53.753] INFO: X-ray hit rate [MHz/cm2]: 56.4 37.8 63.1 95.6 99.3 101.0 103.4 72.7 63.4 84.3 82.7 69.0 73.5 43.9 17.2 21.7
[15:19:53.753] INFO: PixTestHighRate::doXPixelAlive() done
[15:19:53.804] INFO: PixTest:: pg_setup set to default.
[15:19:53.824] INFO: enter test to run
[15:19:57.466] INFO: test: exit no parameter change
[15:19:57.872] QUIET: Connection to board 33 closed.
[15:19:57.882] INFO: pXar: this is the end, my friend