[15:18:42.011] INFO: *** Welcome to pxar ***
[15:18:42.011] INFO: *** Today: 2016/09/23
[15:18:45.659] INFO: *** Version: v1.9.0-818-g96727
[15:18:45.659] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//dacParameters35_C15.dat
[15:18:46.487] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:18:46.487] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[15:18:46.538] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[15:18:48.426] INFO: clk: 4
[15:18:48.426] INFO: ctr: 4
[15:18:48.426] INFO: sda: 19
[15:18:48.426] INFO: tin: 9
[15:18:48.426] INFO: level: 15
[15:18:48.426] INFO: triggerdelay: 0
[15:18:48.427] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:18:48.427] INFO: Log level: INFO
[15:18:48.473] QUIET: Connection to board DTB_WREKRL opened.
[15:18:48.476] 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:
------------------------------------------------------
[15:18:48.479] INFO: RPC call hashes of host and DTB match: 398089610
[15:18:50.073] INFO: DUT info:
[15:18:50.073] INFO: The DUT currently contains the following objects:
[15:18:50.074] INFO: 2 TBM Cores tbm08c (2 ON)
[15:18:50.074] INFO: TBM Core alpha (0): 7 registers set
[15:18:50.074] INFO: TBM Core beta (1): 7 registers set
[15:18:50.074] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:18:50.074] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.074] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:50.632] INFO: enter 'restricted' command line mode
[15:18:50.632] INFO: enter test to run
[15:19:07.646] INFO: test: PixelAlive no parameter change
[15:19:07.646] INFO: running: pixelalive
[15:19:07.776] INFO: ----------------------------------------------------------------------
[15:19:07.776] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:19:07.776] INFO: ----------------------------------------------------------------------
[15:19:08.099] INFO: Expecting 41600 events.
[15:19:12.695] INFO: 41600 events read in total (3878ms).
[15:19:12.862] INFO: Test took 5082ms.
[15:19:12.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:14.860] INFO: PixTestAlive::aliveTest() done
[15:19:14.860] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:19:15.308] INFO: enter test to run
[15:19:22.566] INFO: test: timing no parameter change
[15:19:22.566] INFO: running: timing
[15:19:22.569] INFO: ######################################################################
[15:19:22.569] INFO: PixTestTiming::doTest()
[15:19:22.569] INFO: ######################################################################
[15:19:22.570] INFO: ----------------------------------------------------------------------
[15:19:22.570] INFO: PixTestTiming::TBMPhaseScan()
[15:19:22.570] INFO: ----------------------------------------------------------------------
[15:24:01.196] INFO: TBM Phase Settings: 236
[15:24:01.196] INFO: 400MHz Phase: 3
[15:24:01.196] INFO: 160MHz Phase: 7
[15:24:01.196] INFO: Functional Phase Area: 4
[15:24:01.207] INFO: Test took 278638 ms.
[15:24:01.208] INFO: PixTestTiming::TBMPhaseScan() done.
[15:24:01.208] INFO: ----------------------------------------------------------------------
[15:24:01.208] INFO: PixTestTiming::ROCDelayScan()
[15:24:01.208] INFO: ----------------------------------------------------------------------
[15:26:11.021] INFO: ROC Delay Settings: 220
[15:26:11.021] INFO: ROC Header-Trailer/Token Delay: 11
[15:26:11.021] INFO: ROC Port 0 Delay: 4
[15:26:11.021] INFO: ROC Port 1 Delay: 3
[15:26:11.021] INFO: Functional ROC Area: 5
[15:26:11.024] INFO: Test took 129816 ms.
[15:26:11.024] INFO: PixTestTiming::ROCDelayScan() done.
[15:26:11.025] INFO: ----------------------------------------------------------------------
[15:26:11.025] INFO: PixTestTiming::TimingTest()
[15:26:11.025] INFO: ----------------------------------------------------------------------
[15:26:27.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:42.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:57.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:12.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:27.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:42.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:57.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:12.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:28.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:43.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:43.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:43.749] INFO: ----------------------------------------------------------------------
[15:28:43.749] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:28:43.749] INFO: ----------------------------------------------------------------------
[15:28:43.749] INFO: ----------------------------------------------------------------------
[15:28:43.749] INFO: Read back bit status: 1
[15:28:43.749] INFO: ----------------------------------------------------------------------
[15:28:43.749] INFO: ----------------------------------------------------------------------
[15:28:43.749] INFO: Timings are good!
[15:28:43.750] INFO: ----------------------------------------------------------------------
[15:28:43.750] INFO: Test took 152725 ms.
[15:28:43.750] INFO: PixTestTiming::TimingTest() done.
[15:28:43.750] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:28:43.777] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:28:43.777] INFO: PixTestTiming::doTest took 561211 ms.
[15:28:43.777] INFO: PixTestTiming::doTest() done
[15:28:43.777] INFO: Write out TBMPhaseScan_0_V0
[15:28:43.777] INFO: Write out TBMPhaseScan_1_V0
[15:28:43.777] INFO: Write out CombinedTBMPhaseScan_V0
[15:28:43.859] INFO: Write out ROCDelayScan3_V0
[15:28:43.860] INFO: enter test to run
[15:31:02.833] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:31:02.833] INFO: running: highrate
[15:31:02.968] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:31:03.757] INFO: ----------------------------------------------------------------------
[15:31:03.757] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:31:03.757] INFO: ----------------------------------------------------------------------
[15:31:03.757] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:31:03.757] INFO: edge/corner pixel THR is adjusted
[15:31:03.757] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:31:04.715] INFO: Collecting data for 5 seconds...
[15:31:09.734] INFO: Done with hot pixel readout
[15:31:21.437] INFO: PixTest:: pg_setup set to default.
[15:31:21.438] INFO: 3 hot pixels found in step 0
[15:31:22.430] INFO: Collecting data for 5 seconds...
[15:31:27.447] INFO: Done with hot pixel readout
[15:31:39.111] INFO: PixTest:: pg_setup set to default.
[15:31:39.111] INFO: 1 hot pixels found in step 1
[15:31:40.103] INFO: Collecting data for 5 seconds...
[15:31:45.121] INFO: Done with hot pixel readout
[15:31:56.936] INFO: PixTest:: pg_setup set to default.
[15:31:56.937] INFO: 2 hot pixels found in step 2
[15:31:57.928] INFO: Collecting data for 5 seconds...
[15:32:02.946] INFO: Done with hot pixel readout
[15:32:14.463] INFO: PixTest:: pg_setup set to default.
[15:32:14.464] INFO: 1 hot pixels found in step 3
[15:32:15.456] INFO: Collecting data for 5 seconds...
[15:32:20.473] INFO: Done with hot pixel readout
[15:32:31.879] INFO: PixTest:: pg_setup set to default.
[15:32:31.880] INFO: 0 hot pixels found in step 4
[15:32:31.915] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:32:31.918] INFO: PixTest::trimHotPixels() done
[15:32:31.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat
[15:32:31.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C1.dat
[15:32:31.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C2.dat
[15:32:31.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C3.dat
[15:32:31.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C4.dat
[15:32:31.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C5.dat
[15:32:31.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C6.dat
[15:32:31.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C7.dat
[15:32:31.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C8.dat
[15:32:31.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C9.dat
[15:32:31.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C10.dat
[15:32:31.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C11.dat
[15:32:31.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C12.dat
[15:32:31.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C13.dat
[15:32:31.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C14.dat
[15:32:31.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[15:32:31.005] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[15:32:32.016] INFO: enter test to run
[15:33:59.136] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:33:59.136] INFO: running: highrate
[15:33:59.141] INFO: ----------------------------------------------------------------------
[15:33:59.141] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:33:59.141] INFO: ----------------------------------------------------------------------
[15:33:59.141] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:33:59.141] INFO: edge/corner pixel THR is adjusted
[15:33:59.141] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:34:00.098] INFO: Collecting data for 1 seconds...
[15:34:01.102] INFO: Done with hot pixel readout
[15:34:05.050] INFO: PixTest:: pg_setup set to default.
[15:34:05.050] INFO: 0 hot pixels found in step 0
[15:34:05.056] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:34:05.145] INFO: PixTest::trimHotPixels() done
[15:34:05.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat
[15:34:05.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C1.dat
[15:34:05.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C2.dat
[15:34:05.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C3.dat
[15:34:05.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C4.dat
[15:34:05.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C5.dat
[15:34:05.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C6.dat
[15:34:05.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C7.dat
[15:34:05.198] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C8.dat
[15:34:05.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C9.dat
[15:34:05.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C10.dat
[15:34:05.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C11.dat
[15:34:05.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C12.dat
[15:34:05.225] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C13.dat
[15:34:05.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C14.dat
[15:34:05.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[15:34:05.241] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-13_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[15:34:05.251] INFO: enter test to run
[15:35:42.999] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:35:42.000] INFO: running: xray
[15:35:43.026] INFO: ----------------------------------------------------------------------
[15:35:43.026] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:35:43.026] INFO: ----------------------------------------------------------------------
[15:35:44.012] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:35:55.121] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:36:24.928] INFO: Resuming triggers.
[15:36:36.038] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:37:05.694] INFO: Resuming triggers.
[15:37:16.800] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:37:46.392] INFO: Resuming triggers.
[15:37:57.500] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:38:27.192] INFO: Resuming triggers.
[15:38:38.302] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:39:07.944] INFO: Resuming triggers.
[15:39:19.053] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:39:48.751] INFO: Resuming triggers.
[15:39:59.857] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:40:29.374] INFO: Resuming triggers.
[15:40:40.484] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:41:10.181] INFO: Resuming triggers.
[15:41:21.290] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:41:50.868] INFO: Resuming triggers.
[15:41:51.218] INFO: data taking finished, elapsed time: 100 seconds.
[15:41:52.600] INFO: PixTest:: pg_setup set to default.
[15:41:52.603] INFO: PixTestXray::doPhRun() done
[15:41:52.799] INFO: enter test to run
[15:42:35.349] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:42:35.349] INFO: running: xray
[15:42:35.350] INFO: ----------------------------------------------------------------------
[15:42:35.350] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:42:35.350] INFO: ----------------------------------------------------------------------
[15:42:36.314] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:42:43.296] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:43:14.471] INFO: Resuming triggers.
[15:43:21.455] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:43:52.359] INFO: Resuming triggers.
[15:43:59.339] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:44:30.167] INFO: Resuming triggers.
[15:44:37.152] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:45:07.903] INFO: Resuming triggers.
[15:45:14.882] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:45:45.566] INFO: Resuming triggers.
[15:45:52.547] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:46:23.547] INFO: Resuming triggers.
[15:46:30.530] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:47:01.611] INFO: Resuming triggers.
[15:47:08.599] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:47:40.455] INFO: Resuming triggers.
[15:47:47.443] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:48:19.129] INFO: Resuming triggers.
[15:48:26.114] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:48:56.971] INFO: Resuming triggers.
[15:49:03.959] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:49:34.267] INFO: Resuming triggers.
[15:49:41.249] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:50:11.474] INFO: Resuming triggers.
[15:50:18.457] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:50:48.700] INFO: Resuming triggers.
[15:50:55.689] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:51:25.933] INFO: Resuming triggers.
[15:51:28.512] INFO: data taking finished, elapsed time: 100 seconds.
[15:51:39.962] INFO: PixTest:: pg_setup set to default.
[15:51:39.965] INFO: PixTestXray::doPhRun() done
[15:51:40.117] INFO: enter test to run
[15:52:38.425] INFO: test: HighRate no parameter change
[15:52:38.425] INFO: running: highrate
[15:52:38.476] INFO: ----------------------------------------------------------------------
[15:52:38.476] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:52:38.476] INFO: ----------------------------------------------------------------------
[15:52:38.632] INFO: Expecting 768 events.
[15:52:39.765] INFO: 768 events read in total (418ms).
[15:52:39.766] INFO: Test took 1269ms.
[15:52:40.569] INFO: Expecting 41600 events.
[15:52:43.713] INFO: 41600 events read in total (2617ms).
[15:52:43.714] INFO: Test took 3940ms.
[15:52:43.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:44.471] INFO: Expecting 41600 events.
[15:52:47.698] INFO: 41600 events read in total (2700ms).
[15:52:47.699] INFO: Test took 3933ms.
[15:52:47.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:48.454] INFO: Expecting 41600 events.
[15:52:51.685] INFO: 41600 events read in total (2704ms).
[15:52:51.686] INFO: Test took 3934ms.
[15:52:51.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:52.445] INFO: Expecting 41600 events.
[15:52:55.705] INFO: 41600 events read in total (2733ms).
[15:52:55.706] INFO: Test took 3966ms.
[15:52:55.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:56.464] INFO: Expecting 41600 events.
[15:52:59.712] INFO: 41600 events read in total (2721ms).
[15:52:59.713] INFO: Test took 3956ms.
[15:52:59.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:00.472] INFO: Expecting 41600 events.
[15:53:03.721] INFO: 41600 events read in total (2722ms).
[15:53:03.722] INFO: Test took 3956ms.
[15:53:03.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:04.480] INFO: Expecting 41600 events.
[15:53:07.738] INFO: 41600 events read in total (2731ms).
[15:53:07.739] INFO: Test took 3965ms.
[15:53:07.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:08.494] INFO: Expecting 41600 events.
[15:53:11.752] INFO: 41600 events read in total (2731ms).
[15:53:11.753] INFO: Test took 3961ms.
[15:53:11.788] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:12.512] INFO: Expecting 41600 events.
[15:53:15.759] INFO: 41600 events read in total (2720ms).
[15:53:15.760] INFO: Test took 3955ms.
[15:53:15.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:16.519] INFO: Expecting 41600 events.
[15:53:19.766] INFO: 41600 events read in total (2720ms).
[15:53:19.767] INFO: Test took 3954ms.
[15:53:19.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:20.527] INFO: Expecting 41600 events.
[15:53:23.786] INFO: 41600 events read in total (2733ms).
[15:53:23.788] INFO: Test took 3967ms.
[15:53:23.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:24.545] INFO: Expecting 41600 events.
[15:53:27.806] INFO: 41600 events read in total (2734ms).
[15:53:27.807] INFO: Test took 3961ms.
[15:53:27.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:28.566] INFO: Expecting 41600 events.
[15:53:31.814] INFO: 41600 events read in total (2721ms).
[15:53:31.815] INFO: Test took 3955ms.
[15:53:31.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:32.574] INFO: Expecting 41600 events.
[15:53:35.832] INFO: 41600 events read in total (2731ms).
[15:53:35.833] INFO: Test took 3966ms.
[15:53:35.868] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:36.589] INFO: Expecting 41600 events.
[15:53:39.842] INFO: 41600 events read in total (2726ms).
[15:53:39.843] INFO: Test took 3957ms.
[15:53:39.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:40.603] INFO: Expecting 41600 events.
[15:53:43.862] INFO: 41600 events read in total (2732ms).
[15:53:43.863] INFO: Test took 3966ms.
[15:53:43.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:44.621] INFO: Expecting 41600 events.
[15:53:47.869] INFO: 41600 events read in total (2721ms).
[15:53:47.870] INFO: Test took 3955ms.
[15:53:47.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:48.627] INFO: Expecting 41600 events.
[15:53:51.901] INFO: 41600 events read in total (2747ms).
[15:53:51.902] INFO: Test took 3979ms.
[15:53:51.936] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:52.661] INFO: Expecting 41600 events.
[15:53:55.898] INFO: 41600 events read in total (2710ms).
[15:53:55.899] INFO: Test took 3945ms.
[15:53:55.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:56.658] INFO: Expecting 41600 events.
[15:53:59.782] INFO: 41600 events read in total (2597ms).
[15:53:59.782] INFO: Test took 3830ms.
[15:53:59.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:00.180] INFO: enter test to run
[15:54:50.936] INFO: test: HighRate no parameter change
[15:54:50.936] INFO: running: highrate
[15:54:50.937] INFO: ----------------------------------------------------------------------
[15:54:50.937] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:54:50.937] INFO: ----------------------------------------------------------------------
[15:54:51.558] INFO: Expecting 208000 events.
[15:55:03.479] INFO: 208000 events read in total (11394ms).
[15:55:03.482] INFO: Test took 12535ms.
[15:55:03.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:03.884] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:55:03.884] INFO: number of red-efficiency pixels: 85 48 86 164 158 197 142 89 84 104 111 113 130 75 24 39
[15:55:03.884] INFO: number of X-ray hits detected: 65657 42990 67691 109157 112778 119139 117980 81098 77694 99693 97699 85835 87262 53151 20383 27538
[15:55:03.884] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:55:03.884] INFO: number of Vcal hits detected: 207864 207950 207914 207831 207839 207799 207856 207910 207914 207892 207888 207845 207865 207923 207976 207912
[15:55:03.885] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0
[15:55:03.885] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:55:03.885] INFO: X-ray hit rate [MHz/cm2]: 19.2 12.6 19.8 32.0 33.1 34.9 34.6 23.8 22.8 29.2 28.6 25.2 25.6 15.6 6.0 8.1
[15:55:03.885] INFO: PixTestHighRate::doXPixelAlive() done
[15:55:03.938] INFO: PixTest:: pg_setup set to default.
[15:55:03.952] INFO: enter test to run
[15:55:18.360] INFO: test: HighRate no parameter change
[15:55:18.360] INFO: running: highrate
[15:55:18.361] INFO: ----------------------------------------------------------------------
[15:55:18.361] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:55:18.361] INFO: ----------------------------------------------------------------------
[15:55:18.982] INFO: Expecting 208000 events.
[15:55:32.514] INFO: 208000 events read in total (13006ms).
[15:55:32.519] INFO: Test took 14147ms.
[15:55:32.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:33.098] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:55:33.098] INFO: number of red-efficiency pixels: 229 114 277 507 497 553 428 255 272 400 337 330 312 172 44 55
[15:55:33.098] INFO: number of X-ray hits detected: 131060 85539 132555 213838 221398 234640 231987 160458 153885 196514 192036 169134 172627 105563 40073 54452
[15:55:33.098] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:55:33.098] INFO: number of Vcal hits detected: 207714 207879 207689 207440 207468 207381 207547 207723 207715 207583 207639 207600 207664 207816 207954 207896
[15:55:33.098] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[15:55:33.098] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:55:33.098] INFO: X-ray hit rate [MHz/cm2]: 38.4 25.1 38.9 62.7 64.9 68.8 68.0 47.0 45.1 57.6 56.3 49.6 50.6 30.9 11.7 16.0
[15:55:33.098] INFO: PixTestHighRate::doXPixelAlive() done
[15:55:33.144] INFO: PixTest:: pg_setup set to default.
[15:55:33.161] INFO: enter test to run
[15:55:57.607] INFO: test: HighRate no parameter change
[15:55:57.607] INFO: running: highrate
[15:55:57.608] INFO: ----------------------------------------------------------------------
[15:55:57.608] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:55:57.609] INFO: ----------------------------------------------------------------------
[15:55:58.223] INFO: Expecting 208000 events.
[15:56:13.418] INFO: 208000 events read in total (14668ms).
[15:56:13.425] INFO: Test took 15805ms.
[15:56:13.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:14.171] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:56:14.171] INFO: number of red-efficiency pixels: 442 236 612 1030 1093 1246 907 503 552 833 581 633 662 423 86 104
[15:56:14.171] INFO: number of X-ray hits detected: 190590 124090 192299 310513 321483 340621 337579 234252 222938 286096 278936 245084 251501 153465 57901 78690
[15:56:14.171] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:56:14.171] INFO: number of Vcal hits detected: 207442 207739 207208 206712 206610 206336 206885 207406 207375 207028 207350 207131 207236 207500 207910 207845
[15:56:14.171] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.4 99.3 99.5 99.7 99.7 99.6 99.7 99.6 99.7 99.8 100.0 100.0
[15:56:14.171] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.4 99.3 99.2 99.5 99.7 99.7 99.5 99.7 99.6 99.6 99.8 100.0 99.9
[15:56:14.171] INFO: X-ray hit rate [MHz/cm2]: 55.9 36.4 56.4 91.0 94.2 99.8 98.9 68.7 65.3 83.9 81.8 71.8 73.7 45.0 17.0 23.1
[15:56:14.171] INFO: PixTestHighRate::doXPixelAlive() done
[15:56:14.222] INFO: PixTest:: pg_setup set to default.
[15:56:14.238] INFO: enter test to run
[15:56:30.575] INFO: test: exit no parameter change
[15:56:31.042] QUIET: Connection to board 33 closed.
[15:56:31.055] INFO: pXar: this is the end, my friend