[11:48:13.222]     INFO: *** Welcome to pxar ***
[11:48:13.222]     INFO: *** Today: 2016/09/09
[11:48:13.257]     INFO: *** Version: v1.9.0-818-g96727
[11:48:13.257]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C15.dat
[11:48:13.281]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:48:13.281]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:48:13.286]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:48:13.372]     INFO:         clk: 4
[11:48:13.372]     INFO:         ctr: 4
[11:48:13.372]     INFO:         sda: 19
[11:48:13.372]     INFO:         tin: 9
[11:48:13.372]     INFO:         level: 15
[11:48:13.372]     INFO:         triggerdelay: 0
[11:48:13.372]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:48:13.372]     INFO: Log level: INFO
[11:48:13.390]    QUIET: Connection to board DTB_WREKRL opened.
[11:48:13.393]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[11:48:13.396]     INFO: RPC call hashes of host and DTB match: 398089610
[11:48:14.929]     INFO: DUT info: 
[11:48:14.929]     INFO: The DUT currently contains the following objects:
[11:48:14.929]     INFO:  2 TBM Cores tbm08c (2 ON)
[11:48:14.929]     INFO: 	TBM Core alpha (0): 7 registers set
[11:48:14.929]     INFO: 	TBM Core beta  (1): 7 registers set
[11:48:14.929]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:48:14.929]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:15.333]     INFO: enter 'restricted' command line mode
[11:48:15.333]     INFO: enter test to run
[11:48:24.039]     INFO:   test: PixelAlive no parameter change
[11:48:24.039]     INFO:   running: pixelalive
[11:48:24.048]     INFO:    ----------------------------------------------------------------------
[11:48:24.048]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:48:24.048]     INFO:    ----------------------------------------------------------------------
[11:48:24.366]     INFO: Expecting 41600 events.
[11:48:28.698]     INFO: 41600 events read in total (3613ms).
[11:48:28.867]     INFO: Test took 4816ms.
[11:48:28.881]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:29.151]     INFO: PixTestAlive::aliveTest() done
[11:48:29.151]     INFO: number of dead pixels (per ROC):     0    0    0    2    0    0    0    0    0    0    0    0    0    1    0    0
[11:48:29.182]     INFO: enter test to run
[11:49:07.063]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:49:07.063]     INFO:   running: highrate
[11:49:07.076]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:49:07.330]     INFO:    ----------------------------------------------------------------------
[11:49:07.330]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:49:07.330]     INFO:    ----------------------------------------------------------------------
[11:49:07.330]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:49:07.330]     INFO: edge/corner pixel THR is adjusted
[11:49:07.330]     INFO: PixTestHighRate::trimHotPixels: step 0...
[11:49:08.289]     INFO: Collecting data for 5 seconds...
[11:49:13.306]     INFO: Done with hot pixel readout
[11:49:25.276]     INFO: PixTest::       pg_setup set to default.
[11:49:25.277]     INFO: 9 hot pixels found in step 0
[11:49:26.269]     INFO: Collecting data for 5 seconds...
[11:49:31.287]     INFO: Done with hot pixel readout
[11:49:43.112]     INFO: PixTest::       pg_setup set to default.
[11:49:43.113]     INFO: 14 hot pixels found in step 1
[11:49:44.110]     INFO: Collecting data for 5 seconds...
[11:49:49.129]     INFO: Done with hot pixel readout
[11:50:00.815]     INFO: PixTest::       pg_setup set to default.
[11:50:00.815]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:00.815]     INFO: 9 hot pixels found in step 2
[11:50:01.812]     INFO: Collecting data for 5 seconds...
[11:50:06.829]     INFO: Done with hot pixel readout
[11:50:18.531]     INFO: PixTest::       pg_setup set to default.
[11:50:18.532]     INFO: 7 hot pixels found in step 3
[11:50:19.528]     INFO: Collecting data for 5 seconds...
[11:50:24.547]     INFO: Done with hot pixel readout
[11:50:35.961]     INFO: PixTest::       pg_setup set to default.
[11:50:35.962]     INFO: 5 hot pixels found in step 4
[11:50:36.958]     INFO: Collecting data for 5 seconds...
[11:50:41.976]     INFO: Done with hot pixel readout
[11:50:53.393]     INFO: PixTest::       pg_setup set to default.
[11:50:53.394]     INFO: 9 hot pixels found in step 5
[11:50:54.390]     INFO: Collecting data for 5 seconds...
[11:50:59.407]     INFO: Done with hot pixel readout
[11:51:09.832]     INFO: PixTest::       pg_setup set to default.
[11:51:09.833]     INFO: 4 hot pixels found in step 6
[11:51:10.830]     INFO: Collecting data for 5 seconds...
[11:51:15.849]     INFO: Done with hot pixel readout
[11:51:27.064]     INFO: PixTest::       pg_setup set to default.
[11:51:27.065]     INFO: 5 hot pixels found in step 7
[11:51:28.060]     INFO: Collecting data for 5 seconds...
[11:51:33.079]     INFO: Done with hot pixel readout
[11:51:44.643]     INFO: PixTest::       pg_setup set to default.
[11:51:44.644]     INFO: 4 hot pixels found in step 8
[11:51:45.639]     INFO: Collecting data for 5 seconds...
[11:51:50.657]     INFO: Done with hot pixel readout
[11:52:02.557]     INFO: PixTest::       pg_setup set to default.
[11:52:02.557]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:02.558]     INFO: 4 hot pixels found in step 9
[11:52:03.556]     INFO: Collecting data for 5 seconds...
[11:52:08.574]     INFO: Done with hot pixel readout
[11:52:20.322]     INFO: PixTest::       pg_setup set to default.
[11:52:20.323]     INFO: 9 hot pixels found in step 10
[11:52:21.327]     INFO: Collecting data for 5 seconds...
[11:52:26.347]     INFO: Done with hot pixel readout
[11:52:37.697]     INFO: PixTest::       pg_setup set to default.
[11:52:37.698]     INFO: 5 hot pixels found in step 11
[11:52:38.694]     INFO: Collecting data for 5 seconds...
[11:52:43.713]     INFO: Done with hot pixel readout
[11:52:54.644]     INFO: PixTest::       pg_setup set to default.
[11:52:54.645]     INFO: 6 hot pixels found in step 12
[11:52:55.644]     INFO: Collecting data for 5 seconds...
[11:53:00.662]     INFO: Done with hot pixel readout
[11:53:11.633]     INFO: PixTest::       pg_setup set to default.
[11:53:11.634]     INFO: 1 hot pixels found in step 13
[11:53:12.631]     INFO: Collecting data for 5 seconds...
[11:53:17.649]     INFO: Done with hot pixel readout
[11:53:28.841]     INFO: PixTest::       pg_setup set to default.
[11:53:29.117]     INFO: 1 hot pixels found in step 14
[11:53:29.162]     INFO: 1 hot pixels could not be trimmed and have been masked.
[11:53:29.246]     INFO: PixTest::trimHotPixels() done
[11:53:29.281]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[11:53:29.287]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[11:53:29.294]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[11:53:29.299]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[11:53:29.305]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[11:53:29.310]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[11:53:29.316]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[11:53:29.321]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[11:53:29.327]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[11:53:29.332]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[11:53:29.338]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[11:53:29.343]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[11:53:29.348]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[11:53:29.354]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[11:53:29.359]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[11:53:29.365]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:53:29.370]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:53:29.402]     INFO: enter test to run
[11:54:02.133]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:54:02.133]     INFO:   running: highrate
[11:54:02.138]     INFO:    ----------------------------------------------------------------------
[11:54:02.138]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:54:02.138]     INFO:    ----------------------------------------------------------------------
[11:54:02.138]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:54:02.138]     INFO: edge/corner pixel THR is adjusted
[11:54:02.138]     INFO: PixTestHighRate::trimHotPixels: step 0...
[11:54:03.095]     INFO: Collecting data for 1 seconds...
[11:54:04.098]     INFO: Done with hot pixel readout
[11:54:08.249]     INFO: PixTest::       pg_setup set to default.
[11:54:08.250]     INFO: 0 hot pixels found in step 0
[11:54:08.256]     INFO: 0 hot pixels could not be trimmed and have been masked.
[11:54:08.346]     INFO: PixTest::trimHotPixels() done
[11:54:08.347]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[11:54:08.354]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[11:54:08.360]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[11:54:08.365]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[11:54:08.370]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[11:54:08.376]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[11:54:08.381]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[11:54:08.387]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[11:54:08.392]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[11:54:08.397]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[11:54:08.402]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[11:54:08.408]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[11:54:08.413]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[11:54:08.418]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[11:54:08.424]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[11:54:08.429]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:54:08.435]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:54:08.445]     INFO: enter test to run
[11:55:12.068]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[11:55:12.068]     INFO:   running: xray
[11:55:12.079]     INFO:    ----------------------------------------------------------------------
[11:55:12.080]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[11:55:12.080]     INFO:    ----------------------------------------------------------------------
[11:55:13.091]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[11:55:24.545]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:55:54.994]     INFO: Resuming triggers.
[11:56:06.445]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:56:36.254]     INFO: Resuming triggers.
[11:56:47.712]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:57:16.956]     INFO: Resuming triggers.
[11:57:28.412]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:57:57.732]     INFO: Resuming triggers.
[11:58:09.188]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:58:38.613]     INFO: Resuming triggers.
[11:58:50.068]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:59:19.481]     INFO: Resuming triggers.
[11:59:30.935]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:00:00.524]     INFO: Resuming triggers.
[12:00:11.979]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:00:41.478]     INFO: Resuming triggers.
[12:00:50.170]     INFO: data taking finished, elapsed time: 100 seconds.
[12:01:12.527]     INFO: PixTest::       pg_setup set to default.
[12:01:12.530]     INFO: PixTestXray::doPhRun() done
[12:01:12.768]     INFO: enter test to run
[12:02:13.313]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:02:13.313]     INFO:   running: xray
[12:02:13.315]     INFO:    ----------------------------------------------------------------------
[12:02:13.315]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:02:13.315]     INFO:    ----------------------------------------------------------------------
[12:02:14.279]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:02:20.000]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:02:51.623]     INFO: Resuming triggers.
[12:02:58.340]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:03:28.954]     INFO: Resuming triggers.
[12:03:35.676]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:04:06.480]     INFO: Resuming triggers.
[12:04:13.196]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:04:43.153]     INFO: Resuming triggers.
[12:04:49.871]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:05:20.383]     INFO: Resuming triggers.
[12:05:27.102]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:05:58.090]     INFO: Resuming triggers.
[12:06:04.802]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:06:36.018]     INFO: Resuming triggers.
[12:06:42.736]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:07:13.667]     INFO: Resuming triggers.
[12:07:20.384]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:07:51.526]     INFO: Resuming triggers.
[12:07:58.236]     INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:08:29.443]     INFO: Resuming triggers.
[12:08:36.155]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:09:06.699]     INFO: Resuming triggers.
[12:09:13.410]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:09:43.467]     INFO: Resuming triggers.
[12:09:50.180]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:10:20.212]     INFO: Resuming triggers.
[12:10:26.925]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:10:56.948]     INFO: Resuming triggers.
[12:11:03.273]     INFO: data taking finished, elapsed time: 100 seconds.
[12:11:31.840]     INFO: PixTest::       pg_setup set to default.
[12:11:31.843]     INFO: PixTestXray::doPhRun() done
[12:11:31.994]     INFO: enter test to run
[12:12:07.517]     INFO:   test: HighRate no parameter change
[12:12:07.517]     INFO:   running: highrate
[12:12:07.530]     INFO:    ----------------------------------------------------------------------
[12:12:07.530]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:12:07.530]     INFO:    ----------------------------------------------------------------------
[12:12:07.691]     INFO: Expecting 768 events.
[12:12:08.825]     INFO: 768 events read in total (419ms).
[12:12:08.825]     INFO: Test took 1269ms.
[12:12:09.628]     INFO: Expecting 41600 events.
[12:12:12.667]     INFO: 41600 events read in total (2512ms).
[12:12:12.668]     INFO: Test took 3782ms.
[12:12:12.701]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:13.430]     INFO: Expecting 41600 events.
[12:12:16.609]     INFO: 41600 events read in total (2652ms).
[12:12:16.610]     INFO: Test took 3892ms.
[12:12:16.644]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:17.370]     INFO: Expecting 41600 events.
[12:12:20.592]     INFO: 41600 events read in total (2695ms).
[12:12:20.593]     INFO: Test took 3931ms.
[12:12:20.626]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:21.351]     INFO: Expecting 41600 events.
[12:12:24.586]     INFO: 41600 events read in total (2708ms).
[12:12:24.587]     INFO: Test took 3942ms.
[12:12:24.621]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:25.342]     INFO: Expecting 41600 events.
[12:12:28.562]     INFO: 41600 events read in total (2694ms).
[12:12:28.563]     INFO: Test took 3924ms.
[12:12:28.598]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:29.323]     INFO: Expecting 41600 events.
[12:12:32.556]     INFO: 41600 events read in total (2706ms).
[12:12:32.557]     INFO: Test took 3941ms.
[12:12:32.592]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:33.315]     INFO: Expecting 41600 events.
[12:12:36.539]     INFO: 41600 events read in total (2697ms).
[12:12:36.540]     INFO: Test took 3931ms.
[12:12:36.574]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:37.295]     INFO: Expecting 41600 events.
[12:12:40.525]     INFO: 41600 events read in total (2703ms).
[12:12:40.546]     INFO: Test took 3954ms.
[12:12:40.580]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:41.284]     INFO: Expecting 41600 events.
[12:12:44.532]     INFO: 41600 events read in total (2721ms).
[12:12:44.533]     INFO: Test took 3934ms.
[12:12:44.567]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:45.291]     INFO: Expecting 41600 events.
[12:12:48.528]     INFO: 41600 events read in total (2711ms).
[12:12:48.529]     INFO: Test took 3945ms.
[12:12:48.564]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:49.287]     INFO: Expecting 41600 events.
[12:12:52.526]     INFO: 41600 events read in total (2712ms).
[12:12:52.527]     INFO: Test took 3944ms.
[12:12:52.561]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:53.287]     INFO: Expecting 41600 events.
[12:12:56.532]     INFO: 41600 events read in total (2719ms).
[12:12:56.533]     INFO: Test took 3954ms.
[12:12:56.567]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:57.289]     INFO: Expecting 41600 events.
[12:13:00.539]     INFO: 41600 events read in total (2723ms).
[12:13:00.540]     INFO: Test took 3955ms.
[12:13:00.574]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:01.295]     INFO: Expecting 41600 events.
[12:13:04.526]     INFO: 41600 events read in total (2704ms).
[12:13:04.527]     INFO: Test took 3935ms.
[12:13:04.561]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:05.287]     INFO: Expecting 41600 events.
[12:13:08.522]     INFO: 41600 events read in total (2708ms).
[12:13:08.523]     INFO: Test took 3943ms.
[12:13:08.557]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:09.282]     INFO: Expecting 41600 events.
[12:13:12.527]     INFO: 41600 events read in total (2718ms).
[12:13:12.528]     INFO: Test took 3952ms.
[12:13:12.562]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:13.284]     INFO: Expecting 41600 events.
[12:13:16.526]     INFO: 41600 events read in total (2715ms).
[12:13:16.527]     INFO: Test took 3947ms.
[12:13:16.561]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:17.285]     INFO: Expecting 41600 events.
[12:13:20.520]     INFO: 41600 events read in total (2708ms).
[12:13:20.521]     INFO: Test took 3942ms.
[12:13:20.555]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:21.279]     INFO: Expecting 41600 events.
[12:13:24.299]     INFO: 41600 events read in total (2494ms).
[12:13:24.300]     INFO: Test took 3727ms.
[12:13:24.334]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:25.061]     INFO: Expecting 41600 events.
[12:13:28.207]     INFO: 41600 events read in total (2619ms).
[12:13:28.208]     INFO: Test took 3855ms.
[12:13:28.242]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:28.596]     INFO: enter test to run
[12:13:39.773]     INFO:   test: HighRate no parameter change
[12:13:39.773]     INFO:   running: highrate
[12:13:39.774]     INFO:    ----------------------------------------------------------------------
[12:13:39.774]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:13:39.774]     INFO:    ----------------------------------------------------------------------
[12:13:40.410]     INFO: Expecting 208000 events.
[12:13:52.249]     INFO: 208000 events read in total (11312ms).
[12:13:52.252]     INFO: Test took 12449ms.
[12:13:52.399]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:52.652]     INFO: number of dead pixels (per ROC):     0    0    0    2    0    0    0    0    0    0    0    0    0    0    0    0
[12:13:52.652]     INFO: number of red-efficiency pixels:    81   68   96  123  145  135  170   92   79  121  128  115   88   90   27   30
[12:13:52.652]     INFO: number of X-ray hits detected:    70927 40587 64591 96874 105726 111728 118627 79935 73665 101357 99659 87399 90882 58650 22437 26031
[12:13:52.652]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:13:52.652]     INFO: number of Vcal hits detected:  207915 207931 207902 207776 207852 207863 207822 207905 207920 207878 207870 207882 207911 207904 207973 207969
[12:13:52.652]     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 99.9 100.0 100.0 100.0 100.0
[12:13:52.652]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[12:13:52.652]     INFO: X-ray hit rate [MHz/cm2]:  20.8 11.9 18.9 28.4 31.0 32.7 34.8 23.4 21.6 29.7 29.2 25.6 26.6 17.2 6.6 7.6
[12:13:52.652]     INFO: PixTestHighRate::doXPixelAlive() done
[12:13:52.702]     INFO: PixTest::       pg_setup set to default.
[12:13:52.719]     INFO: enter test to run
[12:14:33.524]     INFO:   test: HighRate no parameter change
[12:14:33.524]     INFO:   running: highrate
[12:14:33.525]     INFO:    ----------------------------------------------------------------------
[12:14:33.525]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:14:33.525]     INFO:    ----------------------------------------------------------------------
[12:14:34.145]     INFO: Expecting 208000 events.
[12:14:47.743]     INFO: 208000 events read in total (13071ms).
[12:14:47.748]     INFO: Test took 14214ms.
[12:14:48.038]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:48.336]     INFO: number of dead pixels (per ROC):     0    0    0    2    0    0    0    0    0    0    0    0    0    0    0    0
[12:14:48.336]     INFO: number of red-efficiency pixels:   281  172  287  449  487  421  589  289  250  370  459  385  311  275   44   68
[12:14:48.336]     INFO: number of X-ray hits detected:    145910 83767 132519 198740 218628 228892 244483 165210 151314 208421 205569 181148 188681 121330 47192 53982
[12:14:48.336]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:14:48.336]     INFO: number of Vcal hits detected:  207700 207814 207682 207426 207470 207549 207324 207691 207730 207603 207500 207590 207664 207700 207955 207931
[12:14:48.337]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[12:14:48.337]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:14:48.337]     INFO: X-ray hit rate [MHz/cm2]:  42.8 24.6 38.8 58.3 64.1 67.1 71.7 48.4 44.4 61.1 60.3 53.1 55.3 35.6 13.8 15.8
[12:14:48.337]     INFO: PixTestHighRate::doXPixelAlive() done
[12:14:48.384]     INFO: PixTest::       pg_setup set to default.
[12:14:48.399]     INFO: enter test to run
[12:15:15.724]     INFO:   test: HighRate no parameter change
[12:15:15.724]     INFO:   running: highrate
[12:15:15.725]     INFO:    ----------------------------------------------------------------------
[12:15:15.725]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:15:15.725]     INFO:    ----------------------------------------------------------------------
[12:15:16.340]     INFO: Expecting 208000 events.
[12:15:31.752]     INFO: 208000 events read in total (14886ms).
[12:15:31.760]     INFO: Test took 16024ms.
[12:15:32.182]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:32.527]     INFO: number of dead pixels (per ROC):     0    0    0    2    0    0    0    0    0    0    0    0    0    0    0    0
[12:15:32.527]     INFO: number of red-efficiency pixels:   619  325  649  928 1064  974 1485  597  481  760 1029  824  686  543  106   89
[12:15:32.527]     INFO: number of X-ray hits detected:    219430 125695 199441 299380 329350 343735 366536 248739 228195 313460 309450 273872 282100 181260 70653 82386
[12:15:32.528]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:15:32.528]     INFO: number of Vcal hits detected:  207197 207649 207184 206775 206637 206780 205925 207267 207470 207129 206662 206998 207210 207274 207889 207907
[12:15:32.528]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.8 99.6 99.5 99.4 99.5 99.1 99.7 99.8 99.6 99.4 99.6 99.7 99.7 100.0 100.0
[12:15:32.528]     INFO: Vcal hit overall efficiency (%):  99.6 99.8 99.6 99.4 99.3 99.4 99.0 99.6 99.7 99.6 99.4 99.5 99.6 99.7 99.9 100.0
[12:15:32.528]     INFO: X-ray hit rate [MHz/cm2]:  64.3 36.8 58.5 87.8 96.5 100.8 107.4 72.9 66.9 91.9 90.7 80.3 82.7 53.1 20.7 24.1
[12:15:32.528]     INFO: PixTestHighRate::doXPixelAlive() done
[12:15:32.579]     INFO: PixTest::       pg_setup set to default.
[12:15:32.597]     INFO: enter test to run
[12:16:08.155]     INFO:   test: exit no parameter change
[12:16:08.694]    QUIET: Connection to board 33 closed.
[12:16:08.825]     INFO: pXar: this is the end, my friend