[12:19:24.253]     INFO: *** Welcome to pxar ***
[12:19:24.253]     INFO: *** Today: 2016/05/20
[12:19:24.286]     INFO: *** Version: v1.9.0-796-gef167-dirty
[12:19:24.286]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C15.dat
[12:19:24.288]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:19:24.288]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:19:24.288]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:19:24.377]     INFO:         clk: 4
[12:19:24.377]     INFO:         ctr: 4
[12:19:24.377]     INFO:         sda: 19
[12:19:24.378]     INFO:         tin: 9
[12:19:24.378]     INFO:         level: 15
[12:19:24.378]     INFO:         triggerdelay: 0
[12:19:24.378]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:19:24.378]     INFO: Log level: INFO
[12:19:24.397]    QUIET: Connection to board DTB_WREK4U opened.
[12:19:24.401]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    32
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREK4U
MAC address: 40D855118020
Hostname:    pixelDTB032
Comment:     
------------------------------------------------------
[12:19:24.404]     INFO: RPC call hashes of host and DTB match: 398089610
[12:19:25.935]     INFO: DUT info: 
[12:19:25.935]     INFO: The DUT currently contains the following objects:
[12:19:25.935]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:19:25.935]     INFO: 	TBM Core alpha (0): 7 registers set
[12:19:25.936]     INFO: 	TBM Core beta  (1): 7 registers set
[12:19:25.936]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:19:25.936]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:25.936]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:19:26.339]     INFO: enter 'restricted' command line mode
[12:19:26.340]     INFO: enter test to run
[12:19:28.857]     INFO:   test: timing no parameter change
[12:19:28.857]     INFO:   running: timing
[12:19:28.880]     INFO: ######################################################################
[12:19:28.880]     INFO: PixTestTiming::doTest()
[12:19:28.885]     INFO: ######################################################################
[12:19:28.886]     INFO:    ----------------------------------------------------------------------
[12:19:28.886]     INFO:    PixTestTiming::TBMPhaseScan()
[12:19:28.886]     INFO:    ----------------------------------------------------------------------
[12:24:03.270]     INFO: TBM Phase Settings: 240
[12:24:03.270]     INFO: 400MHz Phase: 4
[12:24:03.270]     INFO: 160MHz Phase: 7
[12:24:03.270]     INFO: Functional Phase Area: 5
[12:24:03.281]     INFO: Test took 274396 ms.
[12:24:03.281]     INFO: PixTestTiming::TBMPhaseScan() done.
[12:24:03.281]     INFO:    ----------------------------------------------------------------------
[12:24:03.281]     INFO:    PixTestTiming::ROCDelayScan()
[12:24:03.281]     INFO:    ----------------------------------------------------------------------
[12:26:08.525]     INFO: ROC Delay Settings: 228
[12:26:08.525]     INFO: ROC Header-Trailer/Token Delay: 11
[12:26:08.525]     INFO: ROC Port 0 Delay: 4
[12:26:08.525]     INFO: ROC Port 1 Delay: 4
[12:26:08.525]     INFO: Functional ROC Area: 5
[12:26:08.528]     INFO: Test took 125247 ms.
[12:26:08.528]     INFO: PixTestTiming::ROCDelayScan() done.
[12:26:08.529]     INFO:    ----------------------------------------------------------------------
[12:26:08.529]     INFO:    PixTestTiming::TimingTest()
[12:26:08.529]     INFO:    ----------------------------------------------------------------------
[12:26:24.686]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:39.679]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:54.656]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:09.629]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:24.607]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:39.572]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:54.562]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:09.537]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:24.525]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:39.547]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:39.924]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO:    Read back bit status: 1
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO:    Timings are good!
[12:28:39.942]     INFO:    ----------------------------------------------------------------------
[12:28:39.942]     INFO: Test took 151413 ms.
[12:28:39.942]     INFO: PixTestTiming::TimingTest() done.
[12:28:39.955]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:28:39.955]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:28:39.955]     INFO: PixTestTiming::doTest took 551080 ms.
[12:28:39.955]     INFO: PixTestTiming::doTest() done
[12:28:39.955]     INFO: Write out TBMPhaseScan_0_V0
[12:28:39.980]     INFO: Write out TBMPhaseScan_1_V0
[12:28:39.980]     INFO: Write out CombinedTBMPhaseScan_V0
[12:28:40.011]     INFO: Write out ROCDelayScan3_V0
[12:28:40.013]     INFO: enter test to run
[12:29:18.277]     INFO:   test: PixelAlive no parameter change
[12:29:18.277]     INFO:   running: pixelalive
[12:29:18.299]     INFO:    ----------------------------------------------------------------------
[12:29:18.299]     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:29:18.299]     INFO:    ----------------------------------------------------------------------
[12:29:18.619]     INFO: Expecting 41600 events.
[12:29:22.945]     INFO: 41600 events read in total (3611ms).
[12:29:22.946]     INFO: Test took 4644ms.
[12:29:22.953]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:23.353]     INFO: PixTestAlive::aliveTest() done
[12:29:23.353]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:29:23.355]     INFO: enter test to run
[12:29:57.933]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:29:57.933]     INFO:   running: highrate
[12:29:57.933]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:29:58.160]     INFO:    ----------------------------------------------------------------------
[12:29:58.160]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:29:58.160]     INFO:    ----------------------------------------------------------------------
[12:29:58.160]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:29:58.160]     INFO: edge/corner pixel THR is adjusted
[12:29:58.160]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:29:59.118]     INFO: Collecting data for 5 seconds...
[12:30:04.135]     INFO: Done with hot pixel readout
[12:30:12.067]     INFO: PixTest::       pg_setup set to default.
[12:30:12.068]     INFO: 0 hot pixels found in step 0
[12:30:12.070]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:30:12.246]     INFO: PixTest::trimHotPixels() done
[12:30:12.246]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[12:30:12.255]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[12:30:12.261]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[12:30:12.266]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[12:30:12.271]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[12:30:12.277]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[12:30:12.282]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[12:30:12.287]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[12:30:12.292]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[12:30:12.298]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[12:30:12.303]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[12:30:12.308]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[12:30:12.314]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[12:30:12.319]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[12:30:12.324]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[12:30:12.329]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:30:12.335]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:30:12.343]     INFO: enter test to run
[12:30:34.788]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:30:34.788]     INFO:   running: highrate
[12:30:34.793]     INFO:    ----------------------------------------------------------------------
[12:30:34.793]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:30:34.793]     INFO:    ----------------------------------------------------------------------
[12:30:34.793]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:30:34.793]     INFO: edge/corner pixel THR is adjusted
[12:30:34.793]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:30:35.750]     INFO: Collecting data for 5 seconds...
[12:30:40.767]     INFO: Done with hot pixel readout
[12:30:52.576]     INFO: PixTest::       pg_setup set to default.
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.576]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:30:52.577]     INFO: 13 hot pixels found in step 0
[12:30:53.571]     INFO: Collecting data for 5 seconds...
[12:30:58.588]     INFO: Done with hot pixel readout
[12:31:10.416]     INFO: PixTest::       pg_setup set to default.
[12:31:10.417]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:10.417]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:10.417]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:10.417]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:10.417]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:10.417]     INFO: 15 hot pixels found in step 1
[12:31:11.411]     INFO: Collecting data for 5 seconds...
[12:31:16.427]     INFO: Done with hot pixel readout
[12:31:28.269]     INFO: PixTest::       pg_setup set to default.
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.269]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:28.270]     INFO: 9 hot pixels found in step 2
[12:31:29.264]     INFO: Collecting data for 5 seconds...
[12:31:34.281]     INFO: Done with hot pixel readout
[12:31:46.105]     INFO: PixTest::       pg_setup set to default.
[12:31:46.105]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.105]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.105]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.105]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.106]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.106]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:31:46.106]     INFO: 12 hot pixels found in step 3
[12:31:47.100]     INFO: Collecting data for 5 seconds...
[12:31:52.117]     INFO: Done with hot pixel readout
[12:32:03.938]     INFO: PixTest::       pg_setup set to default.
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.938]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:03.939]     INFO: 11 hot pixels found in step 4
[12:32:04.932]     INFO: Collecting data for 5 seconds...
[12:32:09.949]     INFO: Done with hot pixel readout
[12:32:21.754]     INFO: PixTest::       pg_setup set to default.
[12:32:21.754]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:21.754]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:21.754]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:21.754]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:21.754]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:21.755]     INFO: 8 hot pixels found in step 5
[12:32:22.749]     INFO: Collecting data for 5 seconds...
[12:32:27.765]     INFO: Done with hot pixel readout
[12:32:39.635]     INFO: PixTest::       pg_setup set to default.
[12:32:39.635]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:39.635]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:39.635]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:39.635]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:39.635]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:39.636]     INFO: 12 hot pixels found in step 6
[12:32:40.630]     INFO: Collecting data for 5 seconds...
[12:32:45.646]     INFO: Done with hot pixel readout
[12:32:57.752]     INFO: PixTest::       pg_setup set to default.
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.752]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:32:57.753]     INFO: 13 hot pixels found in step 7
[12:32:58.747]     INFO: Collecting data for 5 seconds...
[12:33:03.764]     INFO: Done with hot pixel readout
[12:33:15.634]     INFO: PixTest::       pg_setup set to default.
[12:33:15.634]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:15.634]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:15.634]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:15.634]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:15.634]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:15.635]     INFO: 9 hot pixels found in step 8
[12:33:16.629]     INFO: Collecting data for 5 seconds...
[12:33:21.648]     INFO: Done with hot pixel readout
[12:33:33.191]     INFO: PixTest::       pg_setup set to default.
[12:33:33.191]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:33.191]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:33.191]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:33.191]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:33.191]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:33.192]     INFO: 9 hot pixels found in step 9
[12:33:34.185]     INFO: Collecting data for 5 seconds...
[12:33:39.202]     INFO: Done with hot pixel readout
[12:33:50.731]     INFO: PixTest::       pg_setup set to default.
[12:33:50.731]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:50.731]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:50.731]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:50.731]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:50.731]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:33:50.732]     INFO: 9 hot pixels found in step 10
[12:33:51.726]     INFO: Collecting data for 5 seconds...
[12:33:56.745]     INFO: Done with hot pixel readout
[12:34:08.489]     INFO: PixTest::       pg_setup set to default.
[12:34:08.489]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.489]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.489]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.490]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.490]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.490]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:08.490]     INFO: 9 hot pixels found in step 11
[12:34:09.486]     INFO: Collecting data for 5 seconds...
[12:34:14.502]     INFO: Done with hot pixel readout
[12:34:26.354]     INFO: PixTest::       pg_setup set to default.
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:26.355]     INFO: 13 hot pixels found in step 12
[12:34:27.349]     INFO: Collecting data for 5 seconds...
[12:34:32.365]     INFO: Done with hot pixel readout
[12:34:44.286]     INFO: PixTest::       pg_setup set to default.
[12:34:44.286]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:44.286]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:44.286]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:44.286]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:44.286]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:34:44.287]     INFO: 10 hot pixels found in step 13
[12:34:45.282]     INFO: Collecting data for 5 seconds...
[12:34:50.302]     INFO: Done with hot pixel readout
[12:35:02.353]     INFO: PixTest::       pg_setup set to default.
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:02.354]     INFO: 9 hot pixels found in step 14
[12:35:02.393]     INFO: 9 hot pixels could not be trimmed and have been masked.
[12:35:02.396]     INFO: PixTest::trimHotPixels() done
[12:35:02.397]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[12:35:02.411]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[12:35:02.416]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[12:35:02.421]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[12:35:02.427]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[12:35:02.432]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[12:35:02.437]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[12:35:02.443]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[12:35:02.448]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[12:35:02.453]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[12:35:02.459]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[12:35:02.464]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[12:35:02.469]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[12:35:02.475]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[12:35:02.480]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[12:35:02.485]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:35:02.491]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:35:02.501]     INFO: enter test to run
[12:36:11.762]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:36:11.762]     INFO:   running: highrate
[12:36:11.766]     INFO:    ----------------------------------------------------------------------
[12:36:11.767]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:36:11.767]     INFO:    ----------------------------------------------------------------------
[12:36:11.767]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:36:11.767]     INFO: edge/corner pixel THR is adjusted
[12:36:11.767]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:36:12.724]     INFO: Collecting data for 1 seconds...
[12:36:13.728]     INFO: Done with hot pixel readout
[12:36:17.899]     INFO: PixTest::       pg_setup set to default.
[12:36:17.900]     INFO: 0 hot pixels found in step 0
[12:36:17.906]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:36:17.994]     INFO: PixTest::trimHotPixels() done
[12:36:17.995]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[12:36:17.004]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[12:36:18.009]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[12:36:18.015]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[12:36:18.020]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[12:36:18.026]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[12:36:18.031]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[12:36:18.036]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[12:36:18.042]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[12:36:18.047]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[12:36:18.052]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[12:36:18.058]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[12:36:18.063]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[12:36:18.068]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[12:36:18.074]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[12:36:18.079]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:36:18.085]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-08_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:36:18.094]     INFO: enter test to run
[12:37:21.521]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:37:21.521]     INFO:   running: xray
[12:37:21.522]     INFO:    ----------------------------------------------------------------------
[12:37:21.523]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:37:21.523]     INFO:    ----------------------------------------------------------------------
[12:37:22.486]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:37:33.805]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:38:03.189]     INFO: Resuming triggers.
[12:38:14.517]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:38:43.941]     INFO: Resuming triggers.
[12:38:55.266]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:39:24.599]     INFO: Resuming triggers.
[12:39:35.925]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:40:05.089]     INFO: Resuming triggers.
[12:40:16.418]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:40:45.627]     INFO: Resuming triggers.
[12:40:56.958]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:41:26.360]     INFO: Resuming triggers.
[12:41:37.690]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:42:06.967]     INFO: Resuming triggers.
[12:42:18.291]     INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:42:47.675]     INFO: Resuming triggers.
[12:42:57.384]     INFO: data taking finished, elapsed time: 100 seconds.
[12:43:22.629]     INFO: PixTest::       pg_setup set to default.
[12:43:22.632]     INFO: PixTestXray::doPhRun() done
[12:43:22.835]     INFO: enter test to run
[12:43:47.446]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:43:47.446]     INFO:   running: xray
[12:43:47.448]     INFO:    ----------------------------------------------------------------------
[12:43:47.448]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:43:47.448]     INFO:    ----------------------------------------------------------------------
[12:43:48.412]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:43:55.144]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:44:26.014]     INFO: Resuming triggers.
[12:44:32.752]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:45:03.149]     INFO: Resuming triggers.
[12:45:09.884]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:45:39.714]     INFO: Resuming triggers.
[12:45:46.447]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:46:17.596]     INFO: Resuming triggers.
[12:46:24.327]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:46:55.524]     INFO: Resuming triggers.
[12:47:02.253]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:47:33.425]     INFO: Resuming triggers.
[12:47:40.157]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:48:10.202]     INFO: Resuming triggers.
[12:48:16.934]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:48:46.950]     INFO: Resuming triggers.
[12:48:53.679]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:49:23.753]     INFO: Resuming triggers.
[12:49:30.481]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:50:00.569]     INFO: Resuming triggers.
[12:50:07.299]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:50:37.371]     INFO: Resuming triggers.
[12:50:44.099]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:51:14.388]     INFO: Resuming triggers.
[12:51:21.118]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:51:50.441]     INFO: Resuming triggers.
[12:51:57.174]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:52:27.234]     INFO: Resuming triggers.
[12:52:33.327]     INFO: data taking finished, elapsed time: 100 seconds.
[12:53:00.784]     INFO: PixTest::       pg_setup set to default.
[12:53:00.787]     INFO: PixTestXray::doPhRun() done
[12:53:00.939]     INFO: enter test to run
[12:53:26.554]     INFO:   test: HighRate no parameter change
[12:53:26.554]     INFO:   running: highrate
[12:53:26.556]     INFO:    ----------------------------------------------------------------------
[12:53:26.556]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:53:26.556]     INFO:    ----------------------------------------------------------------------
[12:53:26.711]     INFO: Expecting 768 events.
[12:53:27.843]     INFO: 768 events read in total (416ms).
[12:53:27.843]     INFO: Test took 1268ms.
[12:53:28.647]     INFO: Expecting 41600 events.
[12:53:31.765]     INFO: 41600 events read in total (2591ms).
[12:53:31.766]     INFO: Test took 3914ms.
[12:53:31.801]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:32.527]     INFO: Expecting 41600 events.
[12:53:35.748]     INFO: 41600 events read in total (2694ms).
[12:53:35.749]     INFO: Test took 3929ms.
[12:53:35.784]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:36.508]     INFO: Expecting 41600 events.
[12:53:39.746]     INFO: 41600 events read in total (2711ms).
[12:53:39.747]     INFO: Test took 3945ms.
[12:53:39.782]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:40.504]     INFO: Expecting 41600 events.
[12:53:43.744]     INFO: 41600 events read in total (2713ms).
[12:53:43.745]     INFO: Test took 3944ms.
[12:53:43.781]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:44.503]     INFO: Expecting 41600 events.
[12:53:47.748]     INFO: 41600 events read in total (2719ms).
[12:53:47.749]     INFO: Test took 3949ms.
[12:53:47.785]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:48.505]     INFO: Expecting 41600 events.
[12:53:51.767]     INFO: 41600 events read in total (2735ms).
[12:53:51.768]     INFO: Test took 3964ms.
[12:53:51.803]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:52.521]     INFO: Expecting 41600 events.
[12:53:55.779]     INFO: 41600 events read in total (2731ms).
[12:53:55.780]     INFO: Test took 3960ms.
[12:53:55.815]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:56.539]     INFO: Expecting 41600 events.
[12:53:59.794]     INFO: 41600 events read in total (2729ms).
[12:53:59.795]     INFO: Test took 3961ms.
[12:53:59.830]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:00.548]     INFO: Expecting 41600 events.
[12:54:03.810]     INFO: 41600 events read in total (2735ms).
[12:54:03.811]     INFO: Test took 3963ms.
[12:54:03.846]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:04.559]     INFO: Expecting 41600 events.
[12:54:07.824]     INFO: 41600 events read in total (2738ms).
[12:54:07.825]     INFO: Test took 3960ms.
[12:54:07.860]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:08.581]     INFO: Expecting 41600 events.
[12:54:11.834]     INFO: 41600 events read in total (2726ms).
[12:54:11.835]     INFO: Test took 3956ms.
[12:54:11.870]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:12.593]     INFO: Expecting 41600 events.
[12:54:15.854]     INFO: 41600 events read in total (2734ms).
[12:54:15.855]     INFO: Test took 3966ms.
[12:54:15.891]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:16.613]     INFO: Expecting 41600 events.
[12:54:19.873]     INFO: 41600 events read in total (2733ms).
[12:54:19.874]     INFO: Test took 3964ms.
[12:54:19.910]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:20.631]     INFO: Expecting 41600 events.
[12:54:23.881]     INFO: 41600 events read in total (2723ms).
[12:54:23.882]     INFO: Test took 3952ms.
[12:54:23.917]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:24.638]     INFO: Expecting 41600 events.
[12:54:27.887]     INFO: 41600 events read in total (2723ms).
[12:54:27.888]     INFO: Test took 3953ms.
[12:54:27.922]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:28.642]     INFO: Expecting 41600 events.
[12:54:31.895]     INFO: 41600 events read in total (2726ms).
[12:54:31.896]     INFO: Test took 3954ms.
[12:54:31.931]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:32.653]     INFO: Expecting 41600 events.
[12:54:35.903]     INFO: 41600 events read in total (2723ms).
[12:54:35.904]     INFO: Test took 3953ms.
[12:54:35.940]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:36.657]     INFO: Expecting 41600 events.
[12:54:39.912]     INFO: 41600 events read in total (2728ms).
[12:54:39.913]     INFO: Test took 3954ms.
[12:54:39.948]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:40.668]     INFO: Expecting 41600 events.
[12:54:43.897]     INFO: 41600 events read in total (2702ms).
[12:54:43.898]     INFO: Test took 3930ms.
[12:54:43.933]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:44.657]     INFO: Expecting 41600 events.
[12:54:47.756]     INFO: 41600 events read in total (2572ms).
[12:54:47.757]     INFO: Test took 3804ms.
[12:54:47.792]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:48.153]     INFO: enter test to run
[12:55:20.033]     INFO:   test: HighRate no parameter change
[12:55:20.034]     INFO:   running: highrate
[12:55:20.035]     INFO:    ----------------------------------------------------------------------
[12:55:20.035]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:55:20.035]     INFO:    ----------------------------------------------------------------------
[12:55:20.648]     INFO: Expecting 208000 events.
[12:55:32.539]     INFO: 208000 events read in total (11364ms).
[12:55:32.543]     INFO: Test took 12499ms.
[12:55:32.696]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:32.952]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:55:32.953]     INFO: number of red-efficiency pixels:    79   53   89  163  143  181  181  115   89  119  136  104  111   59   26   37
[12:55:32.953]     INFO: number of X-ray hits detected:    68850 46842 70206 113948 119835 127137 116814 87000 75461 96015 101322 90291 94959 53300 27610 27405
[12:55:32.953]     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:55:32.953]     INFO: number of Vcal hits detected:  207916 207946 207907 207836 207856 207813 207809 207880 207909 207880 207862 207894 207886 207941 207973 207963
[12:55:32.953]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[12:55:32.953]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:55:32.953]     INFO: X-ray hit rate [MHz/cm2]:  20.2 13.7 20.6 33.4 35.1 37.3 34.2 25.5 22.1 28.1 29.7 26.5 27.8 15.6 8.1 8.0
[12:55:32.953]     INFO: PixTestHighRate::doXPixelAlive() done
[12:55:32.998]     INFO: PixTest::       pg_setup set to default.
[12:55:33.015]     INFO: enter test to run
[12:55:58.697]     INFO:   test: HighRate no parameter change
[12:55:58.697]     INFO:   running: highrate
[12:55:58.698]     INFO:    ----------------------------------------------------------------------
[12:55:58.698]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:55:58.698]     INFO:    ----------------------------------------------------------------------
[12:55:59.319]     INFO: Expecting 208000 events.
[12:56:12.818]     INFO: 208000 events read in total (12972ms).
[12:56:12.823]     INFO: Test took 14116ms.
[12:56:13.134]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:13.439]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:56:13.439]     INFO: number of red-efficiency pixels:   239  161  311  478  425  594  551  264  244  364  410  324  298  153   65   68
[12:56:13.439]     INFO: number of X-ray hits detected:    138030 94385 140018 227504 239209 255161 231797 174801 151761 193794 203402 179696 190279 106859 54927 56671
[12:56:13.439]     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:56:13.439]     INFO: number of Vcal hits detected:  207741 207830 207651 207471 207545 207346 207402 207722 207743 207619 207561 207666 207690 207836 207935 207929
[12:56:13.439]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:56:13.439]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[12:56:13.439]     INFO: X-ray hit rate [MHz/cm2]:  40.5 27.7 41.0 66.7 70.1 74.8 67.9 51.2 44.5 56.8 59.6 52.7 55.8 31.3 16.1 16.6
[12:56:13.439]     INFO: PixTestHighRate::doXPixelAlive() done
[12:56:13.483]     INFO: PixTest::       pg_setup set to default.
[12:56:13.495]     INFO: enter test to run
[12:56:54.809]     INFO:   test: HighRate no parameter change
[12:56:54.809]     INFO:   running: highrate
[12:56:54.810]     INFO:    ----------------------------------------------------------------------
[12:56:54.810]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:56:54.810]     INFO:    ----------------------------------------------------------------------
[12:56:55.430]     INFO: Expecting 208000 events.
[12:57:10.191]     INFO: 208000 events read in total (14235ms).
[12:57:10.199]     INFO: Test took 15380ms.
[12:57:10.641]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:10.994]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:57:10.994]     INFO: number of red-efficiency pixels:   522  272  642 1165  940 1257 1240  556  535  837  918  718  603  289  110  108
[12:57:10.994]     INFO: number of X-ray hits detected:    202759 139552 207089 334442 352169 374376 342774 256432 224529 284785 299271 265581 280534 156641 80829 82873
[12:57:10.994]     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:57:10.994]     INFO: number of Vcal hits detected:  207349 207695 207172 206545 206897 206375 206411 207370 207399 207007 206902 207189 207336 207689 207889 207891
[12:57:10.994]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.9 99.6 99.4 99.5 99.3 99.3 99.7 99.7 99.6 99.5 99.6 99.7 99.9 99.9 99.9
[12:57:10.994]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.6 99.3 99.5 99.2 99.2 99.7 99.7 99.5 99.5 99.6 99.7 99.9 99.9 99.9
[12:57:10.994]     INFO: X-ray hit rate [MHz/cm2]:  59.4 40.9 60.7 98.0 103.2 109.7 100.5 75.2 65.8 83.5 87.7 77.8 82.2 45.9 23.7 24.3
[12:57:10.994]     INFO: PixTestHighRate::doXPixelAlive() done
[12:57:11.039]     INFO: PixTest::       pg_setup set to default.
[12:57:11.057]     INFO: enter test to run
[12:57:33.880]     INFO:   test: exit no parameter change
[12:57:34.296]    QUIET: Connection to board 32 closed.
[12:57:34.297]     INFO: pXar: this is the end, my friend