[16:02:27.119] INFO: *** Welcome to pxar ***
[16:02:27.119] INFO: *** Today: 2016/10/11
[16:02:31.255] INFO: *** Version: v1.9.0-818-g96727
[16:02:31.255] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//dacParameters35_C15.dat
[16:02:31.885] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:02:31.921] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//defaultMaskFile.dat
[16:02:31.954] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C15.dat
[16:02:33.440] INFO: clk: 4
[16:02:33.440] INFO: ctr: 4
[16:02:33.440] INFO: sda: 19
[16:02:33.440] INFO: tin: 9
[16:02:33.440] INFO: level: 15
[16:02:33.440] INFO: triggerdelay: 0
[16:02:33.440] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:02:33.440] INFO: Log level: INFO
[16:02:33.502] QUIET: Connection to board DTB_WREKRL opened.
[16:02:33.506] 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:
------------------------------------------------------
[16:02:33.509] INFO: RPC call hashes of host and DTB match: 398089610
[16:02:35.067] INFO: DUT info:
[16:02:35.067] INFO: The DUT currently contains the following objects:
[16:02:35.067] INFO: 2 TBM Cores tbm08c (2 ON)
[16:02:35.067] INFO: TBM Core alpha (0): 7 registers set
[16:02:35.067] INFO: TBM Core beta (1): 7 registers set
[16:02:35.067] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:02:35.067] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.067] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.068] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.068] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.068] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.068] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:02:35.616] INFO: enter 'restricted' command line mode
[16:02:35.616] INFO: enter test to run
[16:02:49.904] INFO: test: PixelAlive no parameter change
[16:02:49.904] INFO: running: pixelalive
[16:02:49.979] INFO: ----------------------------------------------------------------------
[16:02:49.979] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:02:49.979] INFO: ----------------------------------------------------------------------
[16:02:50.302] INFO: Expecting 41600 events.
[16:02:54.680] INFO: 41600 events read in total (3630ms).
[16:02:54.812] INFO: Test took 4831ms.
[16:02:54.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:55.346] INFO: PixTestAlive::aliveTest() done
[16:02:55.346] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:02:55.376] INFO: enter test to run
[16:03:03.743] INFO: test: timing no parameter change
[16:03:03.743] INFO: running: timing
[16:03:03.789] INFO: ######################################################################
[16:03:03.829] INFO: PixTestTiming::doTest()
[16:03:03.829] INFO: ######################################################################
[16:03:03.830] INFO: ----------------------------------------------------------------------
[16:03:03.830] INFO: PixTestTiming::TBMPhaseScan()
[16:03:03.830] INFO: ----------------------------------------------------------------------
[16:08:40.013] INFO: TBM Phase Settings: 224
[16:08:40.013] INFO: 400MHz Phase: 0
[16:08:40.013] INFO: 160MHz Phase: 7
[16:08:40.013] INFO: Functional Phase Area: 4
[16:08:40.024] INFO: Test took 336195 ms.
[16:08:40.024] INFO: PixTestTiming::TBMPhaseScan() done.
[16:08:40.024] INFO: ----------------------------------------------------------------------
[16:08:40.024] INFO: PixTestTiming::ROCDelayScan()
[16:08:40.024] INFO: ----------------------------------------------------------------------
[16:10:36.096] INFO: ROC Delay Settings: 220
[16:10:36.096] INFO: ROC Header-Trailer/Token Delay: 11
[16:10:36.096] INFO: ROC Port 0 Delay: 4
[16:10:36.096] INFO: ROC Port 1 Delay: 3
[16:10:36.096] INFO: Functional ROC Area: 4
[16:10:36.099] INFO: Test took 116075 ms.
[16:10:36.099] INFO: PixTestTiming::ROCDelayScan() done.
[16:10:36.099] INFO: ----------------------------------------------------------------------
[16:10:36.099] INFO: PixTestTiming::TimingTest()
[16:10:36.099] INFO: ----------------------------------------------------------------------
[16:10:52.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:07.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:22.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:37.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:52.609] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:07.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:22.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:37.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:52.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:07.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:08.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: Read back bit status: 1
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: Timings are good!
[16:13:08.197] INFO: ----------------------------------------------------------------------
[16:13:08.197] INFO: Test took 152098 ms.
[16:13:08.197] INFO: PixTestTiming::TimingTest() done.
[16:13:08.220] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:13:08.220] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:13:08.220] INFO: PixTestTiming::doTest took 604434 ms.
[16:13:08.221] INFO: PixTestTiming::doTest() done
[16:13:08.221] INFO: Write out TBMPhaseScan_0_V0
[16:13:08.221] INFO: Write out TBMPhaseScan_1_V0
[16:13:08.221] INFO: Write out CombinedTBMPhaseScan_V0
[16:13:08.245] INFO: Write out ROCDelayScan3_V0
[16:13:08.245] INFO: enter test to run
[16:13:37.076] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:13:37.076] INFO: running: highrate
[16:13:37.105] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:13:37.668] INFO: ----------------------------------------------------------------------
[16:13:37.668] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:13:37.668] INFO: ----------------------------------------------------------------------
[16:13:37.668] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:13:37.668] INFO: edge/corner pixel THR is adjusted
[16:13:37.668] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:13:38.641] INFO: Collecting data for 5 seconds...
[16:13:43.662] INFO: Done with hot pixel readout
[16:13:56.236] INFO: PixTest:: pg_setup set to default.



[16:13:56.237] INFO: 235 hot pixels found in step 0
[16:13:57.235] INFO: Collecting data for 5 seconds...
[16:14:02.254] INFO: Done with hot pixel readout
[16:14:14.601] INFO: PixTest:: pg_setup set to default.



[16:14:14.602] INFO: 212 hot pixels found in step 1
[16:14:15.599] INFO: Collecting data for 5 seconds...
[16:14:20.618] INFO: Done with hot pixel readout
[16:14:32.905] INFO: PixTest:: pg_setup set to default.



[16:14:32.906] INFO: 177 hot pixels found in step 2
[16:14:33.903] INFO: Collecting data for 5 seconds...
[16:14:38.922] INFO: Done with hot pixel readout
[16:14:51.151] INFO: PixTest:: pg_setup set to default.








[16:14:51.153] INFO: 175 hot pixels found in step 3
[16:14:52.150] INFO: Collecting data for 5 seconds...
[16:14:57.169] INFO: Done with hot pixel readout
[16:15:09.490] INFO: PixTest:: pg_setup set to default.





[16:15:09.492] INFO: 133 hot pixels found in step 4
[16:15:10.490] INFO: Collecting data for 5 seconds...
[16:15:15.511] INFO: Done with hot pixel readout
[16:15:28.502] INFO: PixTest:: pg_setup set to default.




[16:15:28.503] INFO: 141 hot pixels found in step 5
[16:15:29.500] INFO: Collecting data for 5 seconds...
[16:15:34.519] INFO: Done with hot pixel readout
[16:15:47.119] INFO: PixTest:: pg_setup set to default.









[16:15:47.121] INFO: 149 hot pixels found in step 6
[16:15:48.120] INFO: Collecting data for 5 seconds...
[16:15:53.140] INFO: Done with hot pixel readout
[16:16:05.846] INFO: PixTest:: pg_setup set to default.














[16:16:05.848] INFO: 112 hot pixels found in step 7
[16:16:06.846] INFO: Collecting data for 5 seconds...
[16:16:11.865] INFO: Done with hot pixel readout
[16:16:24.466] INFO: PixTest:: pg_setup set to default.










[16:16:24.468] INFO: 123 hot pixels found in step 8
[16:16:25.467] INFO: Collecting data for 5 seconds...
[16:16:30.485] INFO: Done with hot pixel readout
[16:16:43.060] INFO: PixTest:: pg_setup set to default.












[16:16:43.061] INFO: 105 hot pixels found in step 9
[16:16:44.059] INFO: Collecting data for 5 seconds...
[16:16:49.078] INFO: Done with hot pixel readout
[16:17:01.604] INFO: PixTest:: pg_setup set to default.


















[16:17:01.606] INFO: 84 hot pixels found in step 10
[16:17:02.605] INFO: Collecting data for 5 seconds...
[16:17:07.623] INFO: Done with hot pixel readout
[16:17:20.197] INFO: PixTest:: pg_setup set to default.















[16:17:20.199] INFO: 81 hot pixels found in step 11
[16:17:21.196] INFO: Collecting data for 5 seconds...
[16:17:26.214] INFO: Done with hot pixel readout
[16:17:38.770] INFO: PixTest:: pg_setup set to default.

















[16:17:38.772] INFO: 97 hot pixels found in step 12
[16:17:39.773] INFO: Collecting data for 5 seconds...
[16:17:44.792] INFO: Done with hot pixel readout
[16:17:57.694] INFO: PixTest:: pg_setup set to default.

















[16:17:57.695] INFO: 76 hot pixels found in step 13
[16:17:58.692] INFO: Collecting data for 5 seconds...
[16:18:03.711] INFO: Done with hot pixel readout
[16:18:16.753] INFO: PixTest:: pg_setup set to default.

























[16:18:16.754] INFO: 83 hot pixels found in step 14
[16:18:16.797] INFO: 83 hot pixels could not be trimmed and have been masked.
[16:18:16.801] INFO: PixTest::trimHotPixels() done
[16:18:16.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C0.dat
[16:18:16.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C1.dat
[16:18:16.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C2.dat
[16:18:16.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C3.dat
[16:18:16.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C4.dat
[16:18:16.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C5.dat
[16:18:16.843] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C6.dat
[16:18:16.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C7.dat
[16:18:16.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C8.dat
[16:18:16.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C9.dat
[16:18:16.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C10.dat
[16:18:16.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C11.dat
[16:18:16.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C12.dat
[16:18:16.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C13.dat
[16:18:16.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C14.dat
[16:18:16.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C15.dat
[16:18:16.904] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-02_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//defaultMaskFile.dat
[16:18:16.915] INFO: enter test to run
[16:18:26.705] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:18:26.705] INFO: running: xray
[16:18:26.706] INFO: ----------------------------------------------------------------------
[16:18:26.706] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:18:26.706] INFO: ----------------------------------------------------------------------
[16:18:27.753] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:18:38.680] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:19:09.103] INFO: Resuming triggers.
[16:19:20.027] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[16:19:49.883] INFO: Resuming triggers.
[16:20:00.810] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:20:30.722] INFO: Resuming triggers.
[16:20:41.641] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[16:21:11.678] INFO: Resuming triggers.
[16:21:22.598] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[16:21:52.552] INFO: Resuming triggers.
[16:22:03.469] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[16:22:33.268] INFO: Resuming triggers.
[16:22:44.190] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[16:23:14.022] INFO: Resuming triggers.
[16:23:24.945] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:23:54.783] INFO: Resuming triggers.
[16:24:05.702] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[16:24:35.571] INFO: Resuming triggers.
[16:24:37.612] INFO: data taking finished, elapsed time: 100 seconds.
[16:24:43.505] INFO: PixTest:: pg_setup set to default.
[16:24:43.508] INFO: PixTestXray::doPhRun() done
[16:24:43.700] INFO: enter test to run
[16:25:23.183] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:25:23.183] INFO: running: xray
[16:25:23.184] INFO: ----------------------------------------------------------------------
[16:25:23.184] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:25:23.184] INFO: ----------------------------------------------------------------------
[16:25:24.147] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:25:30.860] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:26:00.773] INFO: Resuming triggers.
[16:26:07.488] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:26:38.601] INFO: Resuming triggers.
[16:26:45.320] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:27:16.341] INFO: Resuming triggers.
[16:27:23.051] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:27:53.628] INFO: Resuming triggers.
[16:28:00.359] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:28:31.776] INFO: Resuming triggers.
[16:28:38.495] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:29:09.649] INFO: Resuming triggers.
[16:29:16.362] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:29:47.720] INFO: Resuming triggers.
[16:29:54.433] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:30:26.558] INFO: Resuming triggers.
[16:30:33.273] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:31:04.806] INFO: Resuming triggers.
[16:31:11.519] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:31:42.645] INFO: Resuming triggers.
[16:31:49.358] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:32:20.685] INFO: Resuming triggers.
[16:32:27.393] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:32:58.960] INFO: Resuming triggers.
[16:33:05.669] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[16:33:36.459] INFO: Resuming triggers.
[16:33:43.166] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:34:13.719] INFO: Resuming triggers.
[16:34:20.111] INFO: data taking finished, elapsed time: 100 seconds.
[16:34:49.357] INFO: PixTest:: pg_setup set to default.
[16:34:49.360] INFO: PixTestXray::doPhRun() done
[16:34:49.527] INFO: enter test to run
[16:35:10.131] INFO: test: HighRate no parameter change
[16:35:10.132] INFO: running: highrate
[16:35:10.153] INFO: ----------------------------------------------------------------------
[16:35:10.153] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:35:10.153] INFO: ----------------------------------------------------------------------
[16:35:10.313] INFO: Expecting 768 events.
[16:35:11.447] INFO: 768 events read in total (419ms).
[16:35:11.447] INFO: Test took 1269ms.
[16:35:12.251] INFO: Expecting 41600 events.
[16:35:15.246] INFO: 41600 events read in total (2469ms).
[16:35:15.247] INFO: Test took 3721ms.
[16:35:15.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:16.010] INFO: Expecting 41600 events.
[16:35:19.163] INFO: 41600 events read in total (2626ms).
[16:35:19.164] INFO: Test took 3866ms.
[16:35:19.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:19.925] INFO: Expecting 41600 events.
[16:35:23.162] INFO: 41600 events read in total (2710ms).
[16:35:23.163] INFO: Test took 3946ms.
[16:35:23.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:23.924] INFO: Expecting 41600 events.
[16:35:27.169] INFO: 41600 events read in total (2719ms).
[16:35:27.170] INFO: Test took 3954ms.
[16:35:27.206] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:27.927] INFO: Expecting 41600 events.
[16:35:31.186] INFO: 41600 events read in total (2732ms).
[16:35:31.187] INFO: Test took 3961ms.
[16:35:31.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:31.942] INFO: Expecting 41600 events.
[16:35:35.171] INFO: 41600 events read in total (2702ms).
[16:35:35.172] INFO: Test took 3930ms.
[16:35:35.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:35.926] INFO: Expecting 41600 events.
[16:35:39.155] INFO: 41600 events read in total (2702ms).
[16:35:39.156] INFO: Test took 3929ms.
[16:35:39.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:39.911] INFO: Expecting 41600 events.
[16:35:43.163] INFO: 41600 events read in total (2725ms).
[16:35:43.164] INFO: Test took 3954ms.
[16:35:43.200] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:43.920] INFO: Expecting 41600 events.
[16:35:47.172] INFO: 41600 events read in total (2725ms).
[16:35:47.173] INFO: Test took 3954ms.
[16:35:47.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:47.931] INFO: Expecting 41600 events.
[16:35:51.192] INFO: 41600 events read in total (2734ms).
[16:35:51.193] INFO: Test took 3967ms.
[16:35:51.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:51.951] INFO: Expecting 41600 events.
[16:35:55.203] INFO: 41600 events read in total (2725ms).
[16:35:55.204] INFO: Test took 3956ms.
[16:35:55.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:55.964] INFO: Expecting 41600 events.
[16:35:59.231] INFO: 41600 events read in total (2740ms).
[16:35:59.232] INFO: Test took 3975ms.
[16:35:59.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:59.987] INFO: Expecting 41600 events.
[16:36:03.251] INFO: 41600 events read in total (2738ms).
[16:36:03.252] INFO: Test took 3968ms.
[16:36:03.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:04.008] INFO: Expecting 41600 events.
[16:36:07.263] INFO: 41600 events read in total (2729ms).
[16:36:07.264] INFO: Test took 3958ms.
[16:36:07.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:08.024] INFO: Expecting 41600 events.
[16:36:11.269] INFO: 41600 events read in total (2718ms).
[16:36:11.270] INFO: Test took 3953ms.
[16:36:11.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:12.028] INFO: Expecting 41600 events.
[16:36:15.268] INFO: 41600 events read in total (2713ms).
[16:36:15.269] INFO: Test took 3946ms.
[16:36:15.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:16.029] INFO: Expecting 41600 events.
[16:36:19.285] INFO: 41600 events read in total (2729ms).
[16:36:19.286] INFO: Test took 3963ms.
[16:36:19.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:20.046] INFO: Expecting 41600 events.
[16:36:23.302] INFO: 41600 events read in total (2729ms).
[16:36:23.303] INFO: Test took 3962ms.
[16:36:23.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:24.058] INFO: Expecting 41600 events.
[16:36:27.274] INFO: 41600 events read in total (2689ms).
[16:36:27.275] INFO: Test took 3919ms.
[16:36:27.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:28.031] INFO: Expecting 41600 events.
[16:36:31.210] INFO: 41600 events read in total (2652ms).
[16:36:31.212] INFO: Test took 3885ms.
[16:36:31.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:31.607] INFO: enter test to run
[16:36:55.994] INFO: test: HighRate no parameter change
[16:36:55.994] INFO: running: highrate
[16:36:55.995] INFO: ----------------------------------------------------------------------
[16:36:55.995] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:36:55.995] INFO: ----------------------------------------------------------------------
[16:36:56.611] INFO: Expecting 208000 events.
[16:37:08.519] INFO: 208000 events read in total (11381ms).
[16:37:08.522] INFO: Test took 12518ms.
[16:37:08.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:08.925] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:37:08.945] INFO: number of red-efficiency pixels: 68 77 82 176 150 159 162 120 100 146 147 111 103 66 20 27
[16:37:08.945] INFO: number of X-ray hits detected: 70509 45776 72158 110414 115410 120783 123603 87597 75198 97494 92898 77633 81417 51779 21119 25699
[16:37:08.945] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:37:08.945] INFO: number of Vcal hits detected: 207930 207922 207914 207821 207846 207835 207830 207871 207898 207851 207845 207888 207896 207934 207980 207973
[16:37:08.945] 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 100.0 100.0 100.0 100.0
[16:37:08.945] 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 100.0 100.0 100.0 100.0
[16:37:08.945] INFO: X-ray hit rate [MHz/cm2]: 20.7 13.4 21.2 32.4 33.8 35.4 36.2 25.7 22.0 28.6 27.2 22.8 23.9 15.2 6.2 7.5
[16:37:08.945] INFO: PixTestHighRate::doXPixelAlive() done
[16:37:08.993] INFO: PixTest:: pg_setup set to default.
[16:37:08.006] INFO: enter test to run
[16:37:40.218] INFO: test: HighRate no parameter change
[16:37:40.218] INFO: running: highrate
[16:37:40.219] INFO: ----------------------------------------------------------------------
[16:37:40.219] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:37:40.219] INFO: ----------------------------------------------------------------------
[16:37:40.841] INFO: Expecting 208000 events.
[16:37:54.659] INFO: 208000 events read in total (13291ms).
[16:37:54.664] INFO: Test took 14434ms.
[16:37:54.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:55.272] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:37:55.272] INFO: number of red-efficiency pixels: 214 159 286 538 464 507 515 345 308 465 413 308 318 212 52 52
[16:37:55.272] INFO: number of X-ray hits detected: 148815 96135 151636 232044 242166 253085 259951 184219 157806 203734 195388 163076 172245 108261 44384 54507
[16:37:55.272] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:37:55.272] INFO: number of Vcal hits detected: 207771 207832 207680 207405 207499 207435 207399 207606 207675 207491 207547 207681 207656 207779 207947 207947
[16:37:55.272] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:37:55.272] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:37:55.273] INFO: X-ray hit rate [MHz/cm2]: 43.6 28.2 44.4 68.0 71.0 74.2 76.2 54.0 46.3 59.7 57.3 47.8 50.5 31.7 13.0 16.0
[16:37:55.273] INFO: PixTestHighRate::doXPixelAlive() done
[16:37:55.324] INFO: PixTest:: pg_setup set to default.
[16:37:55.343] INFO: enter test to run
[16:38:10.353] INFO: test: HighRate no parameter change
[16:38:10.353] INFO: running: highrate
[16:38:10.354] INFO: ----------------------------------------------------------------------
[16:38:10.354] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:38:10.354] INFO: ----------------------------------------------------------------------
[16:38:10.967] INFO: Expecting 208000 events.
[16:38:26.444] INFO: 208000 events read in total (14950ms).
[16:38:26.451] INFO: Test took 16088ms.
[16:38:26.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:27.225] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:38:27.225] INFO: number of red-efficiency pixels: 440 332 559 1215 988 1127 1141 721 577 936 702 639 675 444 95 99
[16:38:27.225] INFO: number of X-ray hits detected: 214640 139264 219220 334619 351131 365452 374555 266539 228271 296251 282355 235073 249705 156678 64453 79029
[16:38:27.225] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:38:27.225] INFO: number of Vcal hits detected: 207491 207614 207292 206467 206797 206506 206478 207083 207347 206876 207059 207266 207234 207465 207903 207899
[16:38:27.225] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.3 99.5 99.4 99.3 99.6 99.7 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[16:38:27.225] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.7 99.3 99.4 99.3 99.3 99.6 99.7 99.5 99.5 99.6 99.6 99.7 100.0 100.0
[16:38:27.225] INFO: X-ray hit rate [MHz/cm2]: 62.9 40.8 64.3 98.1 102.9 107.1 109.8 78.1 66.9 86.8 82.8 68.9 73.2 45.9 18.9 23.2
[16:38:27.225] INFO: PixTestHighRate::doXPixelAlive() done
[16:38:27.278] INFO: PixTest:: pg_setup set to default.
[16:38:27.295] INFO: enter test to run
[16:38:34.841] INFO: test: exit no parameter change
[16:38:35.451] QUIET: Connection to board 33 closed.
[16:38:35.573] INFO: pXar: this is the end, my friend