[14:06:34.939]     INFO: *** Welcome to pxar ***
[14:06:34.939]     INFO: *** Today: 2016/06/30
[14:06:35.173]     INFO: *** Version: v1.9.0-814-g7497
[14:06:35.173]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//dacParameters35_C15.dat
[14:06:35.220]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:06:35.220]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:06:35.229]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:06:35.329]     INFO:         clk: 4
[14:06:35.329]     INFO:         ctr: 4
[14:06:35.329]     INFO:         sda: 19
[14:06:35.329]     INFO:         tin: 9
[14:06:35.329]     INFO:         level: 15
[14:06:35.329]     INFO:         triggerdelay: 0
[14:06:35.329]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:06:35.329]     INFO: Log level: INFO
[14:06:35.346]    QUIET: Connection to board DTB_WREKRL opened.
[14:06:35.350]     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:06:35.352]     INFO: RPC call hashes of host and DTB match: 398089610
[14:06:36.882]     INFO: DUT info: 
[14:06:36.882]     INFO: The DUT currently contains the following objects:
[14:06:36.882]     INFO:  2 TBM Cores tbm08c (2 ON)
[14:06:36.882]     INFO: 	TBM Core alpha (0): 7 registers set
[14:06:36.882]     INFO: 	TBM Core beta  (1): 7 registers set
[14:06:36.882]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:06:36.882]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:36.882]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:37.291]     INFO: enter 'restricted' command line mode
[14:06:37.291]     INFO: enter test to run
[14:06:42.700]     INFO:   test: PixelAlive no parameter change
[14:06:42.700]     INFO:   running: pixelalive
[14:06:42.709]     INFO:    ----------------------------------------------------------------------
[14:06:42.709]     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:06:42.709]     INFO:    ----------------------------------------------------------------------
[14:06:43.026]     INFO: Expecting 41600 events.
[14:06:47.368]     INFO: 41600 events read in total (3623ms).
[14:06:47.537]     INFO: Test took 4825ms.
[14:06:47.548]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:47.810]     INFO: PixTestAlive::aliveTest() done
[14:06:47.810]     INFO: number of dead pixels (per ROC):     3    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:06:47.841]     INFO: enter test to run
[14:07:46.964]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:07:46.964]     INFO:   running: highrate
[14:07:46.964]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:07:47.178]     INFO:    ----------------------------------------------------------------------
[14:07:47.178]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:07:47.178]     INFO:    ----------------------------------------------------------------------
[14:07:47.178]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:07:47.179]     INFO: edge/corner pixel THR is adjusted
[14:07:47.179]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:07:48.138]     INFO: Collecting data for 5 seconds...
[14:07:53.157]     INFO: Done with hot pixel readout
[14:08:04.773]     INFO: PixTest::       pg_setup set to default.
[14:08:04.774]     INFO: 13 hot pixels found in step 0
[14:08:05.784]     INFO: Collecting data for 5 seconds...
[14:08:10.803]     INFO: Done with hot pixel readout
[14:08:22.344]     INFO: PixTest::       pg_setup set to default.
[14:08:22.344]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.345]     INFO: 9 hot pixels found in step 1
[14:08:23.336]     INFO: Collecting data for 5 seconds...
[14:08:28.353]     INFO: Done with hot pixel readout
[14:08:39.926]     INFO: PixTest::       pg_setup set to default.
[14:08:39.926]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:39.927]     INFO: 12 hot pixels found in step 2
[14:08:40.916]     INFO: Collecting data for 5 seconds...
[14:08:45.933]     INFO: Done with hot pixel readout
[14:08:57.200]     INFO: PixTest::       pg_setup set to default.
[14:08:57.201]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:57.201]     INFO: 9 hot pixels found in step 3
[14:08:58.191]     INFO: Collecting data for 5 seconds...
[14:09:03.209]     INFO: Done with hot pixel readout
[14:09:14.538]     INFO: PixTest::       pg_setup set to default.
[14:09:14.538]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:14.539]     INFO: 7 hot pixels found in step 4
[14:09:15.528]     INFO: Collecting data for 5 seconds...
[14:09:20.546]     INFO: Done with hot pixel readout
[14:09:31.775]     INFO: PixTest::       pg_setup set to default.
[14:09:31.775]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:31.776]     INFO: 10 hot pixels found in step 5
[14:09:32.766]     INFO: Collecting data for 5 seconds...
[14:09:37.784]     INFO: Done with hot pixel readout
[14:09:48.975]     INFO: PixTest::       pg_setup set to default.
[14:09:48.976]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:48.976]     INFO: 8 hot pixels found in step 6
[14:09:49.966]     INFO: Collecting data for 5 seconds...
[14:09:54.984]     INFO: Done with hot pixel readout
[14:10:06.578]     INFO: PixTest::       pg_setup set to default.
[14:10:06.578]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:06.579]     INFO: 4 hot pixels found in step 7
[14:10:07.569]     INFO: Collecting data for 5 seconds...
[14:10:12.589]     INFO: Done with hot pixel readout
[14:10:24.184]     INFO: PixTest::       pg_setup set to default.
[14:10:24.185]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:24.185]     INFO: 2 hot pixels found in step 8
[14:10:25.175]     INFO: Collecting data for 5 seconds...
[14:10:30.192]     INFO: Done with hot pixel readout
[14:10:41.965]     INFO: PixTest::       pg_setup set to default.
[14:10:41.965]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:41.965]     INFO: 2 hot pixels found in step 9
[14:10:42.956]     INFO: Collecting data for 5 seconds...
[14:10:47.977]     INFO: Done with hot pixel readout
[14:10:59.356]     INFO: PixTest::       pg_setup set to default.
[14:10:59.357]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:59.357]     INFO: 2 hot pixels found in step 10
[14:11:00.347]     INFO: Collecting data for 5 seconds...
[14:11:05.367]     INFO: Done with hot pixel readout
[14:11:16.966]     INFO: PixTest::       pg_setup set to default.
[14:11:16.966]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:16.967]     INFO: 2 hot pixels found in step 11
[14:11:17.957]     INFO: Collecting data for 5 seconds...
[14:11:22.977]     INFO: Done with hot pixel readout
[14:11:34.626]     INFO: PixTest::       pg_setup set to default.
[14:11:34.626]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:34.627]     INFO: 3 hot pixels found in step 12
[14:11:35.617]     INFO: Collecting data for 5 seconds...
[14:11:40.636]     INFO: Done with hot pixel readout
[14:11:52.256]     INFO: PixTest::       pg_setup set to default.
[14:11:52.256]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:52.256]     INFO: 4 hot pixels found in step 13
[14:11:53.246]     INFO: Collecting data for 5 seconds...
[14:11:58.262]     INFO: Done with hot pixel readout
[14:12:09.788]     INFO: PixTest::       pg_setup set to default.
[14:12:09.788]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:09.789]     INFO: 4 hot pixels found in step 14
[14:12:09.822]     INFO: 4 hot pixels could not be trimmed and have been masked.
[14:12:09.826]     INFO: PixTest::trimHotPixels() done
[14:12:09.826]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat
[14:12:09.831]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C1.dat
[14:12:09.837]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C2.dat
[14:12:09.843]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C3.dat
[14:12:09.849]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C4.dat
[14:12:09.854]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C5.dat
[14:12:09.859]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C6.dat
[14:12:09.864]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C7.dat
[14:12:09.869]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C8.dat
[14:12:09.874]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C9.dat
[14:12:09.879]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C10.dat
[14:12:09.885]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C11.dat
[14:12:09.890]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C12.dat
[14:12:09.895]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C13.dat
[14:12:09.900]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C14.dat
[14:12:09.905]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:12:09.910]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:12:09.921]     INFO: enter test to run
[14:12:56.354]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:12:56.354]     INFO:   running: highrate
[14:12:56.358]     INFO:    ----------------------------------------------------------------------
[14:12:56.358]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:12:56.358]     INFO:    ----------------------------------------------------------------------
[14:12:56.358]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:12:56.358]     INFO: edge/corner pixel THR is adjusted
[14:12:56.358]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:12:57.316]     INFO: Collecting data for 1 seconds...
[14:12:58.320]     INFO: Done with hot pixel readout
[14:13:02.195]     INFO: PixTest::       pg_setup set to default.
[14:13:02.196]     INFO: 0 hot pixels found in step 0
[14:13:02.201]     INFO: 0 hot pixels could not be trimmed and have been masked.
[14:13:02.296]     INFO: PixTest::trimHotPixels() done
[14:13:02.296]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat
[14:13:02.307]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C1.dat
[14:13:02.312]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C2.dat
[14:13:02.317]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C3.dat
[14:13:02.322]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C4.dat
[14:13:02.328]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C5.dat
[14:13:02.333]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C6.dat
[14:13:02.338]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C7.dat
[14:13:02.343]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C8.dat
[14:13:02.349]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C9.dat
[14:13:02.354]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C10.dat
[14:13:02.359]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C11.dat
[14:13:02.381]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C12.dat
[14:13:02.393]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C13.dat
[14:13:02.403]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C14.dat
[14:13:02.409]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:13:02.414]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-03_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:13:02.430]     INFO: enter test to run
[14:13:38.089]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[14:13:38.089]     INFO:   running: xray
[14:13:38.090]     INFO:    ----------------------------------------------------------------------
[14:13:38.090]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:13:38.090]     INFO:    ----------------------------------------------------------------------
[14:13:39.052]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:13:50.843]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:14:19.695]     INFO: Resuming triggers.
[14:14:31.490]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:15:00.856]     INFO: Resuming triggers.
[14:15:12.651]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:15:42.067]     INFO: Resuming triggers.
[14:15:53.857]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:16:23.313]     INFO: Resuming triggers.
[14:16:35.103]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:17:04.434]     INFO: Resuming triggers.
[14:17:16.223]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:17:45.578]     INFO: Resuming triggers.
[14:17:57.370]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:18:26.649]     INFO: Resuming triggers.
[14:18:38.442]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:19:07.736]     INFO: Resuming triggers.
[14:19:13.734]     INFO: data taking finished, elapsed time: 100 seconds.
[14:19:28.971]     INFO: PixTest::       pg_setup set to default.
[14:19:28.974]     INFO: PixTestXray::doPhRun() done
[14:19:29.109]     INFO: enter test to run
[14:20:27.638]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[14:20:27.639]     INFO:   running: xray
[14:20:27.640]     INFO:    ----------------------------------------------------------------------
[14:20:27.640]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:20:27.640]     INFO:    ----------------------------------------------------------------------
[14:20:28.606]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:20:35.695]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:21:06.747]     INFO: Resuming triggers.
[14:21:13.832]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:21:44.333]     INFO: Resuming triggers.
[14:21:51.422]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:22:22.778]     INFO: Resuming triggers.
[14:22:29.866]     INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:23:01.399]     INFO: Resuming triggers.
[14:23:08.486]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:23:39.018]     INFO: Resuming triggers.
[14:23:46.106]     INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:24:16.217]     INFO: Resuming triggers.
[14:24:23.299]     INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:24:53.473]     INFO: Resuming triggers.
[14:25:00.557]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:25:30.781]     INFO: Resuming triggers.
[14:25:37.869]     INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:26:08.015]     INFO: Resuming triggers.
[14:26:15.101]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:26:45.225]     INFO: Resuming triggers.
[14:26:52.306]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:27:22.554]     INFO: Resuming triggers.
[14:27:29.639]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:27:59.803]     INFO: Resuming triggers.
[14:28:06.889]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:28:37.004]     INFO: Resuming triggers.
[14:28:44.086]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:29:14.259]     INFO: Resuming triggers.
[14:29:15.404]     INFO: data taking finished, elapsed time: 100 seconds.
[14:29:20.644]     INFO: PixTest::       pg_setup set to default.
[14:29:20.647]     INFO: PixTestXray::doPhRun() done
[14:29:20.799]     INFO: enter test to run
[14:30:12.635]     INFO:   test: HighRate no parameter change
[14:30:12.635]     INFO:   running: highrate
[14:30:12.648]     INFO:    ----------------------------------------------------------------------
[14:30:12.648]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:30:12.648]     INFO:    ----------------------------------------------------------------------
[14:30:12.804]     INFO: Expecting 768 events.
[14:30:13.938]     INFO: 768 events read in total (418ms).
[14:30:13.938]     INFO: Test took 1269ms.
[14:30:14.741]     INFO: Expecting 41600 events.
[14:30:17.828]     INFO: 41600 events read in total (2560ms).
[14:30:17.829]     INFO: Test took 3866ms.
[14:30:17.862]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:18.590]     INFO: Expecting 41600 events.
[14:30:21.791]     INFO: 41600 events read in total (2674ms).
[14:30:21.791]     INFO: Test took 3912ms.
[14:30:21.824]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:22.553]     INFO: Expecting 41600 events.
[14:30:25.763]     INFO: 41600 events read in total (2683ms).
[14:30:25.764]     INFO: Test took 3922ms.
[14:30:25.796]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:26.526]     INFO: Expecting 41600 events.
[14:30:29.689]     INFO: 41600 events read in total (2636ms).
[14:30:29.690]     INFO: Test took 3876ms.
[14:30:29.722]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:30.452]     INFO: Expecting 41600 events.
[14:30:33.682]     INFO: 41600 events read in total (2703ms).
[14:30:33.683]     INFO: Test took 3944ms.
[14:30:33.715]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:34.443]     INFO: Expecting 41600 events.
[14:30:37.655]     INFO: 41600 events read in total (2685ms).
[14:30:37.656]     INFO: Test took 3924ms.
[14:30:37.688]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:38.418]     INFO: Expecting 41600 events.
[14:30:41.652]     INFO: 41600 events read in total (2708ms).
[14:30:41.653]     INFO: Test took 3947ms.
[14:30:41.685]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:42.414]     INFO: Expecting 41600 events.
[14:30:45.636]     INFO: 41600 events read in total (2695ms).
[14:30:45.637]     INFO: Test took 3933ms.
[14:30:45.669]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:46.398]     INFO: Expecting 41600 events.
[14:30:49.621]     INFO: 41600 events read in total (2697ms).
[14:30:49.622]     INFO: Test took 3935ms.
[14:30:49.654]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:50.383]     INFO: Expecting 41600 events.
[14:30:53.602]     INFO: 41600 events read in total (2692ms).
[14:30:53.603]     INFO: Test took 3933ms.
[14:30:53.635]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:54.361]     INFO: Expecting 41600 events.
[14:30:57.587]     INFO: 41600 events read in total (2699ms).
[14:30:57.588]     INFO: Test took 3935ms.
[14:30:57.620]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:58.348]     INFO: Expecting 41600 events.
[14:31:01.583]     INFO: 41600 events read in total (2708ms).
[14:31:01.584]     INFO: Test took 3947ms.
[14:31:01.616]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:02.345]     INFO: Expecting 41600 events.
[14:31:05.564]     INFO: 41600 events read in total (2692ms).
[14:31:05.565]     INFO: Test took 3932ms.
[14:31:05.597]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:06.323]     INFO: Expecting 41600 events.
[14:31:09.540]     INFO: 41600 events read in total (2690ms).
[14:31:09.541]     INFO: Test took 3926ms.
[14:31:09.573]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:10.302]     INFO: Expecting 41600 events.
[14:31:13.536]     INFO: 41600 events read in total (2707ms).
[14:31:13.537]     INFO: Test took 3946ms.
[14:31:13.569]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:14.298]     INFO: Expecting 41600 events.
[14:31:17.528]     INFO: 41600 events read in total (2703ms).
[14:31:17.529]     INFO: Test took 3942ms.
[14:31:17.562]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:18.286]     INFO: Expecting 41600 events.
[14:31:21.525]     INFO: 41600 events read in total (2712ms).
[14:31:21.526]     INFO: Test took 3946ms.
[14:31:21.557]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:22.283]     INFO: Expecting 41600 events.
[14:31:25.510]     INFO: 41600 events read in total (2700ms).
[14:31:25.511]     INFO: Test took 3936ms.
[14:31:25.542]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:26.271]     INFO: Expecting 41600 events.
[14:31:29.460]     INFO: 41600 events read in total (2664ms).
[14:31:29.461]     INFO: Test took 3902ms.
[14:31:29.493]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:30.224]     INFO: Expecting 41600 events.
[14:31:33.307]     INFO: 41600 events read in total (2556ms).
[14:31:33.308]     INFO: Test took 3796ms.
[14:31:33.340]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:33.708]     INFO: enter test to run
[14:31:55.026]     INFO:   test: HighRate no parameter change
[14:31:55.026]     INFO:   running: highrate
[14:31:55.028]     INFO:    ----------------------------------------------------------------------
[14:31:55.028]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:31:55.028]     INFO:    ----------------------------------------------------------------------
[14:31:55.671]     INFO: Expecting 208000 events.
[14:32:07.535]     INFO: 208000 events read in total (11337ms).
[14:32:07.538]     INFO: Test took 12501ms.
[14:32:07.677]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:07.929]     INFO: number of dead pixels (per ROC):     3    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:32:07.929]     INFO: number of red-efficiency pixels:    72   51   89  117  146  113  134   83   90   81  123  101  107   54   22   28
[14:32:07.929]     INFO: number of X-ray hits detected:    59357 39833 63604 98638 108004 109912 113141 77924 70886 89952 89293 74215 78067 46673 21325 24145
[14:32:07.929]     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:32:07.929]     INFO: number of Vcal hits detected:  207779 207949 207910 207880 207852 207884 207858 207914 207909 207918 207875 207897 207893 207944 207978 207972
[14:32:07.929]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[14:32:07.929]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0
[14:32:07.929]     INFO: X-ray hit rate [MHz/cm2]:  17.4 11.7 18.6 28.9 31.7 32.2 33.2 22.8 20.8 26.4 26.2 21.8 22.9 13.7 6.3 7.1
[14:32:07.929]     INFO: PixTestHighRate::doXPixelAlive() done
[14:32:07.975]     INFO: PixTest::       pg_setup set to default.
[14:32:07.992]     INFO: enter test to run
[14:32:45.314]     INFO:   test: HighRate no parameter change
[14:32:45.314]     INFO:   running: highrate
[14:32:45.315]     INFO:    ----------------------------------------------------------------------
[14:32:45.315]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:32:45.315]     INFO:    ----------------------------------------------------------------------
[14:32:45.935]     INFO: Expecting 208000 events.
[14:32:59.288]     INFO: 208000 events read in total (12826ms).
[14:32:59.296]     INFO: Test took 13971ms.
[14:32:59.579]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:59.876]     INFO: number of dead pixels (per ROC):     3    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:32:59.876]     INFO: number of red-efficiency pixels:   209  121  233  323  370  447  375  303  246  248  363  246  276  131   53   46
[14:32:59.876]     INFO: number of X-ray hits detected:    119654 80263 129125 199001 219314 221581 227594 159191 142903 181540 182475 149256 157478 93764 43752 48498
[14:32:59.877]     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:32:59.877]     INFO: number of Vcal hits detected:  207622 207873 207741 207652 207605 207503 207584 207682 207747 207735 207611 207747 207713 207863 207946 207953
[14:32:59.877]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[14:32:59.877]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[14:32:59.877]     INFO: X-ray hit rate [MHz/cm2]:  35.1 23.5 37.8 58.3 64.3 64.9 66.7 46.7 41.9 53.2 53.5 43.7 46.2 27.5 12.8 14.2
[14:32:59.877]     INFO: PixTestHighRate::doXPixelAlive() done
[14:32:59.923]     INFO: PixTest::       pg_setup set to default.
[14:32:59.935]     INFO: enter test to run
[14:33:39.337]     INFO:   test: HighRate no parameter change
[14:33:39.337]     INFO:   running: highrate
[14:33:39.338]     INFO:    ----------------------------------------------------------------------
[14:33:39.339]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:33:39.339]     INFO:    ----------------------------------------------------------------------
[14:33:39.959]     INFO: Expecting 208000 events.
[14:33:55.593]     INFO: 208000 events read in total (15108ms).
[14:33:55.600]     INFO: Test took 16253ms.
[14:33:56.024]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:56.367]     INFO: number of dead pixels (per ROC):     3    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:33:56.367]     INFO: number of red-efficiency pixels:   418  230  562  748  852 1100  926  693  491  526  787  509  566  341   63   85
[14:33:56.367]     INFO: number of X-ray hits detected:    180823 121852 195780 301210 331884 334970 345417 240153 216597 275079 274690 227097 239885 143261 65405 73794
[14:33:56.367]     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:33:56.367]     INFO: number of Vcal hits detected:  207375 207751 207269 207138 207003 206624 206848 207133 207463 207426 207095 207419 207368 207609 207936 207912
[14:33:56.367]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.7 99.6 99.6 99.4 99.5 99.6 99.8 99.8 99.6 99.8 99.7 99.8 100.0 100.0
[14:33:56.367]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.6 99.6 99.5 99.3 99.4 99.6 99.7 99.7 99.6 99.7 99.7 99.8 100.0 100.0
[14:33:56.368]     INFO: X-ray hit rate [MHz/cm2]:  53.0 35.7 57.4 88.3 97.3 98.2 101.2 70.4 63.5 80.6 80.5 66.6 70.3 42.0 19.2 21.6
[14:33:56.368]     INFO: PixTestHighRate::doXPixelAlive() done
[14:33:56.413]     INFO: PixTest::       pg_setup set to default.
[14:33:56.430]     INFO: enter test to run
[14:34:24.985]     INFO:   test: exit no parameter change
[14:34:25.318]    QUIET: Connection to board 33 closed.
[14:34:25.327]     INFO: pXar: this is the end, my friend