[10:15:49.063]     INFO: *** Welcome to pxar ***
[10:15:49.063]     INFO: *** Today: 2016/08/03
[10:15:49.083]     INFO: *** Version: v1.9.0-818-g96727
[10:15:49.083]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//dacParameters35_C15.dat
[10:15:49.116]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:15:49.116]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//defaultMaskFile.dat
[10:15:49.121]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C15.dat
[10:15:49.243]     INFO:         clk: 4
[10:15:49.244]     INFO:         ctr: 4
[10:15:49.244]     INFO:         sda: 19
[10:15:49.244]     INFO:         tin: 9
[10:15:49.244]     INFO:         level: 15
[10:15:49.244]     INFO:         triggerdelay: 0
[10:15:49.244]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:15:49.244]     INFO: Log level: INFO
[10:15:49.259]    QUIET: Connection to board DTB_WREKRL opened.
[10:15:49.262]     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:     
------------------------------------------------------
[10:15:49.265]     INFO: RPC call hashes of host and DTB match: 398089610
[10:15:50.800]     INFO: DUT info: 
[10:15:50.800]     INFO: The DUT currently contains the following objects:
[10:15:50.800]     INFO:  2 TBM Cores tbm08c (2 ON)
[10:15:50.800]     INFO: 	TBM Core alpha (0): 7 registers set
[10:15:50.800]     INFO: 	TBM Core beta  (1): 7 registers set
[10:15:50.800]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:15:50.800]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.800]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:50.801]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:15:51.204]     INFO: enter 'restricted' command line mode
[10:15:51.204]     INFO: enter test to run
[10:16:03.639]     INFO:   test: PixelAlive no parameter change
[10:16:03.639]     INFO:   running: pixelalive
[10:16:03.648]     INFO:    ----------------------------------------------------------------------
[10:16:03.648]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:16:03.648]     INFO:    ----------------------------------------------------------------------
[10:16:03.972]     INFO: Expecting 41600 events.
[10:16:08.351]     INFO: 41600 events read in total (3661ms).
[10:16:08.519]     INFO: Test took 4868ms.
[10:16:08.525]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:08.798]     INFO: PixTestAlive::aliveTest() done
[10:16:08.798]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[10:16:08.844]     INFO: enter test to run
[10:18:15.630]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:18:15.630]     INFO:   running: highrate
[10:18:15.630]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:18:15.854]     INFO:    ----------------------------------------------------------------------
[10:18:15.854]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:18:15.854]     INFO:    ----------------------------------------------------------------------
[10:18:15.854]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:18:15.854]     INFO: edge/corner pixel THR is adjusted
[10:18:15.854]     INFO: PixTestHighRate::trimHotPixels: step 0...
[10:18:16.812]     INFO: Collecting data for 5 seconds...
[10:18:21.832]     INFO: Done with hot pixel readout
[10:18:33.445]     INFO: PixTest::       pg_setup set to default.
[10:18:33.446]     INFO: 19 hot pixels found in step 0
[10:18:34.434]     INFO: Collecting data for 5 seconds...
[10:18:39.454]     INFO: Done with hot pixel readout
[10:18:51.080]     INFO: PixTest::       pg_setup set to default.
[10:18:51.081]     INFO: 20 hot pixels found in step 1
[10:18:52.073]     INFO: Collecting data for 5 seconds...
[10:18:57.094]     INFO: Done with hot pixel readout
[10:19:08.600]     INFO: PixTest::       pg_setup set to default.
[10:19:08.601]     INFO: 17 hot pixels found in step 2
[10:19:09.591]     INFO: Collecting data for 5 seconds...
[10:19:14.613]     INFO: Done with hot pixel readout
[10:19:26.098]     INFO: PixTest::       pg_setup set to default.
[10:19:26.098]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:19:26.099]     INFO: 19 hot pixels found in step 3
[10:19:27.088]     INFO: Collecting data for 5 seconds...
[10:19:32.108]     INFO: Done with hot pixel readout
[10:19:43.530]     INFO: PixTest::       pg_setup set to default.
[10:19:43.530]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:19:43.531]     INFO: 11 hot pixels found in step 4
[10:19:44.520]     INFO: Collecting data for 5 seconds...
[10:19:49.542]     INFO: Done with hot pixel readout
[10:20:00.933]     INFO: PixTest::       pg_setup set to default.
[10:20:00.933]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:00.933]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:00.934]     INFO: 19 hot pixels found in step 5
[10:20:01.924]     INFO: Collecting data for 5 seconds...
[10:20:06.941]     INFO: Done with hot pixel readout
[10:20:18.230]     INFO: PixTest::       pg_setup set to default.
[10:20:18.230]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:18.230]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:18.231]     INFO: 9 hot pixels found in step 6
[10:20:19.220]     INFO: Collecting data for 5 seconds...
[10:20:24.237]     INFO: Done with hot pixel readout
[10:20:35.591]     INFO: PixTest::       pg_setup set to default.
[10:20:35.591]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:35.591]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:35.592]     INFO: 4 hot pixels found in step 7
[10:20:36.581]     INFO: Collecting data for 5 seconds...
[10:20:41.598]     INFO: Done with hot pixel readout
[10:20:52.923]     INFO: PixTest::       pg_setup set to default.
[10:20:52.923]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:52.923]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:52.923]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:20:52.924]     INFO: 11 hot pixels found in step 8
[10:20:53.914]     INFO: Collecting data for 5 seconds...
[10:20:58.931]     INFO: Done with hot pixel readout
[10:21:10.180]     INFO: PixTest::       pg_setup set to default.
[10:21:10.180]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:10.180]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:10.180]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:10.180]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:10.181]     INFO: 5 hot pixels found in step 9
[10:21:11.169]     INFO: Collecting data for 5 seconds...
[10:21:16.186]     INFO: Done with hot pixel readout
[10:21:27.527]     INFO: PixTest::       pg_setup set to default.
[10:21:27.527]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:27.527]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:27.528]     INFO: 3 hot pixels found in step 10
[10:21:28.517]     INFO: Collecting data for 5 seconds...
[10:21:33.534]     INFO: Done with hot pixel readout
[10:21:44.869]     INFO: PixTest::       pg_setup set to default.
[10:21:44.869]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:44.869]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:44.869]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:21:44.870]     INFO: 7 hot pixels found in step 11
[10:21:45.860]     INFO: Collecting data for 5 seconds...
[10:21:50.876]     INFO: Done with hot pixel readout
[10:22:02.162]     INFO: PixTest::       pg_setup set to default.
[10:22:02.162]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:22:02.162]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:22:02.162]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:22:02.163]     INFO: 6 hot pixels found in step 12
[10:22:03.152]     INFO: Collecting data for 5 seconds...
[10:22:08.169]     INFO: Done with hot pixel readout
[10:22:19.504]     INFO: PixTest::       pg_setup set to default.
[10:22:19.504]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[10:22:19.505]     INFO: 1 hot pixels found in step 13
[10:22:19.538]     INFO: 1 hot pixels could not be trimmed and have been masked.
[10:22:19.542]     INFO: PixTest::trimHotPixels() done
[10:22:19.542]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C0.dat
[10:22:19.547]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C1.dat
[10:22:19.553]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C2.dat
[10:22:19.559]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C3.dat
[10:22:19.565]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C4.dat
[10:22:19.570]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C5.dat
[10:22:19.576]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C6.dat
[10:22:19.581]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C7.dat
[10:22:19.586]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C8.dat
[10:22:19.591]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C9.dat
[10:22:19.596]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C10.dat
[10:22:19.601]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C11.dat
[10:22:19.607]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C12.dat
[10:22:19.612]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C13.dat
[10:22:19.617]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C14.dat
[10:22:19.623]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C15.dat
[10:22:19.628]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//defaultMaskFile.dat
[10:22:19.638]     INFO: enter test to run
[10:23:15.980]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:23:15.980]     INFO:   running: highrate
[10:23:15.985]     INFO:    ----------------------------------------------------------------------
[10:23:15.985]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:23:15.985]     INFO:    ----------------------------------------------------------------------
[10:23:15.985]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:23:15.985]     INFO: edge/corner pixel THR is adjusted
[10:23:15.985]     INFO: PixTestHighRate::trimHotPixels: step 0...
[10:23:16.942]     INFO: Collecting data for 1 seconds...
[10:23:17.946]     INFO: Done with hot pixel readout
[10:23:21.744]     INFO: PixTest::       pg_setup set to default.
[10:23:21.745]     INFO: 0 hot pixels found in step 0
[10:23:21.750]     INFO: 0 hot pixels could not be trimmed and have been masked.
[10:23:21.845]     INFO: PixTest::trimHotPixels() done
[10:23:21.845]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C0.dat
[10:23:21.855]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C1.dat
[10:23:21.861]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C2.dat
[10:23:21.866]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C3.dat
[10:23:21.871]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C4.dat
[10:23:21.876]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C5.dat
[10:23:21.882]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C6.dat
[10:23:21.887]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C7.dat
[10:23:21.892]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C8.dat
[10:23:21.897]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C9.dat
[10:23:21.902]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C10.dat
[10:23:21.908]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C11.dat
[10:23:21.913]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C12.dat
[10:23:21.918]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C13.dat
[10:23:21.924]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C14.dat
[10:23:21.929]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//trimParameters35_C15.dat
[10:23:21.934]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//defaultMaskFile.dat
[10:23:21.945]     INFO: enter test to run
[10:24:09.772]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[10:24:09.772]     INFO:   running: xray
[10:24:09.773]     INFO:    ----------------------------------------------------------------------
[10:24:09.773]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[10:24:09.773]     INFO:    ----------------------------------------------------------------------
[10:24:10.736]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[10:24:22.622]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:24:51.817]     INFO: Resuming triggers.
[10:25:03.707]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:25:32.909]     INFO: Resuming triggers.
[10:25:44.803]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[10:26:13.886]     INFO: Resuming triggers.
[10:26:25.775]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:26:38.956]    ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a181 80c0 43c8 43c8 291 2a2f 43c8 43c8 d5 2a69 43c9 43c9 43c8 43c9 e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a17b 8040 4388 4388 4388 4388 4388 64a 284c 4388 4388 759 264f 4388 e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a17c 80b1 4388 54a 264d 4388 4388 4388 492 224a 4388 4388 4388 4388 e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a17d 80c0 4388 4388 4388 4388 4388 4388 55 2445 438a 4388 e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a17e 8000 4388 754 244c 4388 4388 30d 2645 4388 84c 222d 4388 4388 4389 4cd 2a47 53c8 e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a17f 8040 43ca 43ca 43ca 805 2049 43ca 43ca 75c 2648 43ca 360 2845 43c9 43ca e000 c000 
[10:26:38.956]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a180 80b1 43c9 43c9 43c9 43c9 43c9 48c 2829 43c9 43c9 43c9 20 204f e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[10:26:40.082]    ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a047 8040 4388 4388 4388 4388 d2 2263 4388 250 2262 4388 81d 226b 4388 115 222e 4388 e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a041 80c0 43c8 43c8 152 224f 43c8 43c8 611 2282 43c9 43c8 20b 2065 43c9 652 2445 43c9 e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a042 8000 43c8 43c8 43c9 48a 282d 60b 2a4e 43c9 85d 2640 43c8 605 204d 43c9 43c9 459 2a65 485 2041 43c9 e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a043 8040 43c8 43c9 6dd 262e 43c8 43c9 43c8 43c8 43c8 43c8 15 264e e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a044 80b1 43c8 45a 2283 43c8 31d 2465 43c8 4cd 2841 43c8 83 2644 4c8 2a4a 4388 4388 721 2a5f c08 4388 e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a045 80c0 4388 4388 159 2445 4388 4388 241 2a29 4388 4388 4388 4c 2a0f 4388 e000 c000 
[10:26:40.082]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a046 8000 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[10:26:44.555]    ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15f 8040 438a 438a 212 2449 438a 438a 438a 438a 4389 438a e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a159 80c0 43c8 43c8 692 2040 691 282d 43c8 55b 224f 43c8 43c8 43c8 43c8 262 224f 43c8 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15a 8000 43c8 154 2a2c 43c8 43c8 43c8 4d0 2643 43c8 43c8 43c8 2e0 244e 2da 2882 43c8 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15b 8040 43c8 43c8 255 2a4e 43c8 44 248c 45a 204c 459 284f 43c8 40b 224f 43c8 43c8 43c8 43c8 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15c 80b1 43c8 43c8 cb 2240 43c8 6d9 2845 6cb 2068 4388 84d 264f 740 4388 4388 4388 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15d 80c0 4388 4388 45c 2042 4388 2cb 244e 848 2a47 4388 71b 244a 4388 612 2049 4388 438a 4388 e000 c000 
[10:26:44.555]    ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15e 8000 4388 4388 4388 4388 4388 4388 35b 2a45 4389 4388 860 2862 e000 c000 
[10:26:54.956]     INFO: Resuming triggers.
[10:27:06.848]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:27:36.048]     INFO: Resuming triggers.
[10:27:47.936]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[10:28:17.642]     INFO: Resuming triggers.
[10:28:29.534]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:28:59.112]     INFO: Resuming triggers.
[10:29:10.003]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:29:39.397]     INFO: Resuming triggers.
[10:29:44.611]     INFO: data taking finished, elapsed time: 100 seconds.
[10:29:57.739]     INFO: PixTest::       pg_setup set to default.
[10:29:57.742]     INFO: PixTestXray::doPhRun() done
[10:29:57.880]     INFO: enter test to run
[10:31:05.185]     INFO:   test: timing no parameter change
[10:31:05.185]     INFO:   running: timing
[10:31:05.188]     INFO: ######################################################################
[10:31:05.188]     INFO: PixTestTiming::doTest()
[10:31:05.188]     INFO: ######################################################################
[10:31:05.189]     INFO:    ----------------------------------------------------------------------
[10:31:05.189]     INFO:    PixTestTiming::TBMPhaseScan()
[10:31:05.189]     INFO:    ----------------------------------------------------------------------
[10:36:55.256]     INFO: TBM Phase Settings: 240
[10:36:55.256]     INFO: 400MHz Phase: 4
[10:36:55.256]     INFO: 160MHz Phase: 7
[10:36:55.256]     INFO: Functional Phase Area: 5
[10:36:55.259]     INFO: Test took 350071 ms.
[10:36:55.260]     INFO: PixTestTiming::TBMPhaseScan() done.
[10:36:55.260]     INFO:    ----------------------------------------------------------------------
[10:36:55.260]     INFO:    PixTestTiming::ROCDelayScan()
[10:36:55.260]     INFO:    ----------------------------------------------------------------------
[10:39:03.138]     INFO: ROC Delay Settings: 228
[10:39:03.138]     INFO: ROC Header-Trailer/Token Delay: 11
[10:39:03.138]     INFO: ROC Port 0 Delay: 4
[10:39:03.138]     INFO: ROC Port 1 Delay: 4
[10:39:03.138]     INFO: Functional ROC Area: 5
[10:39:03.141]     INFO: Test took 127881 ms.
[10:39:03.141]     INFO: PixTestTiming::ROCDelayScan() done.
[10:39:03.141]     INFO:    ----------------------------------------------------------------------
[10:39:03.141]     INFO:    PixTestTiming::TimingTest()
[10:39:03.141]     INFO:    ----------------------------------------------------------------------
[10:39:19.241]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:34.191]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:49.157]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:04.210]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:19.337]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:34.410]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:49.592]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:04.660]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:19.750]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:34.687]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:35.064]     INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO:    Read back bit status: 1
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO:    Timings are good!
[10:41:35.076]     INFO:    ----------------------------------------------------------------------
[10:41:35.076]     INFO: Test took 151935 ms.
[10:41:35.076]     INFO: PixTestTiming::TimingTest() done.
[10:41:35.076]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:41:35.076]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-20_FPIXTest-17C-FNAL-160729-0950_2016-07-29_09h50m_1469803811/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:41:35.076]     INFO: PixTestTiming::doTest took 629891 ms.
[10:41:35.076]     INFO: PixTestTiming::doTest() done
[10:41:35.076]     INFO: Write out TBMPhaseScan_0_V0
[10:41:35.076]     INFO: Write out TBMPhaseScan_1_V0
[10:41:35.077]     INFO: Write out CombinedTBMPhaseScan_V0
[10:41:35.077]     INFO: Write out ROCDelayScan3_V0
[10:41:35.078]     INFO: enter test to run
[10:42:47.796]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[10:42:47.796]     INFO:   running: xray
[10:42:47.798]     INFO:    ----------------------------------------------------------------------
[10:42:47.798]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[10:42:47.798]     INFO:    ----------------------------------------------------------------------
[10:42:48.762]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[10:43:00.656]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:43:30.770]     INFO: Resuming triggers.
[10:43:42.671]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:44:12.140]     INFO: Resuming triggers.
[10:44:24.037]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[10:44:53.226]     INFO: Resuming triggers.
[10:45:05.126]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:45:34.362]     INFO: Resuming triggers.
[10:45:46.256]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:46:15.403]     INFO: Resuming triggers.
[10:46:27.303]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[10:46:56.475]     INFO: Resuming triggers.
[10:47:08.371]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:47:37.459]     INFO: Resuming triggers.
[10:47:49.356]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:48:18.245]     INFO: Resuming triggers.
[10:48:23.410]     INFO: data taking finished, elapsed time: 100 seconds.
[10:48:36.351]     INFO: PixTest::       pg_setup set to default.
[10:48:36.354]     INFO: PixTestXray::doPhRun() done
[10:48:36.488]     INFO: enter test to run
[10:49:42.065]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[10:49:42.066]     INFO:   running: xray
[10:49:42.067]     INFO:    ----------------------------------------------------------------------
[10:49:42.067]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[10:49:42.067]     INFO:    ----------------------------------------------------------------------
[10:49:43.033]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[10:49:50.306]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[10:50:20.297]     INFO: Resuming triggers.
[10:50:27.573]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[10:50:57.603]     INFO: Resuming triggers.
[10:51:04.881]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[10:51:34.890]     INFO: Resuming triggers.
[10:51:42.166]     INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[10:52:12.584]     INFO: Resuming triggers.
[10:52:19.861]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:52:50.374]     INFO: Resuming triggers.
[10:52:57.654]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[10:53:27.907]     INFO: Resuming triggers.
[10:53:35.193]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[10:54:05.512]     INFO: Resuming triggers.
[10:54:12.795]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:54:44.425]     INFO: Resuming triggers.
[10:54:51.706]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:55:22.871]     INFO: Resuming triggers.
[10:55:30.152]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:56:00.668]     INFO: Resuming triggers.
[10:56:07.943]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:56:37.939]     INFO: Resuming triggers.
[10:56:45.213]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[10:57:15.272]     INFO: Resuming triggers.
[10:57:22.550]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:57:52.636]     INFO: Resuming triggers.
[10:57:58.373]     INFO: data taking finished, elapsed time: 100 seconds.
[10:58:22.336]     INFO: PixTest::       pg_setup set to default.
[10:58:22.339]     INFO: PixTestXray::doPhRun() done
[10:58:22.486]     INFO: enter test to run
[11:00:55.645]     INFO:   test: HighRate no parameter change
[11:00:55.645]     INFO:   running: highrate
[11:00:55.646]     INFO:    ----------------------------------------------------------------------
[11:00:55.646]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:00:55.646]     INFO:    ----------------------------------------------------------------------
[11:00:55.787]     INFO: Expecting 768 events.
[11:00:56.920]     INFO: 768 events read in total (418ms).
[11:00:56.921]     INFO: Test took 1269ms.
[11:00:57.724]     INFO: Expecting 41600 events.
[11:01:00.814]     INFO: 41600 events read in total (2563ms).
[11:01:00.815]     INFO: Test took 3888ms.
[11:01:00.845]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:01.579]     INFO: Expecting 41600 events.
[11:01:04.747]     INFO: 41600 events read in total (2641ms).
[11:01:04.748]     INFO: Test took 3885ms.
[11:01:04.779]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:05.510]     INFO: Expecting 41600 events.
[11:01:08.698]     INFO: 41600 events read in total (2662ms).
[11:01:08.699]     INFO: Test took 3904ms.
[11:01:08.730]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:09.461]     INFO: Expecting 41600 events.
[11:01:12.636]     INFO: 41600 events read in total (2648ms).
[11:01:12.637]     INFO: Test took 3889ms.
[11:01:12.675]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:13.401]     INFO: Expecting 41600 events.
[11:01:16.604]     INFO: 41600 events read in total (2676ms).
[11:01:16.605]     INFO: Test took 3912ms.
[11:01:16.637]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:17.364]     INFO: Expecting 41600 events.
[11:01:20.564]     INFO: 41600 events read in total (2673ms).
[11:01:20.565]     INFO: Test took 3911ms.
[11:01:20.596]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:21.324]     INFO: Expecting 41600 events.
[11:01:24.512]     INFO: 41600 events read in total (2661ms).
[11:01:24.513]     INFO: Test took 3900ms.
[11:01:24.545]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:25.272]     INFO: Expecting 41600 events.
[11:01:28.484]     INFO: 41600 events read in total (2686ms).
[11:01:28.485]     INFO: Test took 3922ms.
[11:01:28.516]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:29.244]     INFO: Expecting 41600 events.
[11:01:32.461]     INFO: 41600 events read in total (2690ms).
[11:01:32.462]     INFO: Test took 3929ms.
[11:01:32.493]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:33.224]     INFO: Expecting 41600 events.
[11:01:36.433]     INFO: 41600 events read in total (2682ms).
[11:01:36.434]     INFO: Test took 3924ms.
[11:01:36.465]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:37.195]     INFO: Expecting 41600 events.
[11:01:40.424]     INFO: 41600 events read in total (2703ms).
[11:01:40.425]     INFO: Test took 3943ms.
[11:01:40.456]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:41.183]     INFO: Expecting 41600 events.
[11:01:44.391]     INFO: 41600 events read in total (2682ms).
[11:01:44.392]     INFO: Test took 3918ms.
[11:01:44.423]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:45.150]     INFO: Expecting 41600 events.
[11:01:48.356]     INFO: 41600 events read in total (2679ms).
[11:01:48.357]     INFO: Test took 3918ms.
[11:01:48.387]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:49.116]     INFO: Expecting 41600 events.
[11:01:52.328]     INFO: 41600 events read in total (2685ms).
[11:01:52.329]     INFO: Test took 3924ms.
[11:01:52.359]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:53.088]     INFO: Expecting 41600 events.
[11:01:56.290]     INFO: 41600 events read in total (2675ms).
[11:01:56.291]     INFO: Test took 3915ms.
[11:01:56.321]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:57.052]     INFO: Expecting 41600 events.
[11:02:00.251]     INFO: 41600 events read in total (2672ms).
[11:02:00.252]     INFO: Test took 3913ms.
[11:02:00.282]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:01.015]     INFO: Expecting 41600 events.
[11:02:04.211]     INFO: 41600 events read in total (2669ms).
[11:02:04.212]     INFO: Test took 3912ms.
[11:02:04.242]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:04.973]     INFO: Expecting 41600 events.
[11:02:08.181]     INFO: 41600 events read in total (2681ms).
[11:02:08.181]     INFO: Test took 3921ms.
[11:02:08.212]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:08.941]     INFO: Expecting 41600 events.
[11:02:12.105]     INFO: 41600 events read in total (2637ms).
[11:02:12.106]     INFO: Test took 3877ms.
[11:02:12.136]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:12.868]     INFO: Expecting 41600 events.
[11:02:15.858]     INFO: 41600 events read in total (2463ms).
[11:02:15.858]     INFO: Test took 3704ms.
[11:02:15.888]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:16.262]     INFO: enter test to run
[11:02:38.276]     INFO:   test: HighRate no parameter change
[11:02:38.276]     INFO:   running: highrate
[11:02:38.277]     INFO:    ----------------------------------------------------------------------
[11:02:38.277]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:02:38.277]     INFO:    ----------------------------------------------------------------------
[11:02:38.892]     INFO: Expecting 208000 events.
[11:02:50.563]     INFO: 208000 events read in total (11144ms).
[11:02:50.566]     INFO: Test took 12276ms.
[11:02:50.695]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:50.943]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0  160    0    0    0    0    0    0    0    0
[11:02:50.943]     INFO: number of red-efficiency pixels:    70   35   81  126  135  114  132  244   56  101   91   72   76   57   18   25
[11:02:50.943]     INFO: number of X-ray hits detected:    58336 38851 63064 96083 105975 103996 102450 62576 61477 89647 86264 72409 72854 43895 18325 22924
[11:02:50.943]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:02:50.944]     INFO: number of Vcal hits detected:  207930 207965 207919 207864 207864 207883 207865 199914 207943 207897 207907 207927 207923 207943 207982 207975
[11:02:50.944]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[11:02:50.944]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 96.1 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[11:02:50.944]     INFO: X-ray hit rate [MHz/cm2]:  17.1 11.4 18.5 28.2 31.1 30.5 30.0 18.3 18.0 26.3 25.3 21.2 21.4 12.9 5.4 6.7
[11:02:50.944]     INFO: PixTestHighRate::doXPixelAlive() done
[11:02:50.995]     INFO: PixTest::       pg_setup set to default.
[11:02:51.007]     INFO: enter test to run
[11:03:39.228]     INFO:   test: HighRate no parameter change
[11:03:39.228]     INFO:   running: highrate
[11:03:39.229]     INFO:    ----------------------------------------------------------------------
[11:03:39.229]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:03:39.229]     INFO:    ----------------------------------------------------------------------
[11:03:39.847]     INFO: Expecting 208000 events.
[11:03:52.960]     INFO: 208000 events read in total (12586ms).
[11:03:52.964]     INFO: Test took 13723ms.
[11:03:53.218]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:53.507]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0  160    0    0    0    0    0    0    0    0
[11:03:53.507]     INFO: number of red-efficiency pixels:   196  108  202  391  460  340  314  395  155  284  238  254  260  164   30   72
[11:03:53.507]     INFO: number of X-ray hits detected:    119228 79015 129982 197261 216371 211513 209864 127464 126811 184240 176637 148822 148973 91062 37349 46773
[11:03:53.507]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:03:53.507]     INFO: number of Vcal hits detected:  207799 207888 207781 207583 207497 207637 207664 199743 207840 207702 207745 207728 207729 207834 207970 207928
[11:03:53.507]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[11:03:53.507]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 96.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[11:03:53.507]     INFO: X-ray hit rate [MHz/cm2]:  34.9 23.2 38.1 57.8 63.4 62.0 61.5 37.4 37.2 54.0 51.8 43.6 43.7 26.7 10.9 13.7
[11:03:53.507]     INFO: PixTestHighRate::doXPixelAlive() done
[11:03:53.558]     INFO: PixTest::       pg_setup set to default.
[11:03:53.573]     INFO: enter test to run
[11:04:20.187]     INFO:   test: HighRate no parameter change
[11:04:20.187]     INFO:   running: highrate
[11:04:20.189]     INFO:    ----------------------------------------------------------------------
[11:04:20.189]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:04:20.189]     INFO:    ----------------------------------------------------------------------
[11:04:20.821]     INFO: Expecting 208000 events.
[11:04:35.736]     INFO: 208000 events read in total (14388ms).
[11:04:35.743]     INFO: Test took 15543ms.
[11:04:36.141]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:36.474]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0  160    0    0    0    0    0    0    0    0
[11:04:36.474]     INFO: number of red-efficiency pixels:   405  218  484  904 1122  790  739  645  358  671  585  508  520  325   77  104
[11:04:36.474]     INFO: number of X-ray hits detected:    179567 120032 195649 297633 326723 318769 317135 192931 191792 277556 266531 222894 224308 136995 56848 71547
[11:04:36.474]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:04:36.475]     INFO: number of Vcal hits detected:  207506 207758 207417 206941 206608 207052 207111 199399 207608 207263 207340 207433 207433 207623 207922 207894
[11:04:36.475]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.8 99.5 99.4 99.6 99.6 99.7 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[11:04:36.475]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.7 99.5 99.3 99.5 99.6 95.9 99.8 99.6 99.7 99.7 99.7 99.8 100.0 99.9
[11:04:36.475]     INFO: X-ray hit rate [MHz/cm2]:  52.6 35.2 57.3 87.2 95.8 93.4 93.0 56.5 56.2 81.4 78.1 65.3 65.7 40.2 16.7 21.0
[11:04:36.475]     INFO: PixTestHighRate::doXPixelAlive() done
[11:04:36.522]     INFO: PixTest::       pg_setup set to default.
[11:04:36.543]     INFO: enter test to run
[11:04:55.139]     INFO:   test: exit no parameter change
[11:04:55.435]    QUIET: Connection to board 33 closed.
[11:04:55.436]     INFO: pXar: this is the end, my friend