[16:07:18.237]     INFO: *** Welcome to pxar ***
[16:07:18.237]     INFO: *** Today: 2016/06/20
[16:07:18.256]     INFO: *** Version: v1.9.0-814-g7497
[16:07:18.256]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//dacParameters35_C15.dat
[16:07:18.257]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:07:18.257]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[16:07:18.257]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[16:07:18.330]     INFO:         clk: 4
[16:07:18.330]     INFO:         ctr: 4
[16:07:18.330]     INFO:         sda: 19
[16:07:18.330]     INFO:         tin: 9
[16:07:18.330]     INFO:         level: 15
[16:07:18.330]     INFO:         triggerdelay: 0
[16:07:18.330]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:07:18.330]     INFO: Log level: INFO
[16:07:18.346]    QUIET: Connection to board DTB_WREK4U opened.
[16:07:18.349]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    32
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREK4U
MAC address: 40D855118020
Hostname:    pixelDTB032
Comment:     
------------------------------------------------------
[16:07:18.352]     INFO: RPC call hashes of host and DTB match: 398089610
[16:07:19.889]     INFO: DUT info: 
[16:07:19.889]     INFO: The DUT currently contains the following objects:
[16:07:19.889]     INFO:  2 TBM Cores tbm08c (2 ON)
[16:07:19.889]     INFO: 	TBM Core alpha (0): 7 registers set
[16:07:19.889]     INFO: 	TBM Core beta  (1): 7 registers set
[16:07:19.889]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:07:19.889]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:19.889]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:20.293]     INFO: enter 'restricted' command line mode
[16:07:20.293]     INFO: enter test to run
[16:07:21.838]     INFO:   test: timing no parameter change
[16:07:21.838]     INFO:   running: timing
[16:07:21.848]     INFO: ######################################################################
[16:07:21.848]     INFO: PixTestTiming::doTest()
[16:07:21.848]     INFO: ######################################################################
[16:07:21.848]     INFO:    ----------------------------------------------------------------------
[16:07:21.848]     INFO:    PixTestTiming::TBMPhaseScan()
[16:07:21.848]     INFO:    ----------------------------------------------------------------------
[16:12:18.884]     INFO: TBM Phase Settings: 232
[16:12:18.885]     INFO: 400MHz Phase: 2
[16:12:18.885]     INFO: 160MHz Phase: 7
[16:12:18.885]     INFO: Functional Phase Area: 3
[16:12:18.888]     INFO: Test took 297040 ms.
[16:12:18.888]     INFO: PixTestTiming::TBMPhaseScan() done.
[16:12:18.888]     INFO:    ----------------------------------------------------------------------
[16:12:18.888]     INFO:    PixTestTiming::ROCDelayScan()
[16:12:18.888]     INFO:    ----------------------------------------------------------------------
[16:15:28.384]     INFO: ROC Delay Settings: 228
[16:15:28.384]     INFO: ROC Header-Trailer/Token Delay: 11
[16:15:28.384]     INFO: ROC Port 0 Delay: 4
[16:15:28.384]     INFO: ROC Port 1 Delay: 4
[16:15:28.384]     INFO: Functional ROC Area: 3
[16:15:28.388]     INFO: Test took 189500 ms.
[16:15:28.388]     INFO: PixTestTiming::ROCDelayScan() done.
[16:15:28.388]     INFO:    ----------------------------------------------------------------------
[16:15:28.388]     INFO:    PixTestTiming::TimingTest()
[16:15:28.388]     INFO:    ----------------------------------------------------------------------
[16:15:44.545]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:59.538]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:14.479]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:29.421]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:44.397]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:59.367]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:14.396]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:29.455]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:44.574]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:59.766]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:00.144]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:00.161]     INFO:    ----------------------------------------------------------------------
[16:18:00.161]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:18:00.161]     INFO:    ----------------------------------------------------------------------
[16:18:00.161]     INFO:    ----------------------------------------------------------------------
[16:18:00.161]     INFO:    Read back bit status: 1
[16:18:00.161]     INFO:    ----------------------------------------------------------------------
[16:18:00.162]     INFO:    ----------------------------------------------------------------------
[16:18:00.162]     INFO:    Timings are good!
[16:18:00.162]     INFO:    ----------------------------------------------------------------------
[16:18:00.162]     INFO: Test took 151774 ms.
[16:18:00.162]     INFO: PixTestTiming::TimingTest() done.
[16:18:00.162]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:18:00.162]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:18:00.162]     INFO: PixTestTiming::doTest took 638319 ms.
[16:18:00.162]     INFO: PixTestTiming::doTest() done
[16:18:00.162]     INFO: Write out TBMPhaseScan_0_V0
[16:18:00.186]     INFO: Write out TBMPhaseScan_1_V0
[16:18:00.186]     INFO: Write out CombinedTBMPhaseScan_V0
[16:18:00.186]     INFO: Write out ROCDelayScan3_V0
[16:18:00.187]     INFO: enter test to run
[16:19:40.033]     INFO:   test: PixelAlive no parameter change
[16:19:40.033]     INFO:   running: pixelalive
[16:19:40.038]     INFO:    ----------------------------------------------------------------------
[16:19:40.038]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:19:40.038]     INFO:    ----------------------------------------------------------------------
[16:19:40.363]     INFO: Expecting 41600 events.
[16:19:44.676]     INFO: 41600 events read in total (3597ms).
[16:19:44.677]     INFO: Test took 4637ms.
[16:19:44.683]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:19:45.078]     INFO: PixTestAlive::aliveTest() done
[16:19:45.078]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[16:19:45.082]     INFO: enter test to run
[16:21:47.752]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:21:47.752]     INFO:   running: highrate
[16:21:47.753]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:21:47.903]     INFO:    ----------------------------------------------------------------------
[16:21:47.903]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:21:47.903]     INFO:    ----------------------------------------------------------------------
[16:21:47.903]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:21:47.903]     INFO: edge/corner pixel THR is adjusted
[16:21:47.903]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:21:48.860]     INFO: Collecting data for 5 seconds...
[16:21:53.877]     INFO: Done with hot pixel readout
[16:22:05.107]     INFO: PixTest::       pg_setup set to default.
[16:22:05.108]     INFO: 3 hot pixels found in step 0
[16:22:06.095]     INFO: Collecting data for 5 seconds...
[16:22:11.111]     INFO: Done with hot pixel readout
[16:22:22.306]     INFO: PixTest::       pg_setup set to default.
[16:22:22.307]     INFO: 2 hot pixels found in step 1
[16:22:23.296]     INFO: Collecting data for 5 seconds...
[16:22:28.312]     INFO: Done with hot pixel readout
[16:22:39.534]     INFO: PixTest::       pg_setup set to default.
[16:22:39.535]     INFO: 5 hot pixels found in step 2
[16:22:40.523]     INFO: Collecting data for 5 seconds...
[16:22:45.538]     INFO: Done with hot pixel readout
[16:22:56.783]     INFO: PixTest::       pg_setup set to default.
[16:22:56.784]     INFO: 0 hot pixels found in step 3
[16:22:56.816]     INFO: 0 hot pixels could not be trimmed and have been masked.
[16:22:56.819]     INFO: PixTest::trimHotPixels() done
[16:22:56.819]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat
[16:22:56.825]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C1.dat
[16:22:56.831]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C2.dat
[16:22:56.837]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C3.dat
[16:22:56.842]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C4.dat
[16:22:56.847]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C5.dat
[16:22:56.852]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C6.dat
[16:22:56.857]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C7.dat
[16:22:56.863]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C8.dat
[16:22:56.868]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C9.dat
[16:22:56.873]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C10.dat
[16:22:56.878]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C11.dat
[16:22:56.883]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C12.dat
[16:22:56.888]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C13.dat
[16:22:56.894]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C14.dat
[16:22:56.899]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[16:22:56.904]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[16:22:56.914]     INFO: enter test to run
[16:23:38.184]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:23:38.184]     INFO:   running: highrate
[16:23:38.188]     INFO:    ----------------------------------------------------------------------
[16:23:38.188]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:23:38.188]     INFO:    ----------------------------------------------------------------------
[16:23:38.188]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:23:38.188]     INFO: edge/corner pixel THR is adjusted
[16:23:38.188]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:23:39.146]     INFO: Collecting data for 1 seconds...
[16:23:40.149]     INFO: Done with hot pixel readout
[16:23:43.827]     INFO: PixTest::       pg_setup set to default.
[16:23:43.828]     INFO: 0 hot pixels found in step 0
[16:23:43.834]     INFO: 0 hot pixels could not be trimmed and have been masked.
[16:23:43.937]     INFO: PixTest::trimHotPixels() done
[16:23:43.937]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat
[16:23:43.947]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C1.dat
[16:23:43.953]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C2.dat
[16:23:43.958]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C3.dat
[16:23:43.963]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C4.dat
[16:23:43.969]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C5.dat
[16:23:43.974]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C6.dat
[16:23:43.979]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C7.dat
[16:23:43.984]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C8.dat
[16:23:43.990]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C9.dat
[16:23:43.995]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C10.dat
[16:23:43.001]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C11.dat
[16:23:44.006]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C12.dat
[16:23:44.011]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C13.dat
[16:23:44.016]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C14.dat
[16:23:44.021]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[16:23:44.027]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-H-1-28_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[16:23:44.037]     INFO: enter test to run
[16:25:03.799]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[16:25:03.799]     INFO:   running: xray
[16:25:03.800]     INFO:    ----------------------------------------------------------------------
[16:25:03.800]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:25:03.800]     INFO:    ----------------------------------------------------------------------
[16:25:04.764]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:25:16.857]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:25:46.118]     INFO: Resuming triggers.
[16:25:58.214]     INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[16:26:27.446]     INFO: Resuming triggers.
[16:26:39.543]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[16:27:08.750]     INFO: Resuming triggers.
[16:27:20.845]     INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:27:50.033]     INFO: Resuming triggers.
[16:28:02.127]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:28:31.252]     INFO: Resuming triggers.
[16:28:43.347]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:29:12.927]     INFO: Resuming triggers.
[16:29:25.021]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:29:54.366]     INFO: Resuming triggers.
[16:30:06.459]     INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[16:30:35.381]     INFO: Resuming triggers.
[16:30:38.953]     INFO: data taking finished, elapsed time: 100 seconds.
[16:30:48.252]     INFO: PixTest::       pg_setup set to default.
[16:30:48.255]     INFO: PixTestXray::doPhRun() done
[16:30:48.392]     INFO: enter test to run
[16:31:59.532]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[16:31:59.532]     INFO:   running: xray
[16:31:59.533]     INFO:    ----------------------------------------------------------------------
[16:31:59.533]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:31:59.533]     INFO:    ----------------------------------------------------------------------
[16:32:00.497]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:32:07.998]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[16:32:38.600]     INFO: Resuming triggers.
[16:32:46.099]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[16:33:16.162]     INFO: Resuming triggers.
[16:33:23.662]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:33:53.699]     INFO: Resuming triggers.
[16:34:01.200]     INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[16:34:31.270]     INFO: Resuming triggers.
[16:34:38.771]     INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[16:35:08.816]     INFO: Resuming triggers.
[16:35:16.318]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:35:46.421]     INFO: Resuming triggers.
[16:35:53.927]     INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:36:23.949]     INFO: Resuming triggers.
[16:36:31.455]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:37:01.547]     INFO: Resuming triggers.
[16:37:09.051]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:37:39.138]     INFO: Resuming triggers.
[16:37:46.644]     INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:38:16.705]     INFO: Resuming triggers.
[16:38:24.211]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:38:54.251]     INFO: Resuming triggers.
[16:39:01.754]     INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:39:31.762]     INFO: Resuming triggers.
[16:39:39.263]     INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[16:40:09.312]     INFO: Resuming triggers.
[16:40:12.100]     INFO: data taking finished, elapsed time: 100 seconds.
[16:40:23.547]     INFO: PixTest::       pg_setup set to default.
[16:40:23.550]     INFO: PixTestXray::doPhRun() done
[16:40:23.697]     INFO: enter test to run
[16:43:02.032]     INFO:   test: HighRate no parameter change
[16:43:02.032]     INFO:   running: highrate
[16:43:02.033]     INFO:    ----------------------------------------------------------------------
[16:43:02.033]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:43:02.033]     INFO:    ----------------------------------------------------------------------
[16:43:02.174]     INFO: Expecting 768 events.
[16:43:03.309]     INFO: 768 events read in total (419ms).
[16:43:03.310]     INFO: Test took 1269ms.
[16:43:04.113]     INFO: Expecting 41600 events.
[16:43:07.177]     INFO: 41600 events read in total (2538ms).
[16:43:07.178]     INFO: Test took 3861ms.
[16:43:07.208]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:07.935]     INFO: Expecting 41600 events.
[16:43:11.141]     INFO: 41600 events read in total (2679ms).
[16:43:11.142]     INFO: Test took 3918ms.
[16:43:11.172]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:11.901]     INFO: Expecting 41600 events.
[16:43:15.166]     INFO: 41600 events read in total (2738ms).
[16:43:15.167]     INFO: Test took 3978ms.
[16:43:15.197]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:15.930]     INFO: Expecting 41600 events.
[16:43:19.212]     INFO: 41600 events read in total (2755ms).
[16:43:19.213]     INFO: Test took 4000ms.
[16:43:19.244]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:19.976]     INFO: Expecting 41600 events.
[16:43:23.234]     INFO: 41600 events read in total (2731ms).
[16:43:23.235]     INFO: Test took 3975ms.
[16:43:23.265]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:23.987]     INFO: Expecting 41600 events.
[16:43:27.255]     INFO: 41600 events read in total (2741ms).
[16:43:27.256]     INFO: Test took 3975ms.
[16:43:27.287]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:28.003]     INFO: Expecting 41600 events.
[16:43:31.310]     INFO: 41600 events read in total (2781ms).
[16:43:31.311]     INFO: Test took 4008ms.
[16:43:31.341]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:32.068]     INFO: Expecting 41600 events.
[16:43:35.338]     INFO: 41600 events read in total (2743ms).
[16:43:35.339]     INFO: Test took 3982ms.
[16:43:35.369]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:36.101]     INFO: Expecting 41600 events.
[16:43:39.399]     INFO: 41600 events read in total (2771ms).
[16:43:39.400]     INFO: Test took 4014ms.
[16:43:39.430]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:40.154]     INFO: Expecting 41600 events.
[16:43:43.437]     INFO: 41600 events read in total (2756ms).
[16:43:43.438]     INFO: Test took 3991ms.
[16:43:43.468]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:44.198]     INFO: Expecting 41600 events.
[16:43:47.457]     INFO: 41600 events read in total (2732ms).
[16:43:47.458]     INFO: Test took 3974ms.
[16:43:47.489]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:48.219]     INFO: Expecting 41600 events.
[16:43:51.487]     INFO: 41600 events read in total (2742ms).
[16:43:51.488]     INFO: Test took 3981ms.
[16:43:51.519]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:52.246]     INFO: Expecting 41600 events.
[16:43:55.655]     INFO: 41600 events read in total (2882ms).
[16:43:55.656]     INFO: Test took 4121ms.
[16:43:55.686]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:56.418]     INFO: Expecting 41600 events.
[16:43:59.639]     INFO: 41600 events read in total (2694ms).
[16:43:59.640]     INFO: Test took 3938ms.
[16:43:59.671]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:00.403]     INFO: Expecting 41600 events.
[16:44:03.683]     INFO: 41600 events read in total (2754ms).
[16:44:03.684]     INFO: Test took 3996ms.
[16:44:03.716]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:04.442]     INFO: Expecting 41600 events.
[16:44:07.693]     INFO: 41600 events read in total (2724ms).
[16:44:07.694]     INFO: Test took 3958ms.
[16:44:07.724]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:08.452]     INFO: Expecting 41600 events.
[16:44:11.672]     INFO: 41600 events read in total (2693ms).
[16:44:11.672]     INFO: Test took 3932ms.
[16:44:11.703]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:12.430]     INFO: Expecting 41600 events.
[16:44:15.621]     INFO: 41600 events read in total (2664ms).
[16:44:15.622]     INFO: Test took 3902ms.
[16:44:15.652]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:16.386]     INFO: Expecting 41600 events.
[16:44:19.566]     INFO: 41600 events read in total (2653ms).
[16:44:19.567]     INFO: Test took 3898ms.
[16:44:19.597]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:20.328]     INFO: Expecting 41600 events.
[16:44:23.379]     INFO: 41600 events read in total (2524ms).
[16:44:23.380]     INFO: Test took 3767ms.
[16:44:23.409]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:23.783]     INFO: enter test to run
[16:44:51.583]     INFO:   test: HighRate no parameter change
[16:44:51.583]     INFO:   running: highrate
[16:44:51.584]     INFO:    ----------------------------------------------------------------------
[16:44:51.584]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:44:51.584]     INFO:    ----------------------------------------------------------------------
[16:44:52.204]     INFO: Expecting 208000 events.
[16:45:03.814]     INFO: 208000 events read in total (11084ms).
[16:45:03.817]     INFO: Test took 12224ms.
[16:45:03.941]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:04.186]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[16:45:04.186]     INFO: number of red-efficiency pixels:    64   32   63  100  136  116  140   87   63   95   69   81   69   53   18   26
[16:45:04.186]     INFO: number of X-ray hits detected:    54075 36216 55751 85746 93427 96805 98923 73879 67599 82644 79343 68032 71194 41500 17614 21338
[16:45:04.186]     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:45:04.186]     INFO: number of Vcal hits detected:  207934 207968 207934 207898 207860 207883 207856 207911 207937 207905 207931 207914 207931 207947 207982 207974
[16:45:04.186]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:45:04.186]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:45:04.186]     INFO: X-ray hit rate [MHz/cm2]:  15.8 10.6 16.3 25.1 27.4 28.4 29.0 21.7 19.8 24.2 23.3 19.9 20.9 12.2 5.2 6.3
[16:45:04.186]     INFO: PixTestHighRate::doXPixelAlive() done
[16:45:04.234]     INFO: PixTest::       pg_setup set to default.
[16:45:04.250]     INFO: enter test to run
[16:45:26.767]     INFO:   test: HighRate no parameter change
[16:45:26.767]     INFO:   running: highrate
[16:45:26.768]     INFO:    ----------------------------------------------------------------------
[16:45:26.768]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:45:26.768]     INFO:    ----------------------------------------------------------------------
[16:45:27.388]     INFO: Expecting 208000 events.
[16:45:40.333]     INFO: 208000 events read in total (12419ms).
[16:45:40.338]     INFO: Test took 13559ms.
[16:45:40.578]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:40.860]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[16:45:40.860]     INFO: number of red-efficiency pixels:   148   96  154  221  325  362  365  260  159  238  261  208  197   92   43   37
[16:45:40.860]     INFO: number of X-ray hits detected:    107987 72331 111606 172225 187564 195023 198860 148524 136708 165681 158125 136386 142657 83588 35052 43365
[16:45:40.860]     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:45:40.861]     INFO: number of Vcal hits detected:  207849 207900 207842 207768 207655 207612 207614 207728 207836 207750 207731 207783 207799 207906 207956 207961
[16:45:40.861]     INFO: Vcal hit fiducial efficiency (%):  99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:45:40.861]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:45:40.861]     INFO: X-ray hit rate [MHz/cm2]:  31.7 21.2 32.7 50.5 55.0 57.2 58.3 43.5 40.1 48.6 46.3 40.0 41.8 24.5 10.3 12.7
[16:45:40.861]     INFO: PixTestHighRate::doXPixelAlive() done
[16:45:40.911]     INFO: PixTest::       pg_setup set to default.
[16:45:40.930]     INFO: enter test to run
[16:45:54.074]     INFO:   test: HighRate no parameter change
[16:45:54.074]     INFO:   running: highrate
[16:45:54.075]     INFO: enter test to run
[16:46:03.583]     INFO:   test: HighRate no parameter change
[16:46:03.583]     INFO:   running: highrate
[16:46:03.584]     INFO:    ----------------------------------------------------------------------
[16:46:03.584]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:46:03.584]     INFO:    ----------------------------------------------------------------------
[16:46:04.203]     INFO: Expecting 208000 events.
[16:46:18.634]     INFO: 208000 events read in total (13904ms).
[16:46:18.640]     INFO: Test took 15046ms.
[16:46:19.011]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:19.335]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[16:46:19.335]     INFO: number of red-efficiency pixels:   304  177  354  475  803  682  874  581  317  499  583  442  406  180   62   82
[16:46:19.335]     INFO: number of X-ray hits detected:    164685 110363 168594 261651 285207 294420 301621 224572 208669 251653 242564 208111 217139 126901 53668 65657
[16:46:19.335]     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:46:19.335]     INFO: number of Vcal hits detected:  207660 207811 207605 207466 207053 207211 206954 207288 207663 207441 207354 207526 207566 207806 207937 207916
[16:46:19.335]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.8 99.8 99.6 99.7 99.5 99.7 99.9 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[16:46:19.335]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.8 99.7 99.5 99.6 99.5 99.7 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[16:46:19.335]     INFO: X-ray hit rate [MHz/cm2]:  48.3 32.3 49.4 76.7 83.6 86.3 88.4 65.8 61.2 73.8 71.1 61.0 63.6 37.2 15.7 19.2
[16:46:19.335]     INFO: PixTestHighRate::doXPixelAlive() done
[16:46:19.386]     INFO: PixTest::       pg_setup set to default.
[16:46:19.406]     INFO: enter test to run
[16:46:25.766]     INFO:   test: exit setting parameters: -><-
[16:46:26.072]    QUIET: Connection to board 32 closed.
[16:46:26.073]     INFO: pXar: this is the end, my friend