[12:23:21.043]     INFO: *** Welcome to pxar ***
[12:23:21.043]     INFO: *** Today: 2016/04/27
[12:23:21.061]     INFO: *** Version: v1.9.0-796-gef167-dirty
[12:23:21.062]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//dacParameters35_C15.dat
[12:23:21.065]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:23:21.065]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//defaultMaskFile.dat
[12:23:21.094]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C15.dat
[12:23:21.188]     INFO:         clk: 4
[12:23:21.188]     INFO:         ctr: 4
[12:23:21.188]     INFO:         sda: 19
[12:23:21.188]     INFO:         tin: 9
[12:23:21.188]     INFO:         level: 15
[12:23:21.188]     INFO:         triggerdelay: 0
[12:23:21.188]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:23:21.188]     INFO: Log level: INFO
[12:23:21.206]    QUIET: Connection to board DTB_WREKRL opened.
[12:23:21.209]     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:23:21.212]     INFO: RPC call hashes of host and DTB match: 398089610
[12:23:22.744]     INFO: DUT info: 
[12:23:22.744]     INFO: The DUT currently contains the following objects:
[12:23:22.744]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:23:22.744]     INFO: 	TBM Core alpha (0): 7 registers set
[12:23:22.744]     INFO: 	TBM Core beta  (1): 7 registers set
[12:23:22.744]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:23:22.744]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.744]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:22.745]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:23:23.149]     INFO: enter 'restricted' command line mode
[12:23:23.149]     INFO: enter test to run
[12:23:28.295]     INFO:   test: PixelAlive no parameter change
[12:23:28.295]     INFO:   running: pixelalive
[12:23:28.302]     INFO:    ----------------------------------------------------------------------
[12:23:28.302]     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:23:28.302]     INFO:    ----------------------------------------------------------------------
[12:23:28.616]     INFO: Expecting 41600 events.
[12:23:32.826]     INFO: 41600 events read in total (3492ms).
[12:23:32.994]     INFO: Test took 4690ms.
[12:23:33.007]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:33.271]     INFO: PixTestAlive::aliveTest() done
[12:23:33.271]     INFO: number of dead pixels (per ROC):     0    0    0    0    2    2    0    0    0    0    0    0    0    0    0    0
[12:23:33.304]     INFO: enter test to run
[12:23:57.495]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:23:57.495]     INFO:   running: highrate
[12:23:57.495]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:23:57.756]     INFO:    ----------------------------------------------------------------------
[12:23:57.756]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:23:57.756]     INFO:    ----------------------------------------------------------------------
[12:23:57.756]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:23:57.756]     INFO: edge/corner pixel THR is adjusted
[12:23:57.756]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:23:58.715]     INFO: Collecting data for 5 seconds...
[12:24:03.733]     INFO: Done with hot pixel readout
[12:24:15.395]     INFO: PixTest::       pg_setup set to default.
[12:24:15.396]     INFO: 20 hot pixels found in step 0
[12:24:16.384]     INFO: Collecting data for 5 seconds...
[12:24:21.401]     INFO: Done with hot pixel readout
[12:24:32.945]     INFO: PixTest::       pg_setup set to default.
[12:24:32.945]     INFO: 18 hot pixels found in step 1
[12:24:33.942]     INFO: Collecting data for 5 seconds...
[12:24:38.960]     INFO: Done with hot pixel readout
[12:24:50.421]     INFO: PixTest::       pg_setup set to default.
[12:24:50.422]     INFO: 14 hot pixels found in step 2
[12:24:51.416]     INFO: Collecting data for 5 seconds...
[12:24:56.433]     INFO: Done with hot pixel readout
[12:25:08.071]     INFO: PixTest::       pg_setup set to default.
[12:25:08.072]     INFO: 16 hot pixels found in step 3
[12:25:09.066]     INFO: Collecting data for 5 seconds...
[12:25:14.083]     INFO: Done with hot pixel readout
[12:25:25.796]     INFO: PixTest::       pg_setup set to default.
[12:25:25.796]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:25:25.796]     INFO: 14 hot pixels found in step 4
[12:25:26.790]     INFO: Collecting data for 5 seconds...
[12:25:31.806]     INFO: Done with hot pixel readout
[12:25:43.550]     INFO: PixTest::       pg_setup set to default.
[12:25:43.550]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:25:43.550]     INFO: 14 hot pixels found in step 5
[12:25:44.543]     INFO: Collecting data for 5 seconds...
[12:25:49.560]     INFO: Done with hot pixel readout
[12:26:00.502]     INFO: PixTest::       pg_setup set to default.
[12:26:00.502]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:00.503]     INFO: 13 hot pixels found in step 6
[12:26:01.497]     INFO: Collecting data for 5 seconds...
[12:26:06.514]     INFO: Done with hot pixel readout
[12:26:18.043]     INFO: PixTest::       pg_setup set to default.
[12:26:18.043]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:18.043]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:18.044]     INFO: 13 hot pixels found in step 7
[12:26:19.044]     INFO: Collecting data for 5 seconds...
[12:26:24.061]     INFO: Done with hot pixel readout
[12:26:35.271]     INFO: PixTest::       pg_setup set to default.
[12:26:35.271]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:35.271]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:35.271]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:35.271]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:35.272]     INFO: 8 hot pixels found in step 8
[12:26:36.266]     INFO: Collecting data for 5 seconds...
[12:26:41.283]     INFO: Done with hot pixel readout
[12:26:52.891]     INFO: PixTest::       pg_setup set to default.
[12:26:52.891]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:52.891]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:52.891]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:52.891]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:52.891]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:26:52.892]     INFO: 8 hot pixels found in step 9
[12:26:53.888]     INFO: Collecting data for 5 seconds...
[12:26:58.904]     INFO: Done with hot pixel readout
[12:27:09.909]     INFO: PixTest::       pg_setup set to default.
[12:27:09.909]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:09.909]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:09.909]     INFO: 6 hot pixels found in step 10
[12:27:10.903]     INFO: Collecting data for 5 seconds...
[12:27:15.920]     INFO: Done with hot pixel readout
[12:27:25.820]     INFO: PixTest::       pg_setup set to default.
[12:27:25.820]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:25.820]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:25.820]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:25.820]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:25.821]     INFO: 7 hot pixels found in step 11
[12:27:26.814]     INFO: Collecting data for 5 seconds...
[12:27:31.824]     INFO: Done with hot pixel readout
[12:27:41.759]     INFO: PixTest::       pg_setup set to default.
[12:27:41.759]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:41.759]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:41.759]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:41.760]     INFO: 4 hot pixels found in step 12
[12:27:42.753]     INFO: Collecting data for 5 seconds...
[12:27:47.771]     INFO: Done with hot pixel readout
[12:27:59.509]     INFO: PixTest::       pg_setup set to default.
[12:27:59.509]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:59.509]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:59.509]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:27:59.510]     INFO: 3 hot pixels found in step 13
[12:27:59.547]     INFO: 3 hot pixels could not be trimmed and have been masked.
[12:27:59.550]     INFO: PixTest::trimHotPixels() done
[12:27:59.550]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C0.dat
[12:27:59.556]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C1.dat
[12:27:59.562]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C2.dat
[12:27:59.567]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C3.dat
[12:27:59.572]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C4.dat
[12:27:59.577]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C5.dat
[12:27:59.582]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C6.dat
[12:27:59.588]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C7.dat
[12:27:59.593]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C8.dat
[12:27:59.598]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C9.dat
[12:27:59.603]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C10.dat
[12:27:59.608]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C11.dat
[12:27:59.613]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C12.dat
[12:27:59.618]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C13.dat
[12:27:59.624]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C14.dat
[12:27:59.629]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C15.dat
[12:27:59.647]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//defaultMaskFile.dat
[12:27:59.664]     INFO: enter test to run
[12:28:42.669]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:28:42.669]     INFO:   running: highrate
[12:28:42.674]     INFO:    ----------------------------------------------------------------------
[12:28:42.674]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:28:42.674]     INFO:    ----------------------------------------------------------------------
[12:28:42.674]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:28:42.674]     INFO: edge/corner pixel THR is adjusted
[12:28:42.674]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:28:43.632]     INFO: Collecting data for 1 seconds...
[12:28:44.636]     INFO: Done with hot pixel readout
[12:28:48.629]     INFO: PixTest::       pg_setup set to default.
[12:28:48.630]     INFO: 0 hot pixels found in step 0
[12:28:48.635]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:28:48.726]     INFO: PixTest::trimHotPixels() done
[12:28:48.726]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C0.dat
[12:28:48.738]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C1.dat
[12:28:48.743]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C2.dat
[12:28:48.748]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C3.dat
[12:28:48.754]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C4.dat
[12:28:48.759]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C5.dat
[12:28:48.764]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C6.dat
[12:28:48.769]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C7.dat
[12:28:48.775]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C8.dat
[12:28:48.780]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C9.dat
[12:28:48.785]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C10.dat
[12:28:48.790]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C11.dat
[12:28:48.795]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C12.dat
[12:28:48.801]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C13.dat
[12:28:48.806]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C14.dat
[12:28:48.811]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//trimParameters35_C15.dat
[12:28:48.816]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-18_FPIXTest-17C-FNAL-160421-1341_2016-04-21_13h41m_1461264105/000_FPIXTest_p17//defaultMaskFile.dat
[12:28:48.826]     INFO: enter test to run
[12:29:31.965]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:29:31.965]     INFO:   running: xray
[12:29:31.966]     INFO:    ----------------------------------------------------------------------
[12:29:31.966]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:29:31.966]     INFO:    ----------------------------------------------------------------------
[12:29:32.929]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:29:44.400]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:30:13.413]     INFO: Resuming triggers.
[12:30:24.893]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:30:53.940]     INFO: Resuming triggers.
[12:31:05.418]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:31:34.620]     INFO: Resuming triggers.
[12:31:46.103]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:32:15.083]     INFO: Resuming triggers.
[12:32:26.559]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:32:55.893]     INFO: Resuming triggers.
[12:33:07.366]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:33:35.681]     INFO: Resuming triggers.
[12:33:47.154]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:34:16.392]     INFO: Resuming triggers.
[12:34:27.864]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:34:57.071]     INFO: Resuming triggers.
[12:35:05.605]     INFO: data taking finished, elapsed time: 100 seconds.
[12:35:27.423]     INFO: PixTest::       pg_setup set to default.
[12:35:27.426]     INFO: PixTestXray::doPhRun() done
[12:35:27.561]     INFO: enter test to run
[12:35:47.258]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:35:47.258]     INFO:   running: xray
[12:35:47.259]     INFO:    ----------------------------------------------------------------------
[12:35:47.259]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:35:47.259]     INFO:    ----------------------------------------------------------------------
[12:35:48.223]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:35:54.952]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:36:25.328]     INFO: Resuming triggers.
[12:36:32.059]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:37:02.100]     INFO: Resuming triggers.
[12:37:08.832]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:37:37.765]     INFO: Resuming triggers.
[12:37:44.493]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:38:14.612]     INFO: Resuming triggers.
[12:38:21.342]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:38:51.496]     INFO: Resuming triggers.
[12:38:58.227]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:39:28.215]     INFO: Resuming triggers.
[12:39:34.947]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:40:05.153]     INFO: Resuming triggers.
[12:40:11.884]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:40:42.138]     INFO: Resuming triggers.
[12:40:48.872]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:41:18.000]     INFO: Resuming triggers.
[12:41:25.733]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:41:55.909]     INFO: Resuming triggers.
[12:42:02.639]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:42:32.838]     INFO: Resuming triggers.
[12:42:39.567]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:43:09.755]     INFO: Resuming triggers.
[12:43:16.485]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:43:46.599]     INFO: Resuming triggers.
[12:43:53.329]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:44:23.431]     INFO: Resuming triggers.
[12:44:29.526]     INFO: data taking finished, elapsed time: 100 seconds.
[12:44:57.016]     INFO: PixTest::       pg_setup set to default.
[12:44:57.019]     INFO: PixTestXray::doPhRun() done
[12:44:57.166]     INFO: enter test to run
[12:45:16.278]     INFO:   test: HighRate no parameter change
[12:45:16.278]     INFO:   running: highrate
[12:45:16.300]     INFO:    ----------------------------------------------------------------------
[12:45:16.300]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:45:16.300]     INFO:    ----------------------------------------------------------------------
[12:45:16.463]     INFO: Expecting 768 events.
[12:45:17.597]     INFO: 768 events read in total (418ms).
[12:45:17.598]     INFO: Test took 1269ms.
[12:45:18.401]     INFO: Expecting 41600 events.
[12:45:21.504]     INFO: 41600 events read in total (2577ms).
[12:45:21.505]     INFO: Test took 3899ms.
[12:45:21.539]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:22.265]     INFO: Expecting 41600 events.
[12:45:25.458]     INFO: 41600 events read in total (2666ms).
[12:45:25.459]     INFO: Test took 3902ms.
[12:45:25.494]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:26.217]     INFO: Expecting 41600 events.
[12:45:29.417]     INFO: 41600 events read in total (2673ms).
[12:45:29.418]     INFO: Test took 3905ms.
[12:45:29.453]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:30.175]     INFO: Expecting 41600 events.
[12:45:33.423]     INFO: 41600 events read in total (2721ms).
[12:45:33.424]     INFO: Test took 3952ms.
[12:45:33.463]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:34.178]     INFO: Expecting 41600 events.
[12:45:37.413]     INFO: 41600 events read in total (2708ms).
[12:45:37.414]     INFO: Test took 3927ms.
[12:45:37.450]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:38.173]     INFO: Expecting 41600 events.
[12:45:41.416]     INFO: 41600 events read in total (2716ms).
[12:45:41.417]     INFO: Test took 3948ms.
[12:45:41.452]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:42.172]     INFO: Expecting 41600 events.
[12:45:45.434]     INFO: 41600 events read in total (2735ms).
[12:45:45.435]     INFO: Test took 3964ms.
[12:45:45.471]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:46.188]     INFO: Expecting 41600 events.
[12:45:49.446]     INFO: 41600 events read in total (2731ms).
[12:45:49.447]     INFO: Test took 3957ms.
[12:45:49.482]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:50.205]     INFO: Expecting 41600 events.
[12:45:53.437]     INFO: 41600 events read in total (2705ms).
[12:45:53.438]     INFO: Test took 3937ms.
[12:45:53.474]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:54.190]     INFO: Expecting 41600 events.
[12:45:57.435]     INFO: 41600 events read in total (2718ms).
[12:45:57.437]     INFO: Test took 3945ms.
[12:45:57.472]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:58.191]     INFO: Expecting 41600 events.
[12:46:01.407]     INFO: 41600 events read in total (2689ms).
[12:46:01.409]     INFO: Test took 3919ms.
[12:46:01.444]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:02.162]     INFO: Expecting 41600 events.
[12:46:05.418]     INFO: 41600 events read in total (2729ms).
[12:46:05.419]     INFO: Test took 3957ms.
[12:46:05.455]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:06.176]     INFO: Expecting 41600 events.
[12:46:09.389]     INFO: 41600 events read in total (2686ms).
[12:46:09.390]     INFO: Test took 3916ms.
[12:46:09.425]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:10.145]     INFO: Expecting 41600 events.
[12:46:13.364]     INFO: 41600 events read in total (2692ms).
[12:46:13.365]     INFO: Test took 3920ms.
[12:46:13.401]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:14.124]     INFO: Expecting 41600 events.
[12:46:17.380]     INFO: 41600 events read in total (2730ms).
[12:46:17.381]     INFO: Test took 3961ms.
[12:46:17.416]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:18.137]     INFO: Expecting 41600 events.
[12:46:21.353]     INFO: 41600 events read in total (2690ms).
[12:46:21.353]     INFO: Test took 3918ms.
[12:46:21.389]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:22.110]     INFO: Expecting 41600 events.
[12:46:25.382]     INFO: 41600 events read in total (2746ms).
[12:46:25.383]     INFO: Test took 3976ms.
[12:46:25.418]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:26.138]     INFO: Expecting 41600 events.
[12:46:29.380]     INFO: 41600 events read in total (2715ms).
[12:46:29.381]     INFO: Test took 3944ms.
[12:46:29.416]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:30.138]     INFO: Expecting 41600 events.
[12:46:33.368]     INFO: 41600 events read in total (2703ms).
[12:46:33.369]     INFO: Test took 3933ms.
[12:46:33.403]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:34.128]     INFO: Expecting 41600 events.
[12:46:37.251]     INFO: 41600 events read in total (2596ms).
[12:46:37.252]     INFO: Test took 3830ms.
[12:46:37.287]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:37.647]     INFO: enter test to run
[12:47:24.301]     INFO:   test: HighRate no parameter change
[12:47:24.301]     INFO:   running: highrate
[12:47:24.302]     INFO:    ----------------------------------------------------------------------
[12:47:24.302]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:24.302]     INFO:    ----------------------------------------------------------------------
[12:47:24.914]     INFO: Expecting 208000 events.
[12:47:35.942]     INFO: 208000 events read in total (10502ms).
[12:47:35.945]     INFO: Test took 11635ms.
[12:47:36.099]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:36.353]     INFO: number of dead pixels (per ROC):     0    0    0    0    3    2    0    0    0    0    0    0    0    0    0    0
[12:47:36.353]     INFO: number of red-efficiency pixels:    69   41   79  147  160  159  170   99  105  112  115  102  110   61   25   39
[12:47:36.353]     INFO: number of X-ray hits detected:    64827 44138 67963 108069 121556 119469 120509 89765 87661 103923 97884 87164 92445 52249 20756 26016
[12:47:36.353]     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:47:36.353]     INFO: number of Vcal hits detected:  207931 207958 207919 207850 207685 207739 207826 207899 207893 207884 207881 207897 207887 207936 207975 207961
[12:47:36.353]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[12:47:36.353]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.8 99.9 99.9 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[12:47:36.353]     INFO: X-ray hit rate [MHz/cm2]:  19.0 12.9 19.9 31.7 35.6 35.0 35.3 26.3 25.7 30.5 28.7 25.5 27.1 15.3 6.1 7.6
[12:47:36.353]     INFO: PixTestHighRate::doXPixelAlive() done
[12:47:36.398]     INFO: PixTest::       pg_setup set to default.
[12:47:36.405]     INFO: enter test to run
[12:48:07.604]     INFO:   test: HighRate no parameter change
[12:48:07.605]     INFO:   running: highrate
[12:48:07.606]     INFO:    ----------------------------------------------------------------------
[12:48:07.606]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:07.606]     INFO:    ----------------------------------------------------------------------
[12:48:08.222]     INFO: Expecting 208000 events.
[12:48:21.819]     INFO: 208000 events read in total (13070ms).
[12:48:21.824]     INFO: Test took 14208ms.
[12:48:22.116]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:22.415]     INFO: number of dead pixels (per ROC):     0    0    0    0    3    2    0    0    0    0    0    0    0    0    0    0
[12:48:22.415]     INFO: number of red-efficiency pixels:   161  135  247  425  495  401  524  268  295  397  309  287  268  176   48   68
[12:48:22.415]     INFO: number of X-ray hits detected:    128482 87345 134202 212588 238368 235344 239002 178294 173622 203588 192738 173281 183598 103769 41185 51678
[12:48:22.415]     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:48:22.415]     INFO: number of Vcal hits detected:  207830 207861 207728 207544 207328 207464 207419 207715 207691 207585 207671 207700 207722 207812 207952 207929
[12:48:22.415]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:48:22.415]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:48:22.415]     INFO: X-ray hit rate [MHz/cm2]:  37.7 25.6 39.3 62.3 69.9 69.0 70.1 52.3 50.9 59.7 56.5 50.8 53.8 30.4 12.1 15.1
[12:48:22.415]     INFO: PixTestHighRate::doXPixelAlive() done
[12:48:22.462]     INFO: PixTest::       pg_setup set to default.
[12:48:22.475]     INFO: enter test to run
[12:48:39.212]     INFO:   test: HighRate no parameter change
[12:48:39.212]     INFO:   running: highrate
[12:48:39.213]     INFO:    ----------------------------------------------------------------------
[12:48:39.214]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:39.214]     INFO:    ----------------------------------------------------------------------
[12:48:39.827]     INFO: Expecting 208000 events.
[12:48:55.346]     INFO: 208000 events read in total (14992ms).
[12:48:55.353]     INFO: Test took 16131ms.
[12:48:55.789]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:56.140]     INFO: number of dead pixels (per ROC):     0    0    0    0    3    2    0    0    0    0    0    0    0    0    0    0
[12:48:56.140]     INFO: number of red-efficiency pixels:   308  277  588 1011 1133  944 1281  649  694  940  702  685  592  438   97   99
[12:48:56.140]     INFO: number of X-ray hits detected:    195203 134513 203884 323837 364570 359295 364112 271482 265105 311654 294961 265103 279683 157684 63096 79299
[12:48:56.140]     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:48:56.140]     INFO: number of Vcal hits detected:  207636 207707 207246 206757 206437 206705 206315 207198 207211 206862 207186 207205 207350 207488 207899 207898
[12:48:56.140]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.7 99.5 99.4 99.5 99.3 99.6 99.7 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[12:48:56.140]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.6 99.4 99.2 99.4 99.2 99.6 99.6 99.5 99.6 99.6 99.7 99.8 100.0 100.0
[12:48:56.140]     INFO: X-ray hit rate [MHz/cm2]:  57.2 39.4 59.8 94.9 106.9 105.3 106.7 79.6 77.7 91.3 86.5 77.7 82.0 46.2 18.5 23.2
[12:48:56.140]     INFO: PixTestHighRate::doXPixelAlive() done
[12:48:56.197]     INFO: PixTest::       pg_setup set to default.
[12:48:56.209]     INFO: enter test to run
[12:48:58.812]     INFO:   test: exit no parameter change
[12:48:59.193]    QUIET: Connection to board 33 closed.
[12:48:59.204]     INFO: pXar: this is the end, my friend