[13:51:01.763]     INFO: *** Welcome to pxar ***
[13:51:01.763]     INFO: *** Today: 2016/09/30
[13:51:03.486]     INFO: *** Version: v1.9.0-818-g96727
[13:51:03.486]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C15.dat
[13:51:03.661]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:51:03.661]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[13:51:03.666]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[13:51:03.895]     INFO:         clk: 4
[13:51:03.895]     INFO:         ctr: 4
[13:51:03.895]     INFO:         sda: 19
[13:51:03.895]     INFO:         tin: 9
[13:51:03.895]     INFO:         level: 15
[13:51:03.895]     INFO:         triggerdelay: 0
[13:51:03.895]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:51:03.895]     INFO: Log level: INFO
[13:51:03.929]    QUIET: Connection to board DTB_WREKRL opened.
[13:51:03.933]     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:     
------------------------------------------------------
[13:51:03.935]     INFO: RPC call hashes of host and DTB match: 398089610
[13:51:05.481]     INFO: DUT info: 
[13:51:05.481]     INFO: The DUT currently contains the following objects:
[13:51:05.481]     INFO:  2 TBM Cores tbm08c (2 ON)
[13:51:05.495]     INFO: 	TBM Core alpha (0): 7 registers set
[13:51:05.495]     INFO: 	TBM Core beta  (1): 7 registers set
[13:51:05.495]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:51:05.495]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.948]     INFO: enter 'restricted' command line mode
[13:51:05.948]     INFO: enter test to run
[13:51:16.507]     INFO:   test: PixelAlive no parameter change
[13:51:16.507]     INFO:   running: pixelalive
[13:51:16.545]     INFO:    ----------------------------------------------------------------------
[13:51:16.545]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:51:16.545]     INFO:    ----------------------------------------------------------------------
[13:51:16.869]     INFO: Expecting 41600 events.
[13:51:21.337]     INFO: 41600 events read in total (3750ms).
[13:51:21.503]     INFO: Test took 4955ms.
[13:51:21.511]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:21.783]     INFO: PixTestAlive::aliveTest() done
[13:51:21.783]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    1
[13:51:21.815]     INFO: enter test to run
[13:51:30.139]     INFO:   test: timing no parameter change
[13:51:30.140]     INFO:   running: timing
[13:51:30.143]     INFO: ######################################################################
[13:51:30.143]     INFO: PixTestTiming::doTest()
[13:51:30.143]     INFO: ######################################################################
[13:51:30.143]     INFO:    ----------------------------------------------------------------------
[13:51:30.143]     INFO:    PixTestTiming::TBMPhaseScan()
[13:51:30.143]     INFO:    ----------------------------------------------------------------------
[13:55:59.388]     INFO: TBM Phase Settings: 236
[13:55:59.388]     INFO: 400MHz Phase: 3
[13:55:59.388]     INFO: 160MHz Phase: 7
[13:55:59.388]     INFO: Functional Phase Area: 5
[13:55:59.399]     INFO: Test took 269256 ms.
[13:55:59.399]     INFO: PixTestTiming::TBMPhaseScan() done.
[13:55:59.399]     INFO:    ----------------------------------------------------------------------
[13:55:59.399]     INFO:    PixTestTiming::ROCDelayScan()
[13:55:59.399]     INFO:    ----------------------------------------------------------------------
[13:57:51.308]     INFO: ROC Delay Settings: 228
[13:57:51.308]     INFO: ROC Header-Trailer/Token Delay: 11
[13:57:51.308]     INFO: ROC Port 0 Delay: 4
[13:57:51.308]     INFO: ROC Port 1 Delay: 4
[13:57:51.308]     INFO: Functional ROC Area: 3
[13:57:51.311]     INFO: Test took 111912 ms.
[13:57:51.311]     INFO: PixTestTiming::ROCDelayScan() done.
[13:57:51.311]     INFO:    ----------------------------------------------------------------------
[13:57:51.311]     INFO:    PixTestTiming::TimingTest()
[13:57:51.311]     INFO:    ----------------------------------------------------------------------
[13:58:07.440]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:22.375]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:37.342]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:52.307]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:07.290]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:22.246]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:37.214]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:52.171]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:07.138]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.137]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.518]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO:    Read back bit status: 1
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO:    Timings are good!
[14:00:22.536]     INFO:    ----------------------------------------------------------------------
[14:00:22.536]     INFO: Test took 151225 ms.
[14:00:22.536]     INFO: PixTestTiming::TimingTest() done.
[14:00:22.536]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:00:22.536]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:00:22.536]     INFO: PixTestTiming::doTest took 532396 ms.
[14:00:22.536]     INFO: PixTestTiming::doTest() done
[14:00:22.536]     INFO: Write out TBMPhaseScan_0_V0
[14:00:22.536]     INFO: Write out TBMPhaseScan_1_V0
[14:00:22.536]     INFO: Write out CombinedTBMPhaseScan_V0
[14:00:22.545]     INFO: Write out ROCDelayScan3_V0
[14:00:22.546]     INFO: enter test to run
[14:01:24.280]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:01:24.280]     INFO:   running: highrate
[14:01:24.297]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:01:24.632]     INFO:    ----------------------------------------------------------------------
[14:01:24.632]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:01:24.632]     INFO:    ----------------------------------------------------------------------
[14:01:24.632]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:01:24.632]     INFO: edge/corner pixel THR is adjusted
[14:01:24.632]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:01:25.608]     INFO: Collecting data for 5 seconds...
[14:01:30.628]     INFO: Done with hot pixel readout
[14:01:42.955]     INFO: PixTest::       pg_setup set to default.
[14:01:42.956]     INFO: 45 hot pixels found in step 0
[14:01:43.951]     INFO: Collecting data for 5 seconds...
[14:01:48.971]     INFO: Done with hot pixel readout
[14:02:01.030]     INFO: PixTest::       pg_setup set to default.
[14:02:01.031]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:01.031]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:01.031]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:01.031]     INFO: 41 hot pixels found in step 1
[14:02:02.026]     INFO: Collecting data for 5 seconds...
[14:02:07.044]     INFO: Done with hot pixel readout
[14:02:19.276]     INFO: PixTest::       pg_setup set to default.
[14:02:19.276]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:19.277]     INFO: 48 hot pixels found in step 2
[14:02:20.272]     INFO: Collecting data for 5 seconds...
[14:02:25.291]     INFO: Done with hot pixel readout
[14:02:37.266]     INFO: PixTest::       pg_setup set to default.
[14:02:37.267]     INFO: 37 hot pixels found in step 3
[14:02:38.262]     INFO: Collecting data for 5 seconds...
[14:02:43.280]     INFO: Done with hot pixel readout
[14:02:55.407]     INFO: PixTest::       pg_setup set to default.
[14:02:55.407]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:55.407]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:55.408]     INFO: 44 hot pixels found in step 4
[14:02:56.402]     INFO: Collecting data for 5 seconds...
[14:03:01.420]     INFO: Done with hot pixel readout
[14:03:13.575]     INFO: PixTest::       pg_setup set to default.
[14:03:13.575]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:13.577]     INFO: 26 hot pixels found in step 5
[14:03:14.576]     INFO: Collecting data for 5 seconds...
[14:03:19.595]     INFO: Done with hot pixel readout
[14:03:31.680]     INFO: PixTest::       pg_setup set to default.
[14:03:31.681]     INFO: 26 hot pixels found in step 6
[14:03:32.676]     INFO: Collecting data for 5 seconds...
[14:03:37.694]     INFO: Done with hot pixel readout
[14:03:49.912]     INFO: PixTest::       pg_setup set to default.
[14:03:49.913]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:49.913]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:49.913]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:49.913]     INFO: 28 hot pixels found in step 7
[14:03:50.907]     INFO: Collecting data for 5 seconds...
[14:03:55.926]     INFO: Done with hot pixel readout
[14:04:07.961]     INFO: PixTest::       pg_setup set to default.
[14:04:07.962]     INFO: 20 hot pixels found in step 8
[14:04:08.957]     INFO: Collecting data for 5 seconds...
[14:04:13.975]     INFO: Done with hot pixel readout
[14:04:25.780]     INFO: PixTest::       pg_setup set to default.
[14:04:25.780]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:25.780]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:25.780]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:25.781]     INFO: 25 hot pixels found in step 9
[14:04:26.776]     INFO: Collecting data for 5 seconds...
[14:04:31.795]     INFO: Done with hot pixel readout
[14:04:43.332]     INFO: PixTest::       pg_setup set to default.
[14:04:43.332]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:43.333]     INFO: 20 hot pixels found in step 10
[14:04:44.327]     INFO: Collecting data for 5 seconds...
[14:04:49.346]     INFO: Done with hot pixel readout
[14:05:01.586]     INFO: PixTest::       pg_setup set to default.
[14:05:01.587]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:01.587]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:01.587]     INFO: 20 hot pixels found in step 11
[14:05:02.581]     INFO: Collecting data for 5 seconds...
[14:05:07.600]     INFO: Done with hot pixel readout
[14:05:20.103]     INFO: PixTest::       pg_setup set to default.
[14:05:20.103]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:20.104]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:20.104]     INFO: 21 hot pixels found in step 12
[14:05:21.099]     INFO: Collecting data for 5 seconds...
[14:05:26.117]     INFO: Done with hot pixel readout
[14:05:38.354]     INFO: PixTest::       pg_setup set to default.
[14:05:38.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:38.355]     INFO: 15 hot pixels found in step 13
[14:05:39.349]     INFO: Collecting data for 5 seconds...
[14:05:44.370]     INFO: Done with hot pixel readout
[14:05:56.649]     INFO: PixTest::       pg_setup set to default.
[14:05:56.650]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:56.650]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:56.650]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:56.650]     INFO: 26 hot pixels found in step 14
[14:05:56.690]     INFO: 26 hot pixels could not be trimmed and have been masked.
[14:05:56.693]     INFO: PixTest::trimHotPixels() done
[14:05:56.693]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat
[14:05:56.699]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C1.dat
[14:05:56.706]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C2.dat
[14:05:56.712]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C3.dat
[14:05:56.717]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C4.dat
[14:05:56.723]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C5.dat
[14:05:56.728]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C6.dat
[14:05:56.734]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C7.dat
[14:05:56.739]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C8.dat
[14:05:56.745]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C9.dat
[14:05:56.750]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C10.dat
[14:05:56.755]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C11.dat
[14:05:56.761]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C12.dat
[14:05:56.766]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C13.dat
[14:05:56.772]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C14.dat
[14:05:56.777]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[14:05:56.782]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[14:05:56.793]     INFO: enter test to run
[14:06:19.053]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[14:06:19.054]     INFO:   running: xray
[14:06:19.055]     INFO:    ----------------------------------------------------------------------
[14:06:19.055]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:06:19.055]     INFO:    ----------------------------------------------------------------------
[14:06:20.018]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:06:31.108]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:07:01.201]     INFO: Resuming triggers.
[14:07:12.291]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:07:41.823]     INFO: Resuming triggers.
[14:07:52.910]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:08:22.314]     INFO: Resuming triggers.
[14:08:33.404]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:09:02.787]     INFO: Resuming triggers.
[14:09:13.876]     INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:09:43.328]     INFO: Resuming triggers.
[14:09:54.419]     INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:10:23.934]     INFO: Resuming triggers.
[14:10:35.023]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:11:04.574]     INFO: Resuming triggers.
[14:11:15.667]     INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:11:45.145]     INFO: Resuming triggers.
[14:11:56.238]     INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:12:25.724]     INFO: Resuming triggers.
[14:12:26.243]     INFO: data taking finished, elapsed time: 100 seconds.
[14:12:27.997]     INFO: PixTest::       pg_setup set to default.
[14:12:27.000]     INFO: PixTestXray::doPhRun() done
[14:12:28.152]     INFO: enter test to run
[14:12:50.667]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[14:12:50.667]     INFO:   running: xray
[14:12:50.669]     INFO:    ----------------------------------------------------------------------
[14:12:50.669]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:12:50.669]     INFO:    ----------------------------------------------------------------------
[14:12:51.652]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:12:58.424]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:13:28.783]     INFO: Resuming triggers.
[14:13:35.563]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:14:05.743]     INFO: Resuming triggers.
[14:14:12.524]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:14:42.972]     INFO: Resuming triggers.
[14:14:49.749]     INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:15:20.664]     INFO: Resuming triggers.
[14:15:27.447]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:15:58.519]     INFO: Resuming triggers.
[14:16:05.300]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:16:36.220]     INFO: Resuming triggers.
[14:16:42.003]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:17:13.959]     INFO: Resuming triggers.
[14:17:20.740]     INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:17:51.030]     INFO: Resuming triggers.
[14:17:57.803]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:18:29.247]     INFO: Resuming triggers.
[14:18:36.027]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:19:07.855]     INFO: Resuming triggers.
[14:19:14.633]     INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:19:45.859]     INFO: Resuming triggers.
[14:19:52.630]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:20:22.845]     INFO: Resuming triggers.
[14:20:29.621]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:20:59.763]     INFO: Resuming triggers.
[14:21:06.536]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:21:36.613]     INFO: Resuming triggers.
[14:21:42.075]     INFO: data taking finished, elapsed time: 100 seconds.
[14:22:06.710]     INFO: PixTest::       pg_setup set to default.
[14:22:06.713]     INFO: PixTestXray::doPhRun() done
[14:22:06.861]     INFO: enter test to run
[14:22:34.223]     INFO:   test: HighRate no parameter change
[14:22:34.223]     INFO:   running: highrate
[14:22:34.244]     INFO:    ----------------------------------------------------------------------
[14:22:34.244]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:22:34.245]     INFO:    ----------------------------------------------------------------------
[14:22:34.400]     INFO: Expecting 768 events.
[14:22:35.533]     INFO: 768 events read in total (418ms).
[14:22:35.534]     INFO: Test took 1269ms.
[14:22:36.337]     INFO: Expecting 41600 events.
[14:22:39.455]     INFO: 41600 events read in total (2591ms).
[14:22:39.456]     INFO: Test took 3915ms.
[14:22:39.497]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:40.217]     INFO: Expecting 41600 events.
[14:22:43.426]     INFO: 41600 events read in total (2682ms).
[14:22:43.427]     INFO: Test took 3913ms.
[14:22:43.461]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:44.183]     INFO: Expecting 41600 events.
[14:22:47.373]     INFO: 41600 events read in total (2663ms).
[14:22:47.374]     INFO: Test took 3895ms.
[14:22:47.408]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:48.130]     INFO: Expecting 41600 events.
[14:22:51.349]     INFO: 41600 events read in total (2692ms).
[14:22:51.349]     INFO: Test took 3924ms.
[14:22:51.383]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:52.110]     INFO: Expecting 41600 events.
[14:22:55.334]     INFO: 41600 events read in total (2697ms).
[14:22:55.335]     INFO: Test took 3935ms.
[14:22:55.369]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:56.096]     INFO: Expecting 41600 events.
[14:22:59.329]     INFO: 41600 events read in total (2707ms).
[14:22:59.330]     INFO: Test took 3943ms.
[14:22:59.364]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:00.090]     INFO: Expecting 41600 events.
[14:23:03.324]     INFO: 41600 events read in total (2707ms).
[14:23:03.325]     INFO: Test took 3943ms.
[14:23:03.358]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:04.085]     INFO: Expecting 41600 events.
[14:23:07.318]     INFO: 41600 events read in total (2707ms).
[14:23:07.319]     INFO: Test took 3943ms.
[14:23:07.352]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:08.076]     INFO: Expecting 41600 events.
[14:23:11.330]     INFO: 41600 events read in total (2727ms).
[14:23:11.331]     INFO: Test took 3960ms.
[14:23:11.364]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:12.091]     INFO: Expecting 41600 events.
[14:23:15.311]     INFO: 41600 events read in total (2693ms).
[14:23:15.312]     INFO: Test took 3930ms.
[14:23:15.346]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:16.069]     INFO: Expecting 41600 events.
[14:23:19.305]     INFO: 41600 events read in total (2710ms).
[14:23:19.307]     INFO: Test took 3944ms.
[14:23:19.341]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:20.062]     INFO: Expecting 41600 events.
[14:23:23.302]     INFO: 41600 events read in total (2713ms).
[14:23:23.303]     INFO: Test took 3943ms.
[14:23:23.337]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:24.061]     INFO: Expecting 41600 events.
[14:23:27.300]     INFO: 41600 events read in total (2713ms).
[14:23:27.301]     INFO: Test took 3946ms.
[14:23:27.334]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:28.058]     INFO: Expecting 41600 events.
[14:23:31.286]     INFO: 41600 events read in total (2701ms).
[14:23:31.287]     INFO: Test took 3936ms.
[14:23:31.320]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:32.047]     INFO: Expecting 41600 events.
[14:23:35.278]     INFO: 41600 events read in total (2705ms).
[14:23:35.279]     INFO: Test took 3941ms.
[14:23:35.313]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:36.036]     INFO: Expecting 41600 events.
[14:23:39.277]     INFO: 41600 events read in total (2714ms).
[14:23:39.278]     INFO: Test took 3946ms.
[14:23:39.311]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:40.038]     INFO: Expecting 41600 events.
[14:23:43.281]     INFO: 41600 events read in total (2716ms).
[14:23:43.282]     INFO: Test took 3951ms.
[14:23:43.316]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:44.037]     INFO: Expecting 41600 events.
[14:23:47.277]     INFO: 41600 events read in total (2713ms).
[14:23:47.278]     INFO: Test took 3945ms.
[14:23:47.312]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:48.033]     INFO: Expecting 41600 events.
[14:23:51.262]     INFO: 41600 events read in total (2702ms).
[14:23:51.263]     INFO: Test took 3932ms.
[14:23:51.296]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:52.021]     INFO: Expecting 41600 events.
[14:23:55.113]     INFO: 41600 events read in total (2565ms).
[14:23:55.114]     INFO: Test took 3799ms.
[14:23:55.148]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:55.512]     INFO: enter test to run
[14:24:18.950]     INFO:   test: HighRate no parameter change
[14:24:18.950]     INFO:   running: highrate
[14:24:18.951]     INFO:    ----------------------------------------------------------------------
[14:24:18.952]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:18.952]     INFO:    ----------------------------------------------------------------------
[14:24:19.569]     INFO: Expecting 208000 events.
[14:24:31.423]     INFO: 208000 events read in total (11327ms).
[14:24:31.426]     INFO: Test took 12465ms.
[14:24:31.566]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:31.820]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    1
[14:24:31.820]     INFO: number of red-efficiency pixels:    78   34   71  137  113  121  134  105   96  139  114  104  108   53   24   29
[14:24:31.820]     INFO: number of X-ray hits detected:    61274 40050 64424 100492 108476 106837 106256 82222 82808 105933 97226 80571 82353 48334 19637 26438
[14:24:31.820]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:24:31.820]     INFO: number of Vcal hits detected:  207921 207966 207926 207860 207886 207873 207859 207892 207903 207860 207884 207894 207887 207898 207970 207922
[14:24:31.820]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:24:31.820]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:24:31.820]     INFO: X-ray hit rate [MHz/cm2]:  18.0 11.7 18.9 29.5 31.8 31.3 31.1 24.1 24.3 31.0 28.5 23.6 24.1 14.2 5.8 7.7
[14:24:31.820]     INFO: PixTestHighRate::doXPixelAlive() done
[14:24:31.866]     INFO: PixTest::       pg_setup set to default.
[14:24:31.878]     INFO: enter test to run
[14:24:45.534]     INFO:   test: HighRate no parameter change
[14:24:45.534]     INFO:   running: highrate
[14:24:45.536]     INFO:    ----------------------------------------------------------------------
[14:24:45.536]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:45.536]     INFO:    ----------------------------------------------------------------------
[14:24:46.149]     INFO: Expecting 208000 events.
[14:24:59.668]     INFO: 208000 events read in total (12992ms).
[14:24:59.673]     INFO: Test took 14129ms.
[14:24:59.957]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:00.255]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    1
[14:25:00.255]     INFO: number of red-efficiency pixels:   219  105  219  438  384  403  468  343  276  422  326  312  308  162   36   58
[14:25:00.255]     INFO: number of X-ray hits detected:    126850 83930 134098 207207 223612 220858 220099 171067 171754 219591 200190 166022 170262 100579 41771 55029
[14:25:00.255]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:00.255]     INFO: number of Vcal hits detected:  207766 207889 207759 207530 207589 207566 207488 207629 207710 207549 207658 207668 207677 207780 207963 207893
[14:25:00.255]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:25:00.255]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[14:25:00.255]     INFO: X-ray hit rate [MHz/cm2]:  37.2 24.6 39.3 60.7 65.5 64.7 64.5 50.1 50.3 64.4 58.7 48.7 49.9 29.5 12.2 16.1
[14:25:00.255]     INFO: PixTestHighRate::doXPixelAlive() done
[14:25:00.301]     INFO: PixTest::       pg_setup set to default.
[14:25:00.317]     INFO: enter test to run
[14:25:13.606]     INFO:   test: HighRate no parameter change
[14:25:13.606]     INFO:   running: highrate
[14:25:13.607]     INFO:    ----------------------------------------------------------------------
[14:25:13.607]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:25:13.607]     INFO:    ----------------------------------------------------------------------
[14:25:14.222]     INFO: Expecting 208000 events.
[14:25:29.664]     INFO: 208000 events read in total (14915ms).
[14:25:29.671]     INFO: Test took 16053ms.
[14:25:30.097]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:30.445]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    1
[14:25:30.445]     INFO: number of red-efficiency pixels:   489  209  510 1139  955  907 1257  837  576  941  712  744  800  309   90  103
[14:25:30.445]     INFO: number of X-ray hits detected:    196454 130257 207053 322975 347262 342476 341810 266174 267635 341036 311367 259175 265481 156285 64974 86288
[14:25:30.445]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:30.445]     INFO: number of Vcal hits detected:  207417 207778 207352 206552 206825 206860 206334 206981 207344 206845 207188 207135 207069 207611 207907 207845
[14:25:30.445]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.9 99.7 99.4 99.5 99.5 99.3 99.5 99.7 99.5 99.6 99.6 99.6 99.9 100.0 100.0
[14:25:30.445]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.7 99.3 99.4 99.5 99.2 99.5 99.7 99.4 99.6 99.6 99.6 99.8 100.0 99.9
[14:25:30.445]     INFO: X-ray hit rate [MHz/cm2]:  57.6 38.2 60.7 94.7 101.8 100.4 100.2 78.0 78.4 100.0 91.3 76.0 77.8 45.8 19.0 25.3
[14:25:30.445]     INFO: PixTestHighRate::doXPixelAlive() done
[14:25:30.492]     INFO: PixTest::       pg_setup set to default.
[14:25:30.509]     INFO: enter test to run
[14:25:37.062]     INFO:   test: exit no parameter change
[14:25:37.620]    QUIET: Connection to board 33 closed.
[14:25:37.632]     INFO: pXar: this is the end, my friend