[11:58:06.574]     INFO: *** Welcome to pxar ***
[11:58:06.575]     INFO: *** Today: 2016/10/25
[11:58:06.596]     INFO: *** Version: v1.9.0-818-g96727
[11:58:06.597]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//dacParameters35_C15.dat
[11:58:06.598]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:58:06.598]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//defaultMaskFile.dat
[11:58:06.598]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C15.dat
[11:58:06.672]     INFO:         clk: 4
[11:58:06.672]     INFO:         ctr: 4
[11:58:06.672]     INFO:         sda: 19
[11:58:06.672]     INFO:         tin: 9
[11:58:06.672]     INFO:         level: 15
[11:58:06.672]     INFO:         triggerdelay: 0
[11:58:06.672]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:58:06.672]     INFO: Log level: INFO
[11:58:06.691]    QUIET: Connection to board DTB_WREHUL opened.
[11:58:06.694]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    30
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREHUL
MAC address: 40D85511801E
Hostname:    pixelDTB030
Comment:     
------------------------------------------------------
[11:58:06.697]     INFO: RPC call hashes of host and DTB match: 398089610
[11:58:08.227]     INFO: DUT info: 
[11:58:08.227]     INFO: The DUT currently contains the following objects:
[11:58:08.227]     INFO:  2 TBM Cores tbm08c (2 ON)
[11:58:08.227]     INFO: 	TBM Core alpha (0): 7 registers set
[11:58:08.227]     INFO: 	TBM Core beta  (1): 7 registers set
[11:58:08.227]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:58:08.227]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.227]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:08.630]     INFO: enter 'restricted' command line mode
[11:58:08.630]     INFO: enter test to run
[11:58:15.206]     INFO:   test: PixelAlive no parameter change
[11:58:15.207]     INFO:   running: pixelalive
[11:58:15.247]     INFO:    ----------------------------------------------------------------------
[11:58:15.247]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:58:15.247]     INFO:    ----------------------------------------------------------------------
[11:58:15.564]     INFO: Expecting 41600 events.
[11:58:19.873]     INFO: 41600 events read in total (3590ms).
[11:58:20.038]     INFO: Test took 4788ms.
[11:58:20.047]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:20.434]     INFO: PixTestAlive::aliveTest() done
[11:58:20.434]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    1    0    0    0    0    0    0    0    0   11    0
[11:58:21.236]     INFO: enter test to run
[11:58:26.070]     INFO:   test: timing no parameter change
[11:58:26.070]     INFO:   running: timing
[11:58:26.074]     INFO: ######################################################################
[11:58:26.074]     INFO: PixTestTiming::doTest()
[11:58:26.074]     INFO: ######################################################################
[11:58:26.074]     INFO:    ----------------------------------------------------------------------
[11:58:26.074]     INFO:    PixTestTiming::TBMPhaseScan()
[11:58:26.074]     INFO:    ----------------------------------------------------------------------
[12:04:11.065]     INFO: TBM Phase Settings: 240
[12:04:11.065]     INFO: 400MHz Phase: 4
[12:04:11.065]     INFO: 160MHz Phase: 7
[12:04:11.065]     INFO: Functional Phase Area: 4
[12:04:11.075]     INFO: Test took 345001 ms.
[12:04:11.075]     INFO: PixTestTiming::TBMPhaseScan() done.
[12:04:11.076]     INFO:    ----------------------------------------------------------------------
[12:04:11.076]     INFO:    PixTestTiming::ROCDelayScan()
[12:04:11.076]     INFO:    ----------------------------------------------------------------------
[12:08:08.993]     INFO: ROC Delay Settings: 227
[12:08:08.993]     INFO: ROC Header-Trailer/Token Delay: 11
[12:08:08.993]     INFO: ROC Port 0 Delay: 3
[12:08:08.993]     INFO: ROC Port 1 Delay: 4
[12:08:08.993]     INFO: Functional ROC Area: 4
[12:08:08.996]     INFO: Test took 237920 ms.
[12:08:08.996]     INFO: PixTestTiming::ROCDelayScan() done.
[12:08:08.997]     INFO:    ----------------------------------------------------------------------
[12:08:08.997]     INFO:    PixTestTiming::TimingTest()
[12:08:08.997]     INFO:    ----------------------------------------------------------------------
[12:08:25.318]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:40.412]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:55.536]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:10.622]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:25.672]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:40.732]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:55.768]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:10.773]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:25.810]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:40.906]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:41.288]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO:    Read back bit status: 1
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO:    Timings are good!
[12:10:41.307]     INFO:    ----------------------------------------------------------------------
[12:10:41.307]     INFO: Test took 152311 ms.
[12:10:41.307]     INFO: PixTestTiming::TimingTest() done.
[12:10:41.328]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:10:41.328]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:10:41.328]     INFO: PixTestTiming::doTest took 735258 ms.
[12:10:41.328]     INFO: PixTestTiming::doTest() done
[12:10:41.328]     INFO: Write out TBMPhaseScan_0_V0
[12:10:41.329]     INFO: Write out TBMPhaseScan_1_V0
[12:10:41.329]     INFO: Write out CombinedTBMPhaseScan_V0
[12:10:41.379]     INFO: Write out ROCDelayScan3_V0
[12:10:41.380]     INFO: enter test to run
[12:11:37.865]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:11:37.865]     INFO:   running: highrate
[12:11:37.880]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:11:38.428]     INFO:    ----------------------------------------------------------------------
[12:11:38.429]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:11:38.429]     INFO:    ----------------------------------------------------------------------
[12:11:38.429]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:11:38.429]     INFO: edge/corner pixel THR is adjusted
[12:11:38.429]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:11:39.409]     INFO: Collecting data for 5 seconds...
[12:11:44.429]     INFO: Done with hot pixel readout
[12:11:56.332]     INFO: PixTest::       pg_setup set to default.
[12:11:56.333]     INFO: 1 hot pixels found in step 0
[12:11:57.324]     INFO: Collecting data for 5 seconds...
[12:12:02.343]     INFO: Done with hot pixel readout
[12:12:14.207]     INFO: PixTest::       pg_setup set to default.
[12:12:14.208]     INFO: 1 hot pixels found in step 1
[12:12:15.199]     INFO: Collecting data for 5 seconds...
[12:12:20.217]     INFO: Done with hot pixel readout
[12:12:32.054]     INFO: PixTest::       pg_setup set to default.
[12:12:32.055]     INFO: 3 hot pixels found in step 2
[12:12:33.046]     INFO: Collecting data for 5 seconds...
[12:12:38.065]     INFO: Done with hot pixel readout
[12:12:49.925]     INFO: PixTest::       pg_setup set to default.
[12:12:49.925]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:12:49.925]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:12:49.926]     INFO: 6 hot pixels found in step 3
[12:12:50.917]     INFO: Collecting data for 5 seconds...
[12:12:55.936]     INFO: Done with hot pixel readout
[12:13:07.775]     INFO: PixTest::       pg_setup set to default.
[12:13:07.776]     INFO: 1 hot pixels found in step 4
[12:13:08.766]     INFO: Collecting data for 5 seconds...
[12:13:13.785]     INFO: Done with hot pixel readout
[12:13:25.930]     INFO: PixTest::       pg_setup set to default.
[12:13:25.930]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:25.931]     INFO: 2 hot pixels found in step 5
[12:13:26.922]     INFO: Collecting data for 5 seconds...
[12:13:31.940]     INFO: Done with hot pixel readout
[12:13:43.000]     INFO: PixTest::       pg_setup set to default.
[12:13:43.001]     INFO: 2 hot pixels found in step 6
[12:13:44.991]     INFO: Collecting data for 5 seconds...
[12:13:50.009]     INFO: Done with hot pixel readout
[12:14:01.890]     INFO: PixTest::       pg_setup set to default.
[12:14:01.891]     INFO: 1 hot pixels found in step 7
[12:14:02.884]     INFO: Collecting data for 5 seconds...
[12:14:07.903]     INFO: Done with hot pixel readout
[12:14:19.707]     INFO: PixTest::       pg_setup set to default.
[12:14:19.708]     INFO: 0 hot pixels found in step 8
[12:14:19.744]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:14:19.747]     INFO: PixTest::trimHotPixels() done
[12:14:19.747]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C0.dat
[12:14:19.776]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C1.dat
[12:14:19.789]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C2.dat
[12:14:19.795]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C3.dat
[12:14:19.800]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C4.dat
[12:14:19.806]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C5.dat
[12:14:19.812]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C6.dat
[12:14:19.817]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C7.dat
[12:14:19.823]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C8.dat
[12:14:19.828]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C9.dat
[12:14:19.834]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C10.dat
[12:14:19.839]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C11.dat
[12:14:19.844]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C12.dat
[12:14:19.850]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C13.dat
[12:14:19.855]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C14.dat
[12:14:19.861]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//trimParameters35_C15.dat
[12:14:19.866]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-08_FPIXTest-17C-FNAL-161024-1220-150V_2016-10-24_12h20m_1477329620/000_FPIXTest_p17//defaultMaskFile.dat
[12:14:19.876]     INFO: enter test to run
[12:15:08.352]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:15:08.352]     INFO:   running: xray
[12:15:08.353]     INFO:    ----------------------------------------------------------------------
[12:15:08.353]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:15:08.353]     INFO:    ----------------------------------------------------------------------
[12:15:09.316]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:15:21.036]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:15:50.334]     INFO: Resuming triggers.
[12:16:02.054]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:16:31.427]     INFO: Resuming triggers.
[12:16:43.147]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:17:12.566]     INFO: Resuming triggers.
[12:17:24.284]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:17:53.574]     INFO: Resuming triggers.
[12:18:05.293]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:18:34.559]     INFO: Resuming triggers.
[12:18:46.279]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:19:15.640]     INFO: Resuming triggers.
[12:19:27.363]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:19:56.821]     INFO: Resuming triggers.
[12:20:08.540]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:20:37.840]     INFO: Resuming triggers.
[12:20:44.410]     INFO: data taking finished, elapsed time: 100 seconds.
[12:21:01.066]     INFO: PixTest::       pg_setup set to default.
[12:21:01.070]     INFO: PixTestXray::doPhRun() done
[12:21:01.240]     INFO: enter test to run
[12:21:21.709]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:21:21.709]     INFO:   running: xray
[12:21:21.710]     INFO:    ----------------------------------------------------------------------
[12:21:21.710]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:21:21.710]     INFO:    ----------------------------------------------------------------------
[12:21:22.673]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:21:29.985]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:22:00.862]     INFO: Resuming triggers.
[12:22:08.171]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:22:38.825]     INFO: Resuming triggers.
[12:22:46.136]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:23:16.768]     INFO: Resuming triggers.
[12:23:24.077]     INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:23:54.726]     INFO: Resuming triggers.
[12:24:02.033]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:24:32.727]     INFO: Resuming triggers.
[12:24:40.033]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:25:11.017]     INFO: Resuming triggers.
[12:25:18.325]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:25:48.455]     INFO: Resuming triggers.
[12:25:55.767]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:26:27.310]     INFO: Resuming triggers.
[12:26:34.620]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:27:06.131]     INFO: Resuming triggers.
[12:27:13.444]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:27:44.450]     INFO: Resuming triggers.
[12:27:51.760]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:28:23.072]     INFO: Resuming triggers.
[12:28:30.379]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:29:01.302]     INFO: Resuming triggers.
[12:29:08.615]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:29:38.815]     INFO: Resuming triggers.
[12:29:44.148]     INFO: data taking finished, elapsed time: 100 seconds.
[12:30:06.326]     INFO: PixTest::       pg_setup set to default.
[12:30:06.329]     INFO: PixTestXray::doPhRun() done
[12:30:06.476]     INFO: enter test to run
[12:30:42.225]     INFO:   test: HighRate no parameter change
[12:30:42.225]     INFO:   running: highrate
[12:30:42.246]     INFO:    ----------------------------------------------------------------------
[12:30:42.246]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:30:42.246]     INFO:    ----------------------------------------------------------------------
[12:30:42.401]     INFO: Expecting 768 events.
[12:30:43.534]     INFO: 768 events read in total (418ms).
[12:30:43.535]     INFO: Test took 1268ms.
[12:30:44.338]     INFO: Expecting 41600 events.
[12:30:47.419]     INFO: 41600 events read in total (2554ms).
[12:30:47.420]     INFO: Test took 3878ms.
[12:30:47.452]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:48.180]     INFO: Expecting 41600 events.
[12:30:51.380]     INFO: 41600 events read in total (2673ms).
[12:30:51.381]     INFO: Test took 3912ms.
[12:30:51.413]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:52.138]     INFO: Expecting 41600 events.
[12:30:55.375]     INFO: 41600 events read in total (2711ms).
[12:30:55.376]     INFO: Test took 3945ms.
[12:30:55.408]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:56.131]     INFO: Expecting 41600 events.
[12:30:59.360]     INFO: 41600 events read in total (2702ms).
[12:30:59.361]     INFO: Test took 3936ms.
[12:30:59.392]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:00.117]     INFO: Expecting 41600 events.
[12:31:03.357]     INFO: 41600 events read in total (2713ms).
[12:31:03.358]     INFO: Test took 3947ms.
[12:31:03.391]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:04.116]     INFO: Expecting 41600 events.
[12:31:07.342]     INFO: 41600 events read in total (2700ms).
[12:31:07.342]     INFO: Test took 3935ms.
[12:31:07.375]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:08.101]     INFO: Expecting 41600 events.
[12:31:11.328]     INFO: 41600 events read in total (2700ms).
[12:31:11.328]     INFO: Test took 3936ms.
[12:31:11.361]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:12.089]     INFO: Expecting 41600 events.
[12:31:15.335]     INFO: 41600 events read in total (2719ms).
[12:31:15.336]     INFO: Test took 3957ms.
[12:31:15.369]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:16.094]     INFO: Expecting 41600 events.
[12:31:19.332]     INFO: 41600 events read in total (2711ms).
[12:31:19.333]     INFO: Test took 3947ms.
[12:31:19.365]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:20.094]     INFO: Expecting 41600 events.
[12:31:23.340]     INFO: 41600 events read in total (2719ms).
[12:31:23.341]     INFO: Test took 3958ms.
[12:31:23.374]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:24.102]     INFO: Expecting 41600 events.
[12:31:27.347]     INFO: 41600 events read in total (2718ms).
[12:31:27.348]     INFO: Test took 3956ms.
[12:31:27.381]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:28.106]     INFO: Expecting 41600 events.
[12:31:31.343]     INFO: 41600 events read in total (2710ms).
[12:31:31.344]     INFO: Test took 3946ms.
[12:31:31.377]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:32.104]     INFO: Expecting 41600 events.
[12:31:35.324]     INFO: 41600 events read in total (2693ms).
[12:31:35.326]     INFO: Test took 3930ms.
[12:31:35.361]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:36.082]     INFO: Expecting 41600 events.
[12:31:39.311]     INFO: 41600 events read in total (2702ms).
[12:31:39.312]     INFO: Test took 3933ms.
[12:31:39.346]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:40.071]     INFO: Expecting 41600 events.
[12:31:43.308]     INFO: 41600 events read in total (2710ms).
[12:31:43.309]     INFO: Test took 3946ms.
[12:31:43.343]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:44.070]     INFO: Expecting 41600 events.
[12:31:47.314]     INFO: 41600 events read in total (2717ms).
[12:31:47.315]     INFO: Test took 3953ms.
[12:31:47.349]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:48.074]     INFO: Expecting 41600 events.
[12:31:51.308]     INFO: 41600 events read in total (2707ms).
[12:31:51.309]     INFO: Test took 3943ms.
[12:31:51.342]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:52.066]     INFO: Expecting 41600 events.
[12:31:55.330]     INFO: 41600 events read in total (2737ms).
[12:31:55.330]     INFO: Test took 3969ms.
[12:31:55.364]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:56.086]     INFO: Expecting 41600 events.
[12:31:59.294]     INFO: 41600 events read in total (2681ms).
[12:31:59.295]     INFO: Test took 3914ms.
[12:31:59.327]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:00.056]     INFO: Expecting 41600 events.
[12:32:03.153]     INFO: 41600 events read in total (2570ms).
[12:32:03.154]     INFO: Test took 3808ms.
[12:32:03.186]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:03.551]     INFO: enter test to run
[12:33:03.032]     INFO:   test: HighRate no parameter change
[12:33:03.032]     INFO:   running: highrate
[12:33:03.034]     INFO:    ----------------------------------------------------------------------
[12:33:03.034]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:33:03.034]     INFO:    ----------------------------------------------------------------------
[12:33:03.652]     INFO: Expecting 208000 events.
[12:33:15.384]     INFO: 208000 events read in total (11205ms).
[12:33:15.387]     INFO: Test took 12344ms.
[12:33:15.525]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:15.775]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    1    0    0    0    0    0    0    0    0   11    0
[12:33:15.775]     INFO: number of red-efficiency pixels:    76   54   64   97  134  161  136   86   58  118  114  114  111   53   38   33
[12:33:15.775]     INFO: number of X-ray hits detected:    64089 40678 62731 93837 108038 115505 114274 77237 69869 97584 90086 81227 80167 41748 20875 23745
[12:33:15.775]     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:33:15.775]     INFO: number of Vcal hits detected:  207921 207946 207935 207901 207863 207788 207860 207913 207942 207882 207884 207883 207888 207946 207423 207967
[12:33:15.775]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:33:15.775]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.7 100.0
[12:33:15.775]     INFO: X-ray hit rate [MHz/cm2]:  18.8 11.9 18.4 27.5 31.7 33.9 33.5 22.6 20.5 28.6 26.4 23.8 23.5 12.2 6.1 7.0
[12:33:15.775]     INFO: PixTestHighRate::doXPixelAlive() done
[12:33:15.827]     INFO: PixTest::       pg_setup set to default.
[12:33:15.843]     INFO: enter test to run
[12:33:28.352]     INFO:   test: HighRate no parameter change
[12:33:28.352]     INFO:   running: highrate
[12:33:28.353]     INFO:    ----------------------------------------------------------------------
[12:33:28.353]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:33:28.353]     INFO:    ----------------------------------------------------------------------
[12:33:28.972]     INFO: Expecting 208000 events.
[12:33:42.195]     INFO: 208000 events read in total (12696ms).
[12:33:42.200]     INFO: Test took 13838ms.
[12:33:42.466]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:42.755]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    1    0    0    0    0    0    0    0    0   10    0
[12:33:42.755]     INFO: number of red-efficiency pixels:   204  106  173  252  443  393  400  280  185  358  303  227  246  109   60   52
[12:33:42.755]     INFO: number of X-ray hits detected:    124882 78756 122178 182025 208826 223029 221203 149873 135431 188823 173965 158958 155924 81046 40607 45853
[12:33:42.755]     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:33:42.755]     INFO: number of Vcal hits detected:  207784 207890 207820 207732 207526 207518 207574 207704 207810 207625 207688 207761 207751 207887 207402 207947
[12:33:42.755]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0 100.0
[12:33:42.756]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.7 100.0
[12:33:42.756]     INFO: X-ray hit rate [MHz/cm2]:  36.6 23.1 35.8 53.4 61.2 65.4 64.8 43.9 39.7 55.3 51.0 46.6 45.7 23.8 11.9 13.4
[12:33:42.756]     INFO: PixTestHighRate::doXPixelAlive() done
[12:33:42.809]     INFO: PixTest::       pg_setup set to default.
[12:33:42.822]     INFO: enter test to run
[12:33:55.416]     INFO:   test: HighRate no parameter change
[12:33:55.416]     INFO:   running: highrate
[12:33:55.417]     INFO:    ----------------------------------------------------------------------
[12:33:55.417]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:33:55.417]     INFO:    ----------------------------------------------------------------------
[12:33:56.036]     INFO: Expecting 208000 events.
[12:34:10.861]     INFO: 208000 events read in total (14299ms).
[12:34:10.867]     INFO: Test took 15441ms.
[12:34:11.252]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:11.583]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    1    0    0    0    0    0    0    0    0   11    0
[12:34:11.584]     INFO: number of red-efficiency pixels:   411  216  375  574 1045  863  863  602  338  824  663  454  511  263  101   75
[12:34:11.584]     INFO: number of X-ray hits detected:    188175 118856 184370 273872 315143 337064 332976 226339 205284 285897 262904 239449 234302 122056 61715 69472
[12:34:11.584]     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:34:11.584]     INFO: number of Vcal hits detected:  207523 207771 207574 207368 206744 206938 206943 207240 207631 207053 207244 207495 207445 207710 207356 207925
[12:34:11.584]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.8 99.7 99.4 99.5 99.6 99.7 99.8 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[12:34:11.584]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.8 99.7 99.4 99.5 99.5 99.6 99.8 99.5 99.6 99.8 99.7 99.9 99.7 100.0
[12:34:11.584]     INFO: X-ray hit rate [MHz/cm2]:  55.2 34.8 54.0 80.3 92.4 98.8 97.6 66.3 60.2 83.8 77.1 70.2 68.7 35.8 18.1 20.4
[12:34:11.584]     INFO: PixTestHighRate::doXPixelAlive() done
[12:34:11.633]     INFO: PixTest::       pg_setup set to default.
[12:34:11.647]     INFO: enter test to run
[12:34:14.536]     INFO:   test: exit no parameter change
[12:34:15.011]    QUIET: Connection to board 30 closed.
[12:34:15.025]     INFO: pXar: this is the end, my friend