[09:30:18.611] INFO: *** Welcome to pxar ***
[09:30:18.612] INFO: *** Today: 2016/10/14
[09:30:19.579] INFO: *** Version: v1.9.0-818-g96727
[09:30:19.579] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//dacParameters35_C15.dat
[09:30:19.608] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:30:19.608] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//defaultMaskFile.dat
[09:30:19.623] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C15.dat
[09:30:19.736] INFO: clk: 4
[09:30:19.736] INFO: ctr: 4
[09:30:19.736] INFO: sda: 19
[09:30:19.736] INFO: tin: 9
[09:30:19.736] INFO: level: 15
[09:30:19.736] INFO: triggerdelay: 0
[09:30:19.736] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:30:19.736] INFO: Log level: INFO
[09:30:19.754] QUIET: Connection to board DTB_WREKRL opened.
[09:30:19.758] 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:
------------------------------------------------------
[09:30:19.760] INFO: RPC call hashes of host and DTB match: 398089610
[09:30:21.290] INFO: DUT info:
[09:30:21.290] INFO: The DUT currently contains the following objects:
[09:30:21.290] INFO: 2 TBM Cores tbm08c (2 ON)
[09:30:21.290] INFO: TBM Core alpha (0): 7 registers set
[09:30:21.290] INFO: TBM Core beta (1): 7 registers set
[09:30:21.290] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:30:21.290] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.290] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.290] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.291] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:30:21.723] INFO: enter 'restricted' command line mode
[09:30:21.723] INFO: enter test to run
[09:30:28.897] INFO: test: PixelAlive no parameter change
[09:30:28.897] INFO: running: pixelalive
[09:30:28.993] INFO: ----------------------------------------------------------------------
[09:30:28.993] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:30:28.993] INFO: ----------------------------------------------------------------------
[09:30:29.312] INFO: Expecting 41600 events.
[09:30:33.660] INFO: 41600 events read in total (3629ms).
[09:30:33.824] INFO: Test took 4827ms.
[09:30:33.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:34.350] INFO: PixTestAlive::aliveTest() done
[09:30:34.350] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 1 0 0 0 0 0 0
[09:30:34.504] INFO: enter test to run
[09:30:39.265] INFO: test: timing no parameter change
[09:30:39.265] INFO: running: timing
[09:30:39.268] INFO: ######################################################################
[09:30:39.268] INFO: PixTestTiming::doTest()
[09:30:39.268] INFO: ######################################################################
[09:30:39.268] INFO: ----------------------------------------------------------------------
[09:30:39.268] INFO: PixTestTiming::TBMPhaseScan()
[09:30:39.268] INFO: ----------------------------------------------------------------------
[09:35:12.748] INFO: TBM Phase Settings: 224
[09:35:12.748] INFO: 400MHz Phase: 0
[09:35:12.749] INFO: 160MHz Phase: 7
[09:35:12.749] INFO: Functional Phase Area: 3
[09:35:12.766] INFO: Test took 273498 ms.
[09:35:12.766] INFO: PixTestTiming::TBMPhaseScan() done.
[09:35:12.766] INFO: ----------------------------------------------------------------------
[09:35:12.766] INFO: PixTestTiming::ROCDelayScan()
[09:35:12.766] INFO: ----------------------------------------------------------------------
[09:37:50.418] INFO: ROC Delay Settings: 228
[09:37:50.419] INFO: ROC Header-Trailer/Token Delay: 11
[09:37:50.419] INFO: ROC Port 0 Delay: 4
[09:37:50.419] INFO: ROC Port 1 Delay: 4
[09:37:50.419] INFO: Functional ROC Area: 3
[09:37:50.422] INFO: Test took 157656 ms.
[09:37:50.422] INFO: PixTestTiming::ROCDelayScan() done.
[09:37:50.423] INFO: ----------------------------------------------------------------------
[09:37:50.423] INFO: PixTestTiming::TimingTest()
[09:37:50.423] INFO: ----------------------------------------------------------------------
[09:38:06.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:21.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:36.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:51.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:06.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:21.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:36.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:51.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:06.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:21.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:21.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:21.914] INFO: ----------------------------------------------------------------------
[09:40:21.914] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[09:40:21.914] INFO: ----------------------------------------------------------------------
[09:40:21.914] INFO: ----------------------------------------------------------------------
[09:40:21.915] INFO: Read back bit status: 1
[09:40:21.915] INFO: ----------------------------------------------------------------------
[09:40:21.915] INFO: ----------------------------------------------------------------------
[09:40:21.915] INFO: Timings are good!
[09:40:21.915] INFO: ----------------------------------------------------------------------
[09:40:21.915] INFO: Test took 151493 ms.
[09:40:21.915] INFO: PixTestTiming::TimingTest() done.
[09:40:21.915] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//tbmParameters_C0a.dat
[09:40:21.915] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:40:21.915] INFO: PixTestTiming::doTest took 582650 ms.
[09:40:21.915] INFO: PixTestTiming::doTest() done
[09:40:21.915] INFO: Write out TBMPhaseScan_0_V0
[09:40:21.916] INFO: Write out TBMPhaseScan_1_V0
[09:40:21.916] INFO: Write out CombinedTBMPhaseScan_V0
[09:40:21.917] INFO: Write out ROCDelayScan3_V0
[09:40:21.918] INFO: enter test to run
[09:42:04.452] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:42:04.452] INFO: running: highrate
[09:42:04.463] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:42:04.708] INFO: ----------------------------------------------------------------------
[09:42:04.708] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:42:04.708] INFO: ----------------------------------------------------------------------
[09:42:04.709] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:42:04.709] INFO: edge/corner pixel THR is adjusted
[09:42:04.709] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:42:05.668] INFO: Collecting data for 5 seconds...
[09:42:10.685] INFO: Done with hot pixel readout
[09:42:22.247] INFO: PixTest:: pg_setup set to default.
[09:42:22.248] INFO: 2 hot pixels found in step 0
[09:42:23.239] INFO: Collecting data for 5 seconds...
[09:42:28.256] INFO: Done with hot pixel readout
[09:42:39.733] INFO: PixTest:: pg_setup set to default.

[09:42:39.734] INFO: 3 hot pixels found in step 1
[09:42:40.726] INFO: Collecting data for 5 seconds...
[09:42:45.743] INFO: Done with hot pixel readout
[09:42:57.307] INFO: PixTest:: pg_setup set to default.
[09:42:57.308] INFO: 2 hot pixels found in step 2
[09:42:58.300] INFO: Collecting data for 5 seconds...
[09:43:03.316] INFO: Done with hot pixel readout
[09:43:14.852] INFO: PixTest:: pg_setup set to default.
[09:43:14.853] INFO: 1 hot pixels found in step 3
[09:43:15.843] INFO: Collecting data for 5 seconds...
[09:43:20.859] INFO: Done with hot pixel readout
[09:43:32.326] INFO: PixTest:: pg_setup set to default.
[09:43:32.327] INFO: 0 hot pixels found in step 4
[09:43:32.362] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:43:32.365] INFO: PixTest::trimHotPixels() done
[09:43:32.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C0.dat
[09:43:32.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C1.dat
[09:43:32.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C2.dat
[09:43:32.383] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C3.dat
[09:43:32.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C4.dat
[09:43:32.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C5.dat
[09:43:32.399] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C6.dat
[09:43:32.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C7.dat
[09:43:32.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C8.dat
[09:43:32.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C9.dat
[09:43:32.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C10.dat
[09:43:32.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C11.dat
[09:43:32.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C12.dat
[09:43:32.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C13.dat
[09:43:32.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C14.dat
[09:43:32.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C15.dat
[09:43:32.478] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//defaultMaskFile.dat
[09:43:32.496] INFO: enter test to run
[09:44:05.524] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:44:05.524] INFO: running: highrate
[09:44:05.528] INFO: ----------------------------------------------------------------------
[09:44:05.528] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:44:05.528] INFO: ----------------------------------------------------------------------
[09:44:05.528] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:44:05.528] INFO: edge/corner pixel THR is adjusted
[09:44:05.528] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:44:06.486] INFO: Collecting data for 1 seconds...
[09:44:07.489] INFO: Done with hot pixel readout
[09:44:11.423] INFO: PixTest:: pg_setup set to default.
[09:44:11.424] INFO: 0 hot pixels found in step 0
[09:44:11.429] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:44:11.524] INFO: PixTest::trimHotPixels() done
[09:44:11.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C0.dat
[09:44:11.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C1.dat
[09:44:11.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C2.dat
[09:44:11.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C3.dat
[09:44:11.551] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C4.dat
[09:44:11.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C5.dat
[09:44:11.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C6.dat
[09:44:11.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C7.dat
[09:44:11.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C8.dat
[09:44:11.577] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C9.dat
[09:44:11.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C10.dat
[09:44:11.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C11.dat
[09:44:11.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C12.dat
[09:44:11.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C13.dat
[09:44:11.603] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C14.dat
[09:44:11.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//trimParameters35_C15.dat
[09:44:11.613] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-04_FPIXTest-17C-FNAL-160928-1217-300V_2016-09-28_12h21m_1475083302/000_FPIXTest_p17//defaultMaskFile.dat
[09:44:11.624] INFO: enter test to run
[09:44:51.571] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:44:51.571] INFO: running: xray
[09:44:51.572] INFO: ----------------------------------------------------------------------
[09:44:51.572] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:44:51.572] INFO: ----------------------------------------------------------------------
[09:44:52.545] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:45:04.253] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:45:33.570] INFO: Resuming triggers.
[09:45:45.277] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:46:15.262] INFO: Resuming triggers.
[09:46:26.972] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:46:56.539] INFO: Resuming triggers.
[09:47:08.254] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:47:37.978] INFO: Resuming triggers.
[09:47:49.690] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:48:19.284] INFO: Resuming triggers.
[09:48:30.997] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[09:48:59.934] INFO: Resuming triggers.
[09:49:11.645] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:49:42.082] INFO: Resuming triggers.
[09:49:53.794] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:50:24.294] INFO: Resuming triggers.
[09:50:30.970] INFO: data taking finished, elapsed time: 100 seconds.
[09:50:48.635] INFO: PixTest:: pg_setup set to default.
[09:50:48.638] INFO: PixTestXray::doPhRun() done
[09:50:48.811] INFO: enter test to run
[09:51:37.281] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:51:37.281] INFO: running: xray
[09:51:37.282] INFO: ----------------------------------------------------------------------
[09:51:37.282] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:51:37.282] INFO: ----------------------------------------------------------------------
[09:51:38.256] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:51:45.172] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:52:15.570] INFO: Resuming triggers.
[09:52:22.481] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[09:52:52.668] INFO: Resuming triggers.
[09:52:59.584] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[09:53:30.027] INFO: Resuming triggers.
[09:53:36.936] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[09:54:06.958] INFO: Resuming triggers.
[09:54:13.871] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:54:44.198] INFO: Resuming triggers.
[09:54:51.111] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[09:55:21.327] INFO: Resuming triggers.
[09:55:28.235] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[09:55:58.350] INFO: Resuming triggers.
[09:56:05.259] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[09:56:35.440] INFO: Resuming triggers.
[09:56:42.352] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:57:12.626] INFO: Resuming triggers.
[09:57:19.538] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:57:49.860] INFO: Resuming triggers.
[09:57:56.768] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[09:58:27.020] INFO: Resuming triggers.
[09:58:33.934] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[09:59:04.557] INFO: Resuming triggers.
[09:59:11.466] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[09:59:42.579] INFO: Resuming triggers.
[09:59:49.489] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:00:20.432] INFO: Resuming triggers.
[10:00:23.005] INFO: data taking finished, elapsed time: 100 seconds.
[10:00:40.307] INFO: PixTest:: pg_setup set to default.
[10:00:40.310] INFO: PixTestXray::doPhRun() done
[10:00:40.461] INFO: enter test to run
[10:01:21.948] INFO: test: HighRate no parameter change
[10:01:21.948] INFO: running: highrate
[10:01:21.962] INFO: ----------------------------------------------------------------------
[10:01:21.962] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:01:21.962] INFO: ----------------------------------------------------------------------
[10:01:22.153] INFO: Expecting 768 events.
[10:01:23.283] INFO: 768 events read in total (414ms).
[10:01:23.283] INFO: Test took 1276ms.
[10:01:24.086] INFO: Expecting 41600 events.
[10:01:27.224] INFO: 41600 events read in total (2611ms).
[10:01:27.225] INFO: Test took 3921ms.
[10:01:27.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:27.987] INFO: Expecting 41600 events.
[10:01:31.113] INFO: 41600 events read in total (2600ms).
[10:01:31.113] INFO: Test took 3840ms.
[10:01:31.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:31.870] INFO: Expecting 41600 events.
[10:01:35.077] INFO: 41600 events read in total (2680ms).
[10:01:35.078] INFO: Test took 3916ms.
[10:01:35.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:35.833] INFO: Expecting 41600 events.
[10:01:39.031] INFO: 41600 events read in total (2671ms).
[10:01:39.032] INFO: Test took 3906ms.
[10:01:39.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:39.788] INFO: Expecting 41600 events.
[10:01:42.951] INFO: 41600 events read in total (2636ms).
[10:01:42.952] INFO: Test took 3870ms.
[10:01:42.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:43.714] INFO: Expecting 41600 events.
[10:01:47.032] INFO: 41600 events read in total (2791ms).
[10:01:47.033] INFO: Test took 4031ms.
[10:01:47.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:47.784] INFO: Expecting 41600 events.
[10:01:50.982] INFO: 41600 events read in total (2671ms).
[10:01:50.983] INFO: Test took 3901ms.
[10:01:51.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:51.730] INFO: Expecting 41600 events.
[10:01:54.932] INFO: 41600 events read in total (2675ms).
[10:01:54.933] INFO: Test took 3902ms.
[10:01:54.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:55.691] INFO: Expecting 41600 events.
[10:01:58.928] INFO: 41600 events read in total (2710ms).
[10:01:58.929] INFO: Test took 3948ms.
[10:01:58.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:59.679] INFO: Expecting 41600 events.
[10:02:02.756] INFO: 41600 events read in total (2550ms).
[10:02:02.757] INFO: Test took 3779ms.
[10:02:02.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:03.515] INFO: Expecting 41600 events.
[10:02:06.724] INFO: 41600 events read in total (2682ms).
[10:02:06.725] INFO: Test took 3919ms.
[10:02:06.758] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:07.483] INFO: Expecting 41600 events.
[10:02:10.718] INFO: 41600 events read in total (2708ms).
[10:02:10.719] INFO: Test took 3944ms.
[10:02:10.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:11.476] INFO: Expecting 41600 events.
[10:02:14.678] INFO: 41600 events read in total (2676ms).
[10:02:14.679] INFO: Test took 3910ms.
[10:02:14.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:15.426] INFO: Expecting 41600 events.
[10:02:18.704] INFO: 41600 events read in total (2751ms).
[10:02:18.705] INFO: Test took 3974ms.
[10:02:18.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:19.463] INFO: Expecting 41600 events.
[10:02:22.740] INFO: 41600 events read in total (2750ms).
[10:02:22.741] INFO: Test took 3986ms.
[10:02:22.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:23.501] INFO: Expecting 41600 events.
[10:02:26.811] INFO: 41600 events read in total (2783ms).
[10:02:26.812] INFO: Test took 4022ms.
[10:02:26.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:27.571] INFO: Expecting 41600 events.
[10:02:30.808] INFO: 41600 events read in total (2711ms).
[10:02:30.809] INFO: Test took 3948ms.
[10:02:30.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:31.567] INFO: Expecting 41600 events.
[10:02:34.815] INFO: 41600 events read in total (2721ms).
[10:02:34.816] INFO: Test took 3954ms.
[10:02:34.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:35.569] INFO: Expecting 41600 events.
[10:02:38.833] INFO: 41600 events read in total (2737ms).
[10:02:38.834] INFO: Test took 3966ms.
[10:02:38.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:39.589] INFO: Expecting 41600 events.
[10:02:42.619] INFO: 41600 events read in total (2503ms).
[10:02:42.619] INFO: Test took 3738ms.
[10:02:42.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:43.020] INFO: enter test to run
[10:03:28.404] INFO: test: HighRate no parameter change
[10:03:28.404] INFO: running: highrate
[10:03:28.405] INFO: ----------------------------------------------------------------------
[10:03:28.405] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:03:28.405] INFO: ----------------------------------------------------------------------
[10:03:29.028] INFO: Expecting 208000 events.
[10:03:40.969] INFO: 208000 events read in total (11415ms).
[10:03:40.972] INFO: Test took 12558ms.
[10:03:41.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:41.354] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[10:03:41.354] INFO: number of red-efficiency pixels: 77 48 72 91 98 121 103 101 63 130 101 97 75 55 24 30
[10:03:41.354] INFO: number of X-ray hits detected: 57756 38005 61579 92539 90983 100184 100569 74925 72664 94117 87269 73304 77778 46185 17995 22075
[10:03:41.354] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:03:41.354] INFO: number of Vcal hits detected: 207919 207951 207926 207908 207900 207878 207846 207899 207937 207869 207898 207900 207924 207943 207976 207970
[10:03:41.354] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:03:41.354] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:03:41.354] INFO: X-ray hit rate [MHz/cm2]: 16.9 11.1 18.0 27.1 26.7 29.4 29.5 22.0 21.3 27.6 25.6 21.5 22.8 13.5 5.3 6.5
[10:03:41.354] INFO: PixTestHighRate::doXPixelAlive() done
[10:03:41.401] INFO: PixTest:: pg_setup set to default.
[10:03:41.416] INFO: enter test to run
[10:04:17.755] INFO: test: HighRate no parameter change
[10:04:17.755] INFO: running: highrate
[10:04:17.757] INFO: ----------------------------------------------------------------------
[10:04:17.757] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:04:17.757] INFO: ----------------------------------------------------------------------
[10:04:18.374] INFO: Expecting 208000 events.
[10:04:31.930] INFO: 208000 events read in total (13029ms).
[10:04:31.935] INFO: Test took 14170ms.
[10:04:32.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:32.515] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[10:04:32.515] INFO: number of red-efficiency pixels: 202 119 272 332 355 466 423 285 291 348 365 327 278 173 54 51
[10:04:32.515] INFO: number of X-ray hits detected: 129030 85692 136865 205778 201681 221318 224831 167906 163372 210991 194065 163336 174135 103302 40014 49538
[10:04:32.515] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:04:32.515] INFO: number of Vcal hits detected: 207784 207877 207698 207640 207626 207496 207488 207699 207680 207635 207603 207654 207714 207819 207946 207948
[10:04:32.516] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[10:04:32.516] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[10:04:32.516] INFO: X-ray hit rate [MHz/cm2]: 37.8 25.1 40.1 60.3 59.1 64.9 65.9 49.2 47.9 61.8 56.9 47.9 51.0 30.3 11.7 14.5
[10:04:32.516] INFO: PixTestHighRate::doXPixelAlive() done
[10:04:32.566] INFO: PixTest:: pg_setup set to default.
[10:04:32.577] INFO: enter test to run
[10:04:46.395] INFO: test: HighRate no parameter change
[10:04:46.395] INFO: running: highrate
[10:04:46.396] INFO: ----------------------------------------------------------------------
[10:04:46.396] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:04:46.396] INFO: ----------------------------------------------------------------------
[10:04:47.012] INFO: Expecting 208000 events.
[10:05:02.212] INFO: 208000 events read in total (14673ms).
[10:05:02.219] INFO: Test took 15814ms.
[10:05:02.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:02.989] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[10:05:02.989] INFO: number of red-efficiency pixels: 439 265 613 711 700 1012 879 614 640 806 838 619 537 297 80 90
[10:05:02.989] INFO: number of X-ray hits detected: 190980 126914 203224 306306 300062 330325 332159 248241 242606 311478 287748 243295 259723 153942 59305 73778
[10:05:02.990] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:05:02.990] INFO: number of Vcal hits detected: 207489 207711 207158 207161 207201 206716 206867 207247 207234 207074 207029 207287 207406 207673 207917 207908
[10:05:02.990] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.6 99.7 99.4 99.5 99.7 99.7 99.6 99.6 99.7 99.7 99.9 100.0 100.0
[10:05:02.990] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.6 99.6 99.4 99.5 99.6 99.6 99.6 99.5 99.7 99.7 99.8 100.0 100.0
[10:05:02.990] INFO: X-ray hit rate [MHz/cm2]: 56.0 37.2 59.6 89.8 88.0 96.8 97.4 72.8 71.1 91.3 84.3 71.3 76.1 45.1 17.4 21.6
[10:05:02.990] INFO: PixTestHighRate::doXPixelAlive() done
[10:05:03.039] INFO: PixTest:: pg_setup set to default.
[10:05:03.055] INFO: enter test to run
[10:05:09.099] INFO: test: exit no parameter change
[10:05:09.621] QUIET: Connection to board 33 closed.
[10:05:09.666] INFO: pXar: this is the end, my friend