[12:02:39.127]     INFO: *** Welcome to pxar ***
[12:02:39.127]     INFO: *** Today: 2016/06/24
[12:02:39.645]     INFO: *** Version: v1.9.0-814-g7497
[12:02:39.645]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//dacParameters35_C15.dat
[12:02:39.706]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:02:39.706]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[12:02:39.717]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[12:02:39.839]     INFO:         clk: 4
[12:02:39.839]     INFO:         ctr: 4
[12:02:39.839]     INFO:         sda: 19
[12:02:39.839]     INFO:         tin: 9
[12:02:39.839]     INFO:         level: 15
[12:02:39.839]     INFO:         triggerdelay: 0
[12:02:39.839]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:02:39.839]     INFO: Log level: INFO
[12:02:39.857]    QUIET: Connection to board DTB_WREKRL opened.
[12:02:39.860]     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:     
------------------------------------------------------
[12:02:39.863]     INFO: RPC call hashes of host and DTB match: 398089610
[12:02:41.400]     INFO: DUT info: 
[12:02:41.400]     INFO: The DUT currently contains the following objects:
[12:02:41.400]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:02:41.400]     INFO: 	TBM Core alpha (0): 7 registers set
[12:02:41.400]     INFO: 	TBM Core beta  (1): 7 registers set
[12:02:41.401]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:02:41.401]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.401]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:41.833]     INFO: enter 'restricted' command line mode
[12:02:41.834]     INFO: enter test to run
[12:02:57.728]     INFO:   test: PixelAlive no parameter change
[12:02:57.728]     INFO:   running: pixelalive
[12:02:57.735]     INFO:    ----------------------------------------------------------------------
[12:02:57.735]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:02:57.735]     INFO:    ----------------------------------------------------------------------
[12:02:58.054]     INFO: Expecting 41600 events.
[12:03:02.411]     INFO: 41600 events read in total (3639ms).
[12:03:02.576]     INFO: Test took 4839ms.
[12:03:02.586]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:02.850]     INFO: PixTestAlive::aliveTest() done
[12:03:02.850]     INFO: number of dead pixels (per ROC):   197  101   51   45    1    1    0    0    0    0    0    0    0    0    0   56
[12:03:02.879]     INFO: enter test to run
[12:03:35.735]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:03:35.735]     INFO:   running: highrate
[12:03:35.773]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:03:36.045]     INFO:    ----------------------------------------------------------------------
[12:03:36.045]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:03:36.045]     INFO:    ----------------------------------------------------------------------
[12:03:36.045]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:03:36.045]     INFO: edge/corner pixel THR is adjusted
[12:03:36.045]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:03:37.029]     INFO: Collecting data for 5 seconds...
[12:03:42.046]     INFO: Done with hot pixel readout
[12:03:57.026]     INFO: PixTest::       pg_setup set to default.
[12:03:57.065]     INFO: 4034 hot pixels found in step 0
[12:03:58.063]     INFO: Collecting data for 5 seconds...
[12:04:03.079]     INFO: Done with hot pixel readout
[12:04:16.144]     INFO: PixTest::       pg_setup set to default.
[12:04:16.149]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:16.149]     INFO: 2252 hot pixels found in step 1
[12:04:17.150]     INFO: Collecting data for 5 seconds...
[12:04:22.167]     INFO: Done with hot pixel readout
[12:04:33.958]     INFO: PixTest::       pg_setup set to default.
[12:04:33.960]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:33.960]     INFO: 840 hot pixels found in step 2
[12:04:34.959]     INFO: Collecting data for 5 seconds...
[12:04:39.975]     INFO: Done with hot pixel readout
[12:04:52.149]     INFO: PixTest::       pg_setup set to default.
[12:04:52.150]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:52.150]     INFO: 204 hot pixels found in step 3
[12:04:53.146]     INFO: Collecting data for 5 seconds...
[12:04:58.162]     INFO: Done with hot pixel readout
[12:05:10.306]     INFO: PixTest::       pg_setup set to default.
[12:05:10.306]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:10.307]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:10.307]     INFO: 104 hot pixels found in step 4
[12:05:11.303]     INFO: Collecting data for 5 seconds...
[12:05:16.319]     INFO: Done with hot pixel readout
[12:05:28.423]     INFO: PixTest::       pg_setup set to default.
[12:05:28.424]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:28.424]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:28.424]     INFO: 86 hot pixels found in step 5
[12:05:29.419]     INFO: Collecting data for 5 seconds...
[12:05:34.435]     INFO: Done with hot pixel readout
[12:05:46.510]     INFO: PixTest::       pg_setup set to default.
[12:05:46.510]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:46.511]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:46.511]     INFO: 57 hot pixels found in step 6
[12:05:47.506]     INFO: Collecting data for 5 seconds...
[12:05:52.522]     INFO: Done with hot pixel readout
[12:06:04.624]     INFO: PixTest::       pg_setup set to default.
[12:06:04.624]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:04.625]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:04.625]     INFO: 41 hot pixels found in step 7
[12:06:05.619]     INFO: Collecting data for 5 seconds...
[12:06:10.636]     INFO: Done with hot pixel readout
[12:06:22.725]     INFO: PixTest::       pg_setup set to default.
[12:06:22.725]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:22.726]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:22.726]     INFO: 28 hot pixels found in step 8
[12:06:23.722]     INFO: Collecting data for 5 seconds...
[12:06:28.738]     INFO: Done with hot pixel readout
[12:06:40.794]     INFO: PixTest::       pg_setup set to default.
[12:06:40.794]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:40.795]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:40.795]     INFO: 23 hot pixels found in step 9
[12:06:41.789]     INFO: Collecting data for 5 seconds...
[12:06:46.806]     INFO: Done with hot pixel readout
[12:06:59.097]     INFO: PixTest::       pg_setup set to default.
[12:06:59.097]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:59.099]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:59.099]     INFO: 37 hot pixels found in step 10
[12:07:00.102]     INFO: Collecting data for 5 seconds...
[12:07:05.122]     INFO: Done with hot pixel readout
[12:07:17.175]     INFO: PixTest::       pg_setup set to default.
[12:07:17.175]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:17.176]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:17.176]     INFO: 15 hot pixels found in step 11
[12:07:18.171]     INFO: Collecting data for 5 seconds...
[12:07:23.190]     INFO: Done with hot pixel readout
[12:07:35.208]     INFO: PixTest::       pg_setup set to default.
[12:07:35.208]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:35.209]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:35.209]     INFO: 15 hot pixels found in step 12
[12:07:36.206]     INFO: Collecting data for 5 seconds...
[12:07:41.225]     INFO: Done with hot pixel readout
[12:07:53.196]     INFO: PixTest::       pg_setup set to default.
[12:07:53.196]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:53.197]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:53.197]     INFO: 19 hot pixels found in step 13
[12:07:54.192]     INFO: Collecting data for 5 seconds...
[12:07:59.210]     INFO: Done with hot pixel readout
[12:08:11.133]     INFO: PixTest::       pg_setup set to default.
[12:08:11.133]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:08:11.134]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:08:11.134]     INFO: 16 hot pixels found in step 14
[12:08:11.181]     INFO: 16 hot pixels could not be trimmed and have been masked.
[12:08:11.185]     INFO: PixTest::trimHotPixels() done
[12:08:11.185]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat
[12:08:11.191]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C1.dat
[12:08:11.215]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C2.dat
[12:08:11.227]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C3.dat
[12:08:11.238]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C4.dat
[12:08:11.243]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C5.dat
[12:08:11.249]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C6.dat
[12:08:11.254]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C7.dat
[12:08:11.261]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C8.dat
[12:08:11.266]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C9.dat
[12:08:11.272]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C10.dat
[12:08:11.277]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C11.dat
[12:08:11.282]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C12.dat
[12:08:11.288]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C13.dat
[12:08:11.293]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C14.dat
[12:08:11.298]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:11.304]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:11.315]     INFO: enter test to run
[12:08:40.637]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:08:40.637]     INFO:   running: highrate
[12:08:40.642]     INFO:    ----------------------------------------------------------------------
[12:08:40.642]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:08:40.642]     INFO:    ----------------------------------------------------------------------
[12:08:40.642]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:08:40.642]     INFO: edge/corner pixel THR is adjusted
[12:08:40.642]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:08:41.600]     INFO: Collecting data for 1 seconds...
[12:08:42.603]     INFO: Done with hot pixel readout
[12:08:46.485]     INFO: PixTest::       pg_setup set to default.
[12:08:46.486]     INFO: 0 hot pixels found in step 0
[12:08:46.492]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:08:46.586]     INFO: PixTest::trimHotPixels() done
[12:08:46.586]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat
[12:08:46.598]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C1.dat
[12:08:46.603]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C2.dat
[12:08:46.608]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C3.dat
[12:08:46.613]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C4.dat
[12:08:46.619]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C5.dat
[12:08:46.624]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C6.dat
[12:08:46.629]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C7.dat
[12:08:46.634]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C8.dat
[12:08:46.639]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C9.dat
[12:08:46.644]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C10.dat
[12:08:46.649]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C11.dat
[12:08:46.654]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C12.dat
[12:08:46.659]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C13.dat
[12:08:46.664]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C14.dat
[12:08:46.670]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:46.675]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-03_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:46.684]     INFO: enter test to run
[12:09:08.437]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:09:08.437]     INFO:   running: xray
[12:09:08.438]     INFO:    ----------------------------------------------------------------------
[12:09:08.438]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:09:08.438]     INFO:    ----------------------------------------------------------------------
[12:09:09.402]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:09:21.023]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:09:51.281]     INFO: Resuming triggers.
[12:10:02.908]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:10:33.122]     INFO: Resuming triggers.
[12:10:44.748]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:11:14.282]     INFO: Resuming triggers.
[12:11:25.913]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:11:55.520]     INFO: Resuming triggers.
[12:12:07.155]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:12:36.726]     INFO: Resuming triggers.
[12:12:48.364]     INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:13:17.953]     INFO: Resuming triggers.
[12:13:29.583]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:13:59.132]     INFO: Resuming triggers.
[12:14:10.766]     INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:14:40.401]     INFO: Resuming triggers.
[12:14:47.694]     INFO: data taking finished, elapsed time: 100 seconds.
[12:15:06.424]     INFO: PixTest::       pg_setup set to default.
[12:15:06.427]     INFO: PixTestXray::doPhRun() done
[12:15:06.596]     INFO: enter test to run
[12:15:25.339]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:15:25.339]     INFO:   running: xray
[12:15:25.340]     INFO:    ----------------------------------------------------------------------
[12:15:25.340]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:15:25.340]     INFO:    ----------------------------------------------------------------------
[12:15:26.304]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:15:33.389]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:16:03.686]     INFO: Resuming triggers.
[12:16:10.772]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:16:41.175]     INFO: Resuming triggers.
[12:16:48.256]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:17:18.234]     INFO: Resuming triggers.
[12:17:25.314]     INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:17:55.011]     INFO: Resuming triggers.
[12:18:02.092]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:18:31.773]     INFO: Resuming triggers.
[12:18:38.851]     INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:19:09.740]     INFO: Resuming triggers.
[12:19:16.818]     INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:19:47.025]     INFO: Resuming triggers.
[12:19:54.104]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:20:24.172]     INFO: Resuming triggers.
[12:20:31.252]     INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:21:02.301]     INFO: Resuming triggers.
[12:21:09.381]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:21:40.708]     INFO: Resuming triggers.
[12:21:47.788]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[12:22:18.945]     INFO: Resuming triggers.
[12:22:26.029]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[12:22:56.526]     INFO: Resuming triggers.
[12:23:03.609]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:23:34.043]     INFO: Resuming triggers.
[12:23:41.124]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:24:11.467]     INFO: Resuming triggers.
[12:24:12.662]     INFO: data taking finished, elapsed time: 100 seconds.
[12:24:18.162]     INFO: PixTest::       pg_setup set to default.
[12:24:18.165]     INFO: PixTestXray::doPhRun() done
[12:24:18.316]     INFO: enter test to run
[12:24:41.791]     INFO:   test: HighRate no parameter change
[12:24:41.791]     INFO:   running: highrate
[12:24:41.846]     INFO:    ----------------------------------------------------------------------
[12:24:41.846]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:24:41.846]     INFO:    ----------------------------------------------------------------------
[12:24:42.002]     INFO: Expecting 768 events.
[12:24:43.137]     INFO: 768 events read in total (419ms).
[12:24:43.137]     INFO: Test took 1270ms.
[12:24:43.940]     INFO: Expecting 41600 events.
[12:24:46.998]     INFO: 41600 events read in total (2531ms).
[12:24:46.999]     INFO: Test took 3854ms.
[12:24:47.033]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:47.758]     INFO: Expecting 41600 events.
[12:24:50.940]     INFO: 41600 events read in total (2656ms).
[12:24:50.941]     INFO: Test took 3892ms.
[12:24:50.975]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:51.700]     INFO: Expecting 41600 events.
[12:24:54.924]     INFO: 41600 events read in total (2697ms).
[12:24:54.925]     INFO: Test took 3932ms.
[12:24:54.961]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:55.679]     INFO: Expecting 41600 events.
[12:24:58.923]     INFO: 41600 events read in total (2717ms).
[12:24:58.924]     INFO: Test took 3945ms.
[12:24:58.959]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:59.682]     INFO: Expecting 41600 events.
[12:25:02.919]     INFO: 41600 events read in total (2710ms).
[12:25:02.920]     INFO: Test took 3942ms.
[12:25:02.955]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:03.679]     INFO: Expecting 41600 events.
[12:25:06.927]     INFO: 41600 events read in total (2722ms).
[12:25:06.928]     INFO: Test took 3955ms.
[12:25:06.963]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:07.687]     INFO: Expecting 41600 events.
[12:25:10.935]     INFO: 41600 events read in total (2721ms).
[12:25:10.936]     INFO: Test took 3954ms.
[12:25:10.971]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:11.694]     INFO: Expecting 41600 events.
[12:25:14.931]     INFO: 41600 events read in total (2710ms).
[12:25:14.932]     INFO: Test took 3943ms.
[12:25:14.967]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:15.691]     INFO: Expecting 41600 events.
[12:25:18.935]     INFO: 41600 events read in total (2717ms).
[12:25:18.936]     INFO: Test took 3950ms.
[12:25:18.971]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:19.689]     INFO: Expecting 41600 events.
[12:25:22.945]     INFO: 41600 events read in total (2729ms).
[12:25:22.946]     INFO: Test took 3955ms.
[12:25:22.980]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:23.702]     INFO: Expecting 41600 events.
[12:25:26.953]     INFO: 41600 events read in total (2724ms).
[12:25:26.954]     INFO: Test took 3957ms.
[12:25:26.988]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:27.712]     INFO: Expecting 41600 events.
[12:25:30.960]     INFO: 41600 events read in total (2721ms).
[12:25:30.961]     INFO: Test took 3955ms.
[12:25:30.996]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:31.717]     INFO: Expecting 41600 events.
[12:25:34.970]     INFO: 41600 events read in total (2726ms).
[12:25:34.971]     INFO: Test took 3957ms.
[12:25:35.005]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:35.729]     INFO: Expecting 41600 events.
[12:25:38.977]     INFO: 41600 events read in total (2721ms).
[12:25:38.978]     INFO: Test took 3954ms.
[12:25:39.013]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:39.735]     INFO: Expecting 41600 events.
[12:25:42.986]     INFO: 41600 events read in total (2724ms).
[12:25:42.987]     INFO: Test took 3955ms.
[12:25:43.021]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:43.744]     INFO: Expecting 41600 events.
[12:25:47.005]     INFO: 41600 events read in total (2734ms).
[12:25:47.006]     INFO: Test took 3966ms.
[12:25:47.040]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:47.763]     INFO: Expecting 41600 events.
[12:25:51.013]     INFO: 41600 events read in total (2723ms).
[12:25:51.014]     INFO: Test took 3955ms.
[12:25:51.048]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:51.770]     INFO: Expecting 41600 events.
[12:25:55.011]     INFO: 41600 events read in total (2714ms).
[12:25:55.012]     INFO: Test took 3945ms.
[12:25:55.046]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:55.771]     INFO: Expecting 41600 events.
[12:25:58.982]     INFO: 41600 events read in total (2685ms).
[12:25:58.983]     INFO: Test took 3920ms.
[12:25:59.018]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:59.742]     INFO: Expecting 41600 events.
[12:26:02.856]     INFO: 41600 events read in total (2587ms).
[12:26:02.857]     INFO: Test took 3820ms.
[12:26:02.892]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:03.253]     INFO: enter test to run
[12:26:10.894]     INFO:   test: HighRate no parameter change
[12:26:10.894]     INFO:   running: highrate
[12:26:10.895]     INFO:    ----------------------------------------------------------------------
[12:26:10.895]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:26:10.895]     INFO:    ----------------------------------------------------------------------
[12:26:11.507]     INFO: Expecting 208000 events.
[12:26:23.421]     INFO: 208000 events read in total (11387ms).
[12:26:23.425]     INFO: Test took 12522ms.
[12:26:23.571]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:23.825]     INFO: number of dead pixels (per ROC):   196  101   51   44    1    1    0    0    0    0    0    0    0    0    0   57
[12:26:23.825]     INFO: number of red-efficiency pixels:   384  375  127  147  127  149  120   93   78  106  102   96  103   68   29  108
[12:26:23.825]     INFO: number of X-ray hits detected:    112314 108952 53853 91825 104688 111029 100002 75960 73692 92738 91953 78863 86338 50026 19909 23046
[12:26:23.825]     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:26:23.825]     INFO: number of Vcal hits detected:  197973 202623 205364 205512 207791 207800 207878 207903 207920 207892 207898 207902 207896 207932 207971 204820
[12:26:23.825]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.8 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 99.9
[12:26:23.825]     INFO: Vcal hit overall efficiency (%):  95.2 97.4 98.7 98.8 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 98.5
[12:26:23.825]     INFO: X-ray hit rate [MHz/cm2]:  32.9 31.9 15.8 26.9 30.7 32.5 29.3 22.3 21.6 27.2 27.0 23.1 25.3 14.7 5.8 6.8
[12:26:23.825]     INFO: PixTestHighRate::doXPixelAlive() done
[12:26:23.872]     INFO: PixTest::       pg_setup set to default.
[12:26:23.885]     INFO: enter test to run
[12:26:39.894]     INFO:   test: HighRate no parameter change
[12:26:39.894]     INFO:   running: highrate
[12:26:39.895]     INFO:    ----------------------------------------------------------------------
[12:26:39.895]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:26:39.895]     INFO:    ----------------------------------------------------------------------
[12:26:40.509]     INFO: Expecting 208000 events.
[12:26:53.879]     INFO: 208000 events read in total (12844ms).
[12:26:53.884]     INFO: Test took 13980ms.
[12:26:54.163]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:54.457]     INFO: number of dead pixels (per ROC):   196  101   51   44    1    1    0    0    0    0    0    0    0    0    0   57
[12:26:54.457]     INFO: number of red-efficiency pixels:   478  463  184  310  347  468  410  247  236  307  339  269  296  162   58  140
[12:26:54.457]     INFO: number of X-ray hits detected:    159591 145083 107303 180652 206403 218018 198205 150519 146372 184871 183411 157540 170907 98884 39594 43782
[12:26:54.457]     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:26:54.457]     INFO: number of Vcal hits detected:  197809 202520 205296 205320 207543 207446 207560 207733 207751 207680 207639 207713 207687 207828 207941 204778
[12:26:54.457]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.8 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 99.9
[12:26:54.457]     INFO: Vcal hit overall efficiency (%):  95.1 97.4 98.7 98.7 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 98.5
[12:26:54.457]     INFO: X-ray hit rate [MHz/cm2]:  46.8 42.5 31.5 53.0 60.5 63.9 58.1 44.1 42.9 54.2 53.8 46.2 50.1 29.0 11.6 12.8
[12:26:54.457]     INFO: PixTestHighRate::doXPixelAlive() done
[12:26:54.505]     INFO: PixTest::       pg_setup set to default.
[12:26:54.521]     INFO: enter test to run
[12:27:15.230]     INFO:   test: HighRate no parameter change
[12:27:15.230]     INFO:   running: highrate
[12:27:15.231]     INFO:    ----------------------------------------------------------------------
[12:27:15.231]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:27:15.231]     INFO:    ----------------------------------------------------------------------
[12:27:15.850]     INFO: Expecting 208000 events.
[12:27:30.954]     INFO: 208000 events read in total (14577ms).
[12:27:30.961]     INFO: Test took 15720ms.
[12:27:31.398]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:31.737]     INFO: number of dead pixels (per ROC):   198  101   51   45    1    1    0    0    0    0    0    0    0    0    0   57
[12:27:31.737]     INFO: number of red-efficiency pixels:   616  539  416  758  777 1172  971  484  501  696  851  599  747  395   82  184
[12:27:31.737]     INFO: number of X-ray hits detected:    209094 186059 166265 281888 318892 338671 307490 234074 226558 285926 283283 244588 265577 153786 61636 66740
[12:27:31.737]     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:27:31.737]     INFO: number of Vcal hits detected:  197635 202411 204997 204761 207012 206409 206826 207411 207433 207198 206973 207300 207131 207553 207916 204671
[12:27:31.737]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.7 99.8 99.6 99.6 99.3 99.5 99.7 99.8 99.7 99.6 99.7 99.6 99.8 100.0 99.8
[12:27:31.737]     INFO: Vcal hit overall efficiency (%):  95.0 97.3 98.6 98.4 99.5 99.2 99.4 99.7 99.7 99.6 99.5 99.7 99.6 99.8 100.0 98.4
[12:27:31.737]     INFO: X-ray hit rate [MHz/cm2]:  61.3 54.5 48.7 82.6 93.5 99.3 90.1 68.6 66.4 83.8 83.0 71.7 77.8 45.1 18.1 19.6
[12:27:31.737]     INFO: PixTestHighRate::doXPixelAlive() done
[12:27:31.786]     INFO: PixTest::       pg_setup set to default.
[12:27:31.804]     INFO: enter test to run
[12:27:50.317]     INFO:   test: exit no parameter change
[12:27:50.647]    QUIET: Connection to board 33 closed.
[12:27:50.659]     INFO: pXar: this is the end, my friend