[11:35:04.293] INFO: *** Welcome to pxar ***
[11:35:04.294] INFO: *** Today: 2016/09/12
[11:35:05.560] INFO: *** Version: v1.9.0-818-g96727
[11:35:05.561] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//dacParameters35_C15.dat
[11:35:05.667] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:35:05.667] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//defaultMaskFile.dat
[11:35:05.667] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C15.dat
[11:35:05.779] INFO: clk: 4
[11:35:05.779] INFO: ctr: 4
[11:35:05.779] INFO: sda: 19
[11:35:05.779] INFO: tin: 9
[11:35:05.779] INFO: level: 15
[11:35:05.779] INFO: triggerdelay: 0
[11:35:05.779] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:35:05.779] INFO: Log level: INFO
[11:35:05.792] QUIET: Connection to board DTB_WREKRL opened.
[11:35:05.795] 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:
------------------------------------------------------
[11:35:05.798] INFO: RPC call hashes of host and DTB match: 398089610
[11:35:07.328] INFO: DUT info:
[11:35:07.328] INFO: The DUT currently contains the following objects:
[11:35:07.328] INFO: 2 TBM Cores tbm08c (2 ON)
[11:35:07.328] INFO: TBM Core alpha (0): 7 registers set
[11:35:07.328] INFO: TBM Core beta (1): 7 registers set
[11:35:07.328] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:35:07.328] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.328] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:35:07.753] INFO: enter 'restricted' command line mode
[11:35:07.753] INFO: enter test to run
[11:35:19.775] INFO: test: PixelAlive no parameter change
[11:35:19.775] INFO: running: pixelalive
[11:35:19.784] INFO: ----------------------------------------------------------------------
[11:35:19.784] 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:35:19.784] INFO: ----------------------------------------------------------------------
[11:35:20.108] INFO: Expecting 41600 events.
[11:35:24.453] INFO: 41600 events read in total (3627ms).
[11:35:24.624] INFO: Test took 4837ms.
[11:35:24.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:25.337] INFO: PixTestAlive::aliveTest() done
[11:35:25.337] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 52 0 0 0 0 0 0 0 0 0
[11:35:25.368] INFO: enter test to run
[11:35:26.999] INFO: test: timing no parameter change
[11:35:26.999] INFO: running: timing
[11:35:27.025] INFO: ######################################################################
[11:35:27.056] INFO: PixTestTiming::doTest()
[11:35:27.056] INFO: ######################################################################
[11:35:27.057] INFO: ----------------------------------------------------------------------
[11:35:27.057] INFO: PixTestTiming::TBMPhaseScan()
[11:35:27.057] INFO: ----------------------------------------------------------------------
[11:41:29.523] INFO: TBM Phase Settings: 236
[11:41:29.523] INFO: 400MHz Phase: 3
[11:41:29.523] INFO: 160MHz Phase: 7
[11:41:29.523] INFO: Functional Phase Area: 4
[11:41:29.534] INFO: Test took 362478 ms.
[11:41:29.534] INFO: PixTestTiming::TBMPhaseScan() done.
[11:41:29.534] INFO: ----------------------------------------------------------------------
[11:41:29.534] INFO: PixTestTiming::ROCDelayScan()
[11:41:29.534] INFO: ----------------------------------------------------------------------
[11:43:25.043] INFO: ROC Delay Settings: 220
[11:43:25.043] INFO: ROC Header-Trailer/Token Delay: 11
[11:43:25.043] INFO: ROC Port 0 Delay: 4
[11:43:25.043] INFO: ROC Port 1 Delay: 3
[11:43:25.043] INFO: Functional ROC Area: 4
[11:43:25.046] INFO: Test took 115512 ms.
[11:43:25.046] INFO: PixTestTiming::ROCDelayScan() done.
[11:43:25.046] INFO: ----------------------------------------------------------------------
[11:43:25.046] INFO: PixTestTiming::TimingTest()
[11:43:25.046] INFO: ----------------------------------------------------------------------
[11:43:41.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:56.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:11.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:26.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:41.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:56.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:11.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:25.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:40.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:55.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:56.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: Read back bit status: 1
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: Timings are good!
[11:45:56.301] INFO: ----------------------------------------------------------------------
[11:45:56.301] INFO: Test took 151255 ms.
[11:45:56.301] INFO: PixTestTiming::TimingTest() done.
[11:45:56.413] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:45:56.414] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:45:56.414] INFO: PixTestTiming::doTest took 629393 ms.
[11:45:56.414] INFO: PixTestTiming::doTest() done
[11:45:56.414] INFO: Write out TBMPhaseScan_0_V0
[11:45:56.414] INFO: Write out TBMPhaseScan_1_V0
[11:45:56.414] INFO: Write out CombinedTBMPhaseScan_V0
[11:45:56.475] INFO: Write out ROCDelayScan3_V0
[11:45:56.475] INFO: enter test to run
[11:55:13.583] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:55:13.583] INFO: running: highrate
[11:55:13.584] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:55:13.874] INFO: ----------------------------------------------------------------------
[11:55:13.874] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:55:13.874] INFO: ----------------------------------------------------------------------
[11:55:13.875] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:55:13.875] INFO: edge/corner pixel THR is adjusted
[11:55:13.875] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:55:14.832] INFO: Collecting data for 5 seconds...
[11:55:19.850] INFO: Done with hot pixel readout
[11:55:31.218] INFO: PixTest:: pg_setup set to default.
[11:55:31.219] INFO: 3 hot pixels found in step 0
[11:55:32.210] INFO: Collecting data for 5 seconds...
[11:55:37.227] INFO: Done with hot pixel readout
[11:55:48.537] INFO: PixTest:: pg_setup set to default.
[11:55:48.538] INFO: 2 hot pixels found in step 1
[11:55:49.528] INFO: Collecting data for 5 seconds...
[11:55:54.545] INFO: Done with hot pixel readout
[11:56:05.997] INFO: PixTest:: pg_setup set to default.
[11:56:05.998] INFO: 2 hot pixels found in step 2
[11:56:06.988] INFO: Collecting data for 5 seconds...
[11:56:12.006] INFO: Done with hot pixel readout
[11:56:23.428] INFO: PixTest:: pg_setup set to default.
[11:56:23.429] INFO: 2 hot pixels found in step 3
[11:56:24.420] INFO: Collecting data for 5 seconds...
[11:56:29.436] INFO: Done with hot pixel readout
[11:56:40.913] INFO: PixTest:: pg_setup set to default.
[11:56:40.913] INFO: 1 hot pixels found in step 4
[11:56:41.903] INFO: Collecting data for 5 seconds...
[11:56:46.921] INFO: Done with hot pixel readout
[11:56:57.923] INFO: PixTest:: pg_setup set to default.
[11:56:57.924] INFO: 0 hot pixels found in step 5
[11:56:57.969] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:56:57.972] INFO: PixTest::trimHotPixels() done
[11:56:57.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C0.dat
[11:56:57.978] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C1.dat
[11:56:57.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C2.dat
[11:56:57.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C3.dat
[11:56:57.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C4.dat
[11:56:57.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C5.dat
[11:56:57.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C6.dat
[11:56:58.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C7.dat
[11:56:58.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C8.dat
[11:56:58.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C9.dat
[11:56:58.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C10.dat
[11:56:58.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C11.dat
[11:56:58.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C12.dat
[11:56:58.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C13.dat
[11:56:58.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C14.dat
[11:56:58.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C15.dat
[11:56:58.060] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//defaultMaskFile.dat
[11:56:58.069] INFO: enter test to run
[11:58:15.678] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:58:15.678] INFO: running: highrate
[11:58:15.682] INFO: ----------------------------------------------------------------------
[11:58:15.682] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:58:15.682] INFO: ----------------------------------------------------------------------
[11:58:15.682] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:58:15.683] INFO: edge/corner pixel THR is adjusted
[11:58:15.683] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:58:16.640] INFO: Collecting data for 1 seconds...
[11:58:17.644] INFO: Done with hot pixel readout
[11:58:21.486] INFO: PixTest:: pg_setup set to default.
[11:58:21.487] INFO: 0 hot pixels found in step 0
[11:58:21.492] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:58:21.588] INFO: PixTest::trimHotPixels() done
[11:58:21.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C0.dat
[11:58:21.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C1.dat
[11:58:21.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C2.dat
[11:58:21.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C3.dat
[11:58:21.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C4.dat
[11:58:21.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C5.dat
[11:58:21.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C6.dat
[11:58:21.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C7.dat
[11:58:21.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C8.dat
[11:58:21.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C9.dat
[11:58:21.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C10.dat
[11:58:21.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C11.dat
[11:58:21.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C12.dat
[11:58:21.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C13.dat
[11:58:21.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C14.dat
[11:58:21.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//trimParameters35_C15.dat
[11:58:21.681] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-19_FPIXTest-17C-FNAL-160907-1215-150V_2016-09-07_12h15m_1473268513/000_FPIXTest_p17//defaultMaskFile.dat
[11:58:21.691] INFO: enter test to run
[11:58:48.078] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:58:48.078] INFO: running: xray
[11:58:48.079] INFO: ----------------------------------------------------------------------
[11:58:48.079] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:58:48.079] INFO: ----------------------------------------------------------------------
[11:58:49.043] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:59:00.840] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:59:29.824] INFO: Resuming triggers.
[11:59:41.629] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:00:10.930] INFO: Resuming triggers.
[12:00:22.732] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:00:52.332] INFO: Resuming triggers.
[12:01:04.135] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:01:33.740] INFO: Resuming triggers.
[12:01:45.541] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:02:14.561] INFO: Resuming triggers.
[12:02:26.359] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:02:56.164] INFO: Resuming triggers.
[12:03:07.963] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:03:37.092] INFO: Resuming triggers.
[12:03:48.890] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:04:18.864] INFO: Resuming triggers.
[12:04:24.825] INFO: data taking finished, elapsed time: 100 seconds.
[12:04:40.185] INFO: PixTest:: pg_setup set to default.
[12:04:40.188] INFO: PixTestXray::doPhRun() done
[12:04:40.555] INFO: enter test to run
[12:05:33.219] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:05:33.219] INFO: running: xray
[12:05:33.220] INFO: ----------------------------------------------------------------------
[12:05:33.220] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:05:33.220] INFO: ----------------------------------------------------------------------
[12:05:34.182] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:05:41.290] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:06:12.361] INFO: Resuming triggers.
[12:06:19.463] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:06:50.341] INFO: Resuming triggers.
[12:06:57.443] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:07:27.687] INFO: Resuming triggers.
[12:07:34.795] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:08:04.670] INFO: Resuming triggers.
[12:08:11.776] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:08:41.807] INFO: Resuming triggers.
[12:08:48.916] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:09:19.071] INFO: Resuming triggers.
[12:09:26.181] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:09:56.735] INFO: Resuming triggers.
[12:10:03.844] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:10:34.142] INFO: Resuming triggers.
[12:10:41.250] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:11:11.391] INFO: Resuming triggers.
[12:11:18.492] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:11:48.597] INFO: Resuming triggers.
[12:11:55.698] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[12:12:25.967] INFO: Resuming triggers.
[12:12:33.072] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[12:13:03.889] INFO: Resuming triggers.
[12:13:10.996] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:13:41.565] INFO: Resuming triggers.
[12:13:48.660] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:14:19.350] INFO: Resuming triggers.
[12:14:20.224] INFO: data taking finished, elapsed time: 100 seconds.
[12:14:24.401] INFO: PixTest:: pg_setup set to default.
[12:14:24.404] INFO: PixTestXray::doPhRun() done
[12:14:24.556] INFO: enter test to run
[12:14:47.623] INFO: test: HighRate no parameter change
[12:14:47.623] INFO: running: highrate
[12:14:47.648] INFO: ----------------------------------------------------------------------
[12:14:47.648] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:14:47.648] INFO: ----------------------------------------------------------------------
[12:14:47.794] INFO: Expecting 768 events.
[12:14:48.950] INFO: 768 events read in total (440ms).
[12:14:48.950] INFO: Test took 1289ms.
[12:14:49.753] INFO: Expecting 41600 events.
[12:14:52.821] INFO: 41600 events read in total (2541ms).
[12:14:52.821] INFO: Test took 3848ms.
[12:14:52.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:53.585] INFO: Expecting 41600 events.
[12:14:56.757] INFO: 41600 events read in total (2645ms).
[12:14:56.757] INFO: Test took 3890ms.
[12:14:56.788] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:57.519] INFO: Expecting 41600 events.
[12:15:00.691] INFO: 41600 events read in total (2645ms).
[12:15:00.692] INFO: Test took 3887ms.
[12:15:00.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:01.450] INFO: Expecting 41600 events.
[12:15:04.584] INFO: 41600 events read in total (2607ms).
[12:15:04.585] INFO: Test took 3845ms.
[12:15:04.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:05.347] INFO: Expecting 41600 events.
[12:15:08.516] INFO: 41600 events read in total (2642ms).
[12:15:08.517] INFO: Test took 3885ms.
[12:15:08.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:09.274] INFO: Expecting 41600 events.
[12:15:12.561] INFO: 41600 events read in total (2760ms).
[12:15:12.562] INFO: Test took 3998ms.
[12:15:12.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:13.321] INFO: Expecting 41600 events.
[12:15:16.523] INFO: 41600 events read in total (2676ms).
[12:15:16.524] INFO: Test took 3914ms.
[12:15:16.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:17.285] INFO: Expecting 41600 events.
[12:15:20.466] INFO: 41600 events read in total (2654ms).
[12:15:20.467] INFO: Test took 3896ms.
[12:15:20.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:21.228] INFO: Expecting 41600 events.
[12:15:24.392] INFO: 41600 events read in total (2637ms).
[12:15:24.393] INFO: Test took 3879ms.
[12:15:24.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:25.151] INFO: Expecting 41600 events.
[12:15:28.368] INFO: 41600 events read in total (2690ms).
[12:15:28.369] INFO: Test took 3928ms.
[12:15:28.401] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:29.130] INFO: Expecting 41600 events.
[12:15:32.301] INFO: 41600 events read in total (2644ms).
[12:15:32.302] INFO: Test took 3885ms.
[12:15:32.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:33.060] INFO: Expecting 41600 events.
[12:15:36.272] INFO: 41600 events read in total (2685ms).
[12:15:36.273] INFO: Test took 3925ms.
[12:15:36.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:37.030] INFO: Expecting 41600 events.
[12:15:40.224] INFO: 41600 events read in total (2667ms).
[12:15:40.225] INFO: Test took 3904ms.
[12:15:40.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:40.974] INFO: Expecting 41600 events.
[12:15:44.179] INFO: 41600 events read in total (2679ms).
[12:15:44.180] INFO: Test took 3907ms.
[12:15:44.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:44.937] INFO: Expecting 41600 events.
[12:15:48.116] INFO: 41600 events read in total (2652ms).
[12:15:48.117] INFO: Test took 3890ms.
[12:15:48.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:48.876] INFO: Expecting 41600 events.
[12:15:52.089] INFO: 41600 events read in total (2686ms).
[12:15:52.090] INFO: Test took 3925ms.
[12:15:52.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:52.850] INFO: Expecting 41600 events.
[12:15:56.074] INFO: 41600 events read in total (2697ms).
[12:15:56.075] INFO: Test took 3938ms.
[12:15:56.106] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:56.833] INFO: Expecting 41600 events.
[12:16:00.042] INFO: 41600 events read in total (2682ms).
[12:16:00.043] INFO: Test took 3921ms.
[12:16:00.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:00.798] INFO: Expecting 41600 events.
[12:16:03.971] INFO: 41600 events read in total (2646ms).
[12:16:03.971] INFO: Test took 3880ms.
[12:16:03.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:04.734] INFO: Expecting 41600 events.
[12:16:07.745] INFO: 41600 events read in total (2484ms).
[12:16:07.746] INFO: Test took 3727ms.
[12:16:07.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:08.147] INFO: enter test to run
[12:16:11.271] INFO: test: HighRate no parameter change
[12:16:11.271] INFO: running: highrate
[12:16:11.272] INFO: ----------------------------------------------------------------------
[12:16:11.272] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:16:11.272] INFO: ----------------------------------------------------------------------
[12:16:11.917] INFO: Expecting 208000 events.
[12:16:23.612] INFO: 208000 events read in total (11169ms).
[12:16:23.615] INFO: Test took 12305ms.
[12:16:23.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:23.988] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 51 0 0 0 0 0 0 0 0 0
[12:16:24.009] INFO: number of red-efficiency pixels: 66 49 49 99 96 143 157 76 78 87 98 82 105 52 21 22
[12:16:24.009] INFO: number of X-ray hits detected: 54419 34870 53204 86010 88258 96599 92435 68013 69485 92351 91474 77031 80728 48415 15520 18585
[12:16:24.009] 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:16:24.009] INFO: number of Vcal hits detected: 207934 207950 207950 207900 207899 207854 205294 207924 207922 207913 207899 207916 207894 207945 207979 207978
[12:16:24.009] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:16:24.009] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 98.7 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0
[12:16:24.009] INFO: X-ray hit rate [MHz/cm2]: 16.0 10.2 15.6 25.2 25.9 28.3 27.1 19.9 20.4 27.1 26.8 22.6 23.7 14.2 4.5 5.4
[12:16:24.009] INFO: PixTestHighRate::doXPixelAlive() done
[12:16:24.056] INFO: PixTest:: pg_setup set to default.
[12:16:24.066] INFO: enter test to run
[12:16:40.518] INFO: test: HighRate no parameter change
[12:16:40.519] INFO: running: highrate
[12:16:40.520] INFO: ----------------------------------------------------------------------
[12:16:40.520] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:16:40.520] INFO: ----------------------------------------------------------------------
[12:16:41.138] INFO: Expecting 208000 events.
[12:16:54.909] INFO: 208000 events read in total (13245ms).
[12:16:54.913] INFO: Test took 14385ms.
[12:16:55.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:55.473] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 51 0 0 0 0 0 0 0 0 0
[12:16:55.473] INFO: number of red-efficiency pixels: 203 104 165 369 292 396 453 222 223 288 314 293 315 159 47 46
[12:16:55.473] INFO: number of X-ray hits detected: 116618 73833 113531 184325 188407 206317 199076 146638 150274 197305 195946 164470 173352 102882 33486 39644
[12:16:55.473] 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:16:55.473] INFO: number of Vcal hits detected: 207781 207894 207818 207608 207682 207562 204963 207767 207770 207697 207669 207696 207673 207822 207952 207954
[12:16:55.473] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[12:16:55.473] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 98.5 99.9 99.9 99.9 99.8 99.9 99.8 99.9 100.0 100.0
[12:16:55.473] INFO: X-ray hit rate [MHz/cm2]: 34.2 21.6 33.3 54.0 55.2 60.5 58.4 43.0 44.0 57.8 57.4 48.2 50.8 30.2 9.8 11.6
[12:16:55.473] INFO: PixTestHighRate::doXPixelAlive() done
[12:16:55.520] INFO: PixTest:: pg_setup set to default.
[12:16:55.539] INFO: enter test to run
[12:17:12.830] INFO: test: HighRate no parameter change
[12:17:12.830] INFO: running: highrate
[12:17:12.831] INFO: ----------------------------------------------------------------------
[12:17:12.831] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:17:12.832] INFO: ----------------------------------------------------------------------
[12:17:13.464] INFO: Expecting 208000 events.
[12:17:29.044] INFO: 208000 events read in total (15053ms).
[12:17:29.051] INFO: Test took 16211ms.
[12:17:29.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:29.794] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 52 0 0 0 0 0 0 0 0 0
[12:17:29.794] INFO: number of red-efficiency pixels: 427 231 360 845 661 925 1035 470 490 756 700 748 778 325 66 94
[12:17:29.794] INFO: number of X-ray hits detected: 179859 114589 175895 282865 291052 317902 305616 224827 232114 303255 301597 254321 266890 158786 51486 61087
[12:17:29.794] 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:17:29.794] INFO: number of Vcal hits detected: 207446 207736 207582 207023 207233 206829 204201 207472 207449 207134 207218 207154 207101 207619 207933 207904
[12:17:29.794] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.5 99.5 99.8 99.8 99.6 99.7 99.6 99.6 99.8 100.0 100.0
[12:17:29.794] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.5 99.6 99.4 98.2 99.7 99.7 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[12:17:29.794] INFO: X-ray hit rate [MHz/cm2]: 52.7 33.6 51.6 82.9 85.3 93.2 89.6 65.9 68.0 88.9 88.4 74.5 78.2 46.5 15.1 17.9
[12:17:29.794] INFO: PixTestHighRate::doXPixelAlive() done
[12:17:29.839] INFO: PixTest:: pg_setup set to default.
[12:17:29.859] INFO: enter test to run
[12:17:34.126] INFO: test: exit no parameter change
[12:17:34.848] QUIET: Connection to board 33 closed.
[12:17:35.170] INFO: pXar: this is the end, my friend