[14:49:02.805]     INFO: *** Welcome to pxar ***
[14:49:02.805]     INFO: *** Today: 2016/07/11
[14:49:03.701]     INFO: *** Version: v1.9.0-814-g7497
[14:49:03.701]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//dacParameters35_C15.dat
[14:49:03.778]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:49:03.778]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[14:49:03.784]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[14:49:03.902]     INFO:         clk: 4
[14:49:03.902]     INFO:         ctr: 4
[14:49:03.902]     INFO:         sda: 19
[14:49:03.902]     INFO:         tin: 9
[14:49:03.902]     INFO:         level: 15
[14:49:03.902]     INFO:         triggerdelay: 0
[14:49:03.902]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:49:03.903]     INFO: Log level: INFO
[14:49:03.923]    QUIET: Connection to board DTB_WREKRL opened.
[14:49:03.927]     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:49:03.930]     INFO: RPC call hashes of host and DTB match: 398089610
[14:49:05.473]     INFO: DUT info: 
[14:49:05.473]     INFO: The DUT currently contains the following objects:
[14:49:05.473]     INFO:  2 TBM Cores tbm08c (2 ON)
[14:49:05.473]     INFO: 	TBM Core alpha (0): 7 registers set
[14:49:05.473]     INFO: 	TBM Core beta  (1): 7 registers set
[14:49:05.473]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:49:05.473]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.473]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.474]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:49:05.906]     INFO: enter 'restricted' command line mode
[14:49:05.906]     INFO: enter test to run
[14:49:16.067]     INFO:   test: PixelAlive no parameter change
[14:49:16.067]     INFO:   running: pixelalive
[14:49:16.142]     INFO:    ----------------------------------------------------------------------
[14:49:16.142]     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:49:16.142]     INFO:    ----------------------------------------------------------------------
[14:49:16.459]     INFO: Expecting 41600 events.
[14:49:20.774]     INFO: 41600 events read in total (3596ms).
[14:49:20.941]     INFO: Test took 4795ms.
[14:49:20.954]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:21.573]     INFO: PixTestAlive::aliveTest() done
[14:49:21.573]     INFO: number of dead pixels (per ROC):     0    0    0    0    1    2  160    0    2    0    2    0    0    0    0    0
[14:49:21.733]     INFO: enter test to run
[14:49:54.699]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:49:54.699]     INFO:   running: highrate
[14:49:54.712]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:49:54.987]     INFO:    ----------------------------------------------------------------------
[14:49:54.987]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:49:54.987]     INFO:    ----------------------------------------------------------------------
[14:49:54.987]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:49:54.987]     INFO: edge/corner pixel THR is adjusted
[14:49:54.987]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:49:55.947]     INFO: Collecting data for 5 seconds...
[14:50:00.962]     INFO: Done with hot pixel readout
[14:50:12.768]     INFO: PixTest::       pg_setup set to default.
[14:50:12.769]     INFO: 25 hot pixels found in step 0
[14:50:13.764]     INFO: Collecting data for 5 seconds...
[14:50:18.780]     INFO: Done with hot pixel readout
[14:50:30.596]     INFO: PixTest::       pg_setup set to default.
[14:50:30.596]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:30.597]     INFO: 41 hot pixels found in step 1
[14:50:31.589]     INFO: Collecting data for 5 seconds...
[14:50:36.604]     INFO: Done with hot pixel readout
[14:50:48.407]     INFO: PixTest::       pg_setup set to default.
[14:50:48.407]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:48.407]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:48.408]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:48.408]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:48.408]     INFO: 35 hot pixels found in step 2
[14:50:49.400]     INFO: Collecting data for 5 seconds...
[14:50:54.415]     INFO: Done with hot pixel readout
[14:51:06.253]     INFO: PixTest::       pg_setup set to default.
[14:51:06.254]     INFO: 22 hot pixels found in step 3
[14:51:07.247]     INFO: Collecting data for 5 seconds...
[14:51:12.262]     INFO: Done with hot pixel readout
[14:51:24.116]     INFO: PixTest::       pg_setup set to default.
[14:51:24.116]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:24.116]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:24.116]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:24.116]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:24.116]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:24.117]     INFO: 23 hot pixels found in step 4
[14:51:25.108]     INFO: Collecting data for 5 seconds...
[14:51:30.123]     INFO: Done with hot pixel readout
[14:51:41.924]     INFO: PixTest::       pg_setup set to default.
[14:51:41.924]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:41.925]     INFO: 23 hot pixels found in step 5
[14:51:42.917]     INFO: Collecting data for 5 seconds...
[14:51:47.934]     INFO: Done with hot pixel readout
[14:51:59.761]     INFO: PixTest::       pg_setup set to default.
[14:51:59.762]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:51:59.762]     INFO: 20 hot pixels found in step 6
[14:52:00.755]     INFO: Collecting data for 5 seconds...
[14:52:05.770]     INFO: Done with hot pixel readout
[14:52:17.626]     INFO: PixTest::       pg_setup set to default.
[14:52:17.627]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:52:17.627]     INFO: 33 hot pixels found in step 7
[14:52:18.619]     INFO: Collecting data for 5 seconds...
[14:52:23.635]     INFO: Done with hot pixel readout
[14:52:35.456]     INFO: PixTest::       pg_setup set to default.
[14:52:35.457]     INFO: 20 hot pixels found in step 8
[14:52:36.449]     INFO: Collecting data for 5 seconds...
[14:52:41.465]     INFO: Done with hot pixel readout
[14:52:53.292]     INFO: PixTest::       pg_setup set to default.
[14:52:53.293]     INFO: 17 hot pixels found in step 9
[14:52:54.285]     INFO: Collecting data for 5 seconds...
[14:52:59.300]     INFO: Done with hot pixel readout
[14:53:11.145]     INFO: PixTest::       pg_setup set to default.
[14:53:11.146]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:11.146]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:11.146]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:11.146]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:11.146]     INFO: 25 hot pixels found in step 10
[14:53:12.138]     INFO: Collecting data for 5 seconds...
[14:53:17.154]     INFO: Done with hot pixel readout
[14:53:28.979]     INFO: PixTest::       pg_setup set to default.
[14:53:28.980]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:28.980]     INFO: 14 hot pixels found in step 11
[14:53:29.973]     INFO: Collecting data for 5 seconds...
[14:53:34.989]     INFO: Done with hot pixel readout
[14:53:46.825]     INFO: PixTest::       pg_setup set to default.
[14:53:46.826]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:53:46.826]     INFO: 16 hot pixels found in step 12
[14:53:47.818]     INFO: Collecting data for 5 seconds...
[14:53:52.834]     INFO: Done with hot pixel readout
[14:54:04.677]     INFO: PixTest::       pg_setup set to default.
[14:54:04.678]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:54:04.678]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:54:04.678]     INFO: 16 hot pixels found in step 13
[14:54:05.671]     INFO: Collecting data for 5 seconds...
[14:54:10.687]     INFO: Done with hot pixel readout
[14:54:22.535]     INFO: PixTest::       pg_setup set to default.
[14:54:22.535]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[14:54:22.535]     INFO: 10 hot pixels found in step 14
[14:54:22.571]     INFO: 10 hot pixels could not be trimmed and have been masked.
[14:54:22.584]     INFO: PixTest::trimHotPixels() done
[14:54:22.584]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat
[14:54:22.596]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C1.dat
[14:54:22.602]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C2.dat
[14:54:22.607]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C3.dat
[14:54:22.613]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C4.dat
[14:54:22.618]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C5.dat
[14:54:22.623]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C6.dat
[14:54:22.628]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C7.dat
[14:54:22.633]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C8.dat
[14:54:22.638]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C9.dat
[14:54:22.644]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C10.dat
[14:54:22.649]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C11.dat
[14:54:22.654]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C12.dat
[14:54:22.659]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C13.dat
[14:54:22.665]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C14.dat
[14:54:22.670]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[14:54:22.675]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[14:54:22.685]     INFO: enter test to run
[14:55:28.960]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:55:28.960]     INFO:   running: highrate
[14:55:28.965]     INFO:    ----------------------------------------------------------------------
[14:55:28.965]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:55:28.965]     INFO:    ----------------------------------------------------------------------
[14:55:28.965]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:55:28.965]     INFO: edge/corner pixel THR is adjusted
[14:55:28.965]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:55:29.923]     INFO: Collecting data for 1 seconds...
[14:55:30.926]     INFO: Done with hot pixel readout
[14:55:34.936]     INFO: PixTest::       pg_setup set to default.
[14:55:34.936]     INFO: 0 hot pixels found in step 0
[14:55:34.942]     INFO: 0 hot pixels could not be trimmed and have been masked.
[14:55:35.035]     INFO: PixTest::trimHotPixels() done
[14:55:35.036]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat
[14:55:35.044]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C1.dat
[14:55:35.050]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C2.dat
[14:55:35.055]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C3.dat
[14:55:35.060]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C4.dat
[14:55:35.065]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C5.dat
[14:55:35.071]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C6.dat
[14:55:35.076]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C7.dat
[14:55:35.081]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C8.dat
[14:55:35.086]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C9.dat
[14:55:35.091]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C10.dat
[14:55:35.096]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C11.dat
[14:55:35.101]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C12.dat
[14:55:35.107]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C13.dat
[14:55:35.112]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C14.dat
[14:55:35.117]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[14:55:35.122]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-36_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[14:55:35.132]     INFO: enter test to run
[14:55:52.768]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[14:55:52.768]     INFO:   running: xray
[14:55:52.770]     INFO:    ----------------------------------------------------------------------
[14:55:52.770]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:55:52.770]     INFO:    ----------------------------------------------------------------------
[14:55:53.752]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:56:05.105]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:56:34.377]     INFO: Resuming triggers.
[14:56:45.732]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:57:15.178]     INFO: Resuming triggers.
[14:57:26.531]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:57:55.895]     INFO: Resuming triggers.
[14:58:07.251]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:58:36.577]     INFO: Resuming triggers.
[14:58:47.931]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:59:17.252]     INFO: Resuming triggers.
[14:59:28.606]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:59:57.981]     INFO: Resuming triggers.
[15:00:09.338]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:00:38.747]     INFO: Resuming triggers.
[15:00:50.104]     INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:01:19.471]     INFO: Resuming triggers.
[15:01:28.946]     INFO: data taking finished, elapsed time: 100 seconds.
[15:01:53.566]     INFO: PixTest::       pg_setup set to default.
[15:01:53.570]     INFO: PixTestXray::doPhRun() done
[15:01:53.707]     INFO: enter test to run
[15:02:33.990]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[15:02:33.990]     INFO:   running: xray
[15:02:33.991]     INFO:    ----------------------------------------------------------------------
[15:02:33.991]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[15:02:33.991]     INFO:    ----------------------------------------------------------------------
[15:02:34.965]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[15:02:41.612]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:03:11.555]     INFO: Resuming triggers.
[15:03:18.205]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:03:48.183]     INFO: Resuming triggers.
[15:03:54.836]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:04:24.777]     INFO: Resuming triggers.
[15:04:31.424]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:05:01.411]     INFO: Resuming triggers.
[15:05:08.059]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:05:37.990]     INFO: Resuming triggers.
[15:05:44.638]     INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:06:14.554]     INFO: Resuming triggers.
[15:06:21.205]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:06:51.108]     INFO: Resuming triggers.
[15:06:57.756]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:07:27.713]     INFO: Resuming triggers.
[15:07:34.360]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:08:04.324]     INFO: Resuming triggers.
[15:08:10.967]     INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:08:40.943]     INFO: Resuming triggers.
[15:08:47.587]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:09:17.572]     INFO: Resuming triggers.
[15:09:24.221]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:09:53.861]     INFO: Resuming triggers.
[15:10:00.507]     INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:10:30.414]     INFO: Resuming triggers.
[15:10:37.061]     INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:11:07.049]     INFO: Resuming triggers.
[15:11:13.696]     INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:11:43.742]     INFO: Resuming triggers.
[15:11:44.334]     INFO: data taking finished, elapsed time: 100 seconds.
[15:11:47.373]     INFO: PixTest::       pg_setup set to default.
[15:11:47.376]     INFO: PixTestXray::doPhRun() done
[15:11:47.528]     INFO: enter test to run
[15:12:15.658]     INFO:   test: HighRate no parameter change
[15:12:15.658]     INFO:   running: highrate
[15:12:15.659]     INFO:    ----------------------------------------------------------------------
[15:12:15.659]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:12:15.659]     INFO:    ----------------------------------------------------------------------
[15:12:15.799]     INFO: Expecting 768 events.
[15:12:16.935]     INFO: 768 events read in total (417ms).
[15:12:16.936]     INFO: Test took 1271ms.
[15:12:17.740]     INFO: Expecting 41600 events.
[15:12:20.792]     INFO: 41600 events read in total (2525ms).
[15:12:20.793]     INFO: Test took 3850ms.
[15:12:20.826]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:21.555]     INFO: Expecting 41600 events.
[15:12:24.735]     INFO: 41600 events read in total (2654ms).
[15:12:24.736]     INFO: Test took 3891ms.
[15:12:24.770]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:25.496]     INFO: Expecting 41600 events.
[15:12:28.713]     INFO: 41600 events read in total (2690ms).
[15:12:28.714]     INFO: Test took 3927ms.
[15:12:28.748]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:29.469]     INFO: Expecting 41600 events.
[15:12:32.700]     INFO: 41600 events read in total (2704ms).
[15:12:32.701]     INFO: Test took 3935ms.
[15:12:32.736]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:33.458]     INFO: Expecting 41600 events.
[15:12:36.707]     INFO: 41600 events read in total (2722ms).
[15:12:36.708]     INFO: Test took 3954ms.
[15:12:36.743]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:37.466]     INFO: Expecting 41600 events.
[15:12:40.708]     INFO: 41600 events read in total (2716ms).
[15:12:40.709]     INFO: Test took 3947ms.
[15:12:40.743]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:41.468]     INFO: Expecting 41600 events.
[15:12:44.703]     INFO: 41600 events read in total (2708ms).
[15:12:44.704]     INFO: Test took 3942ms.
[15:12:44.739]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:45.462]     INFO: Expecting 41600 events.
[15:12:48.721]     INFO: 41600 events read in total (2732ms).
[15:12:48.722]     INFO: Test took 3965ms.
[15:12:48.757]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:49.479]     INFO: Expecting 41600 events.
[15:12:52.731]     INFO: 41600 events read in total (2725ms).
[15:12:52.732]     INFO: Test took 3956ms.
[15:12:52.766]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:53.492]     INFO: Expecting 41600 events.
[15:12:56.736]     INFO: 41600 events read in total (2718ms).
[15:12:56.737]     INFO: Test took 3953ms.
[15:12:56.772]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:57.493]     INFO: Expecting 41600 events.
[15:13:00.748]     INFO: 41600 events read in total (2728ms).
[15:13:00.749]     INFO: Test took 3960ms.
[15:13:00.783]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:01.508]     INFO: Expecting 41600 events.
[15:13:04.778]     INFO: 41600 events read in total (2743ms).
[15:13:04.779]     INFO: Test took 3977ms.
[15:13:04.814]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:05.538]     INFO: Expecting 41600 events.
[15:13:08.773]     INFO: 41600 events read in total (2708ms).
[15:13:08.774]     INFO: Test took 3942ms.
[15:13:08.808]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:09.532]     INFO: Expecting 41600 events.
[15:13:12.779]     INFO: 41600 events read in total (2720ms).
[15:13:12.780]     INFO: Test took 3953ms.
[15:13:12.814]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:13.537]     INFO: Expecting 41600 events.
[15:13:16.777]     INFO: 41600 events read in total (2713ms).
[15:13:16.778]     INFO: Test took 3945ms.
[15:13:16.813]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:17.535]     INFO: Expecting 41600 events.
[15:13:20.783]     INFO: 41600 events read in total (2721ms).
[15:13:20.784]     INFO: Test took 3954ms.
[15:13:20.827]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:21.538]     INFO: Expecting 41600 events.
[15:13:24.781]     INFO: 41600 events read in total (2716ms).
[15:13:24.782]     INFO: Test took 3935ms.
[15:13:24.818]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:25.540]     INFO: Expecting 41600 events.
[15:13:28.792]     INFO: 41600 events read in total (2725ms).
[15:13:28.793]     INFO: Test took 3956ms.
[15:13:28.828]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:29.553]     INFO: Expecting 41600 events.
[15:13:32.787]     INFO: 41600 events read in total (2708ms).
[15:13:32.788]     INFO: Test took 3942ms.
[15:13:32.822]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:33.547]     INFO: Expecting 41600 events.
[15:13:36.643]     INFO: 41600 events read in total (2569ms).
[15:13:36.644]     INFO: Test took 3804ms.
[15:13:36.678]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:37.042]     INFO: enter test to run
[15:13:54.553]     INFO:   test: HighRate no parameter change
[15:13:54.553]     INFO:   running: highrate
[15:13:54.554]     INFO:    ----------------------------------------------------------------------
[15:13:54.554]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:13:54.554]     INFO:    ----------------------------------------------------------------------
[15:13:55.171]     INFO: Expecting 208000 events.
[15:14:07.126]     INFO: 208000 events read in total (11429ms).
[15:14:07.129]     INFO: Test took 12566ms.
[15:14:07.276]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:07.530]     INFO: number of dead pixels (per ROC):     0    0    0    0    1    2   89    0    2    0    2    0    0    0    0    0
[15:14:07.530]     INFO: number of red-efficiency pixels:    90   59   79  143  132  126  332  108   77  125  106   95  104   59   16   27
[15:14:07.530]     INFO: number of X-ray hits detected:    67990 45576 71691 110119 115708 120648 121663 87970 77332 98761 97862 83673 85004 52091 21268 23789
[15:14:07.530]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:14:07.530]     INFO: number of Vcal hits detected:  207907 207941 207919 207853 207817 207771 199930 207889 207824 207872 207791 207904 207894 207940 207983 207973
[15:14:07.530]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 98.2 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:14:07.530]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 96.1 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:14:07.530]     INFO: X-ray hit rate [MHz/cm2]:  19.9 13.4 21.0 32.3 33.9 35.4 35.7 25.8 22.7 28.9 28.7 24.5 24.9 15.3 6.2 7.0
[15:14:07.530]     INFO: PixTestHighRate::doXPixelAlive() done
[15:14:07.582]     INFO: PixTest::       pg_setup set to default.
[15:14:07.594]     INFO: enter test to run
[15:14:23.673]     INFO:   test: HighRate no parameter change
[15:14:23.673]     INFO:   running: highrate
[15:14:23.674]     INFO:    ----------------------------------------------------------------------
[15:14:23.674]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:14:23.674]     INFO:    ----------------------------------------------------------------------
[15:14:24.294]     INFO: Expecting 208000 events.
[15:14:37.972]     INFO: 208000 events read in total (13152ms).
[15:14:37.978]     INFO: Test took 14295ms.
[15:14:38.284]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:38.585]     INFO: number of dead pixels (per ROC):     0    0    0    0    1    2   65    0    2    0    2    0    0    0    0    0
[15:14:38.585]     INFO: number of red-efficiency pixels:   277  149  287  517  501  509  749  316  260  354  360  233  312  131   58   59
[15:14:38.586]     INFO: number of X-ray hits detected:    139828 92681 147296 224502 236378 247698 244305 181002 157899 202639 201271 173135 174663 106507 43934 49011
[15:14:38.586]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:14:38.586]     INFO: number of Vcal hits detected:  207702 207846 207677 207442 207414 207346 199497 207661 207633 207631 207511 207745 207669 207863 207941 207939
[15:14:38.586]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 97.4 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:14:38.586]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.7 99.7 95.9 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:14:38.586]     INFO: X-ray hit rate [MHz/cm2]:  41.0 27.2 43.2 65.8 69.3 72.6 71.6 53.1 46.3 59.4 59.0 50.7 51.2 31.2 12.9 14.4
[15:14:38.586]     INFO: PixTestHighRate::doXPixelAlive() done
[15:14:38.640]     INFO: PixTest::       pg_setup set to default.
[15:14:38.657]     INFO: enter test to run
[15:14:58.929]     INFO:   test: HighRate no parameter change
[15:14:58.929]     INFO:   running: highrate
[15:14:58.930]     INFO:    ----------------------------------------------------------------------
[15:14:58.930]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:14:58.930]     INFO:    ----------------------------------------------------------------------
[15:14:59.546]     INFO: Expecting 208000 events.
[15:15:15.094]     INFO: 208000 events read in total (15021ms).
[15:15:15.101]     INFO: Test took 16161ms.
[15:15:15.549]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:15.899]     INFO: number of dead pixels (per ROC):     0    0    0    0    1    2   63    0    2    0    2    0    0    0    0    0
[15:15:15.899]     INFO: number of red-efficiency pixels:   546  271  636 1178 1110 1091 1560  695  470  769  820  559  656  340  113   98
[15:15:15.900]     INFO: number of X-ray hits detected:    211533 139905 221167 339980 357839 372953 365574 272957 239738 305382 304033 260664 263143 160333 66571 74347
[15:15:15.900]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:15:15.900]     INFO: number of Vcal hits detected:  207318 207690 207208 206478 206561 206529 198202 207143 207381 207109 206925 207382 207251 207615 207883 207898
[15:15:15.900]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.9 99.7 99.3 99.4 99.4 96.8 99.6 99.8 99.6 99.6 99.7 99.7 99.8 99.9 100.0
[15:15:15.900]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.6 99.3 99.3 99.3 95.3 99.6 99.7 99.6 99.5 99.7 99.6 99.8 99.9 100.0
[15:15:15.900]     INFO: X-ray hit rate [MHz/cm2]:  62.0 41.0 64.8 99.7 104.9 109.3 107.2 80.0 70.3 89.5 89.1 76.4 77.1 47.0 19.5 21.8
[15:15:15.900]     INFO: PixTestHighRate::doXPixelAlive() done
[15:15:15.949]     INFO: PixTest::       pg_setup set to default.
[15:15:15.966]     INFO: enter test to run
[15:15:22.856]     INFO:   test: exit no parameter change
[15:15:23.161]    QUIET: Connection to board 33 closed.
[15:15:23.162]     INFO: pXar: this is the end, my friend