[09:40:34.467] INFO: *** Welcome to pxar ***
[09:40:34.467] INFO: *** Today: 2016/10/20
[09:40:35.562] INFO: *** Version: v1.9.0-818-g96727
[09:40:35.562] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//dacParameters35_C15.dat
[09:40:35.963] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:40:35.964] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//defaultMaskFile.dat
[09:40:35.964] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C15.dat
[09:40:36.055] INFO: clk: 4
[09:40:36.055] INFO: ctr: 4
[09:40:36.055] INFO: sda: 19
[09:40:36.055] INFO: tin: 9
[09:40:36.055] INFO: level: 15
[09:40:36.055] INFO: triggerdelay: 0
[09:40:36.055] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:40:36.055] INFO: Log level: INFO
[09:40:36.073] QUIET: Connection to board DTB_WREKRL opened.
[09:40:36.077] 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:40:36.079] INFO: RPC call hashes of host and DTB match: 398089610
[09:40:37.613] INFO: DUT info:
[09:40:37.613] INFO: The DUT currently contains the following objects:
[09:40:37.613] INFO: 2 TBM Cores tbm08c (2 ON)
[09:40:37.613] INFO: TBM Core alpha (0): 7 registers set
[09:40:37.613] INFO: TBM Core beta (1): 7 registers set
[09:40:37.613] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:40:37.613] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.613] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.614] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:37.614] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:40:38.025] INFO: enter 'restricted' command line mode
[09:40:38.025] INFO: enter test to run
[09:40:44.867] INFO: test: PixelAlive no parameter change
[09:40:44.867] INFO: running: pixelalive
[09:40:44.899] INFO: ----------------------------------------------------------------------
[09:40:44.899] 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:40:44.899] INFO: ----------------------------------------------------------------------
[09:40:45.218] INFO: Expecting 41600 events.
[09:40:49.565] INFO: 41600 events read in total (3629ms).
[09:40:49.735] INFO: Test took 4833ms.
[09:40:49.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:51.214] INFO: PixTestAlive::aliveTest() done
[09:40:51.214] INFO: number of dead pixels (per ROC): 0 0 0 0 1 2 0 1 0 0 0 0 0 1 0 0
[09:40:51.292] INFO: enter test to run
[09:40:53.323] INFO: test: timing no parameter change
[09:40:53.323] INFO: running: timing
[09:40:53.343] INFO: ######################################################################
[09:40:53.367] INFO: PixTestTiming::doTest()
[09:40:53.367] INFO: ######################################################################
[09:40:53.367] INFO: ----------------------------------------------------------------------
[09:40:53.367] INFO: PixTestTiming::TBMPhaseScan()
[09:40:53.367] INFO: ----------------------------------------------------------------------
[09:45:30.902] INFO: TBM Phase Settings: 240
[09:45:30.902] INFO: 400MHz Phase: 4
[09:45:30.902] INFO: 160MHz Phase: 7
[09:45:30.902] INFO: Functional Phase Area: 5
[09:45:30.912] INFO: Test took 277545 ms.
[09:45:30.912] INFO: PixTestTiming::TBMPhaseScan() done.
[09:45:30.912] INFO: ----------------------------------------------------------------------
[09:45:30.912] INFO: PixTestTiming::ROCDelayScan()
[09:45:30.912] INFO: ----------------------------------------------------------------------
[09:47:30.940] INFO: ROC Delay Settings: 228
[09:47:30.940] INFO: ROC Header-Trailer/Token Delay: 11
[09:47:30.940] INFO: ROC Port 0 Delay: 4
[09:47:30.940] INFO: ROC Port 1 Delay: 4
[09:47:30.940] INFO: Functional ROC Area: 5
[09:47:30.943] INFO: Test took 120031 ms.
[09:47:30.943] INFO: PixTestTiming::ROCDelayScan() done.
[09:47:30.944] INFO: ----------------------------------------------------------------------
[09:47:30.944] INFO: PixTestTiming::TimingTest()
[09:47:30.944] INFO: ----------------------------------------------------------------------
[09:47:47.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:02.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:16.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:31.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:46.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:02.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:17.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:32.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:47.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:02.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:02.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: Read back bit status: 1
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: Timings are good!
[09:50:02.584] INFO: ----------------------------------------------------------------------
[09:50:02.584] INFO: Test took 151640 ms.
[09:50:02.584] INFO: PixTestTiming::TimingTest() done.
[09:50:02.591] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0a.dat
[09:50:02.591] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:50:02.591] INFO: PixTestTiming::doTest took 549251 ms.
[09:50:02.591] INFO: PixTestTiming::doTest() done
[09:50:02.591] INFO: Write out TBMPhaseScan_0_V0
[09:50:02.592] INFO: Write out TBMPhaseScan_1_V0
[09:50:02.592] INFO: Write out CombinedTBMPhaseScan_V0
[09:50:02.617] INFO: Write out ROCDelayScan3_V0
[09:50:02.617] INFO: enter test to run
[09:50:29.040] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:50:29.040] INFO: running: highrate
[09:50:29.040] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:50:29.256] INFO: ----------------------------------------------------------------------
[09:50:29.256] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:50:29.257] INFO: ----------------------------------------------------------------------
[09:50:29.257] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:50:29.257] INFO: edge/corner pixel THR is adjusted
[09:50:29.257] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:50:30.214] INFO: Collecting data for 5 seconds...
[09:50:35.233] INFO: Done with hot pixel readout
[09:50:46.686] INFO: PixTest:: pg_setup set to default.


[09:50:46.687] INFO: 2 hot pixels found in step 0
[09:50:46.725] INFO: 2 hot pixels could not be trimmed and have been masked.
[09:50:46.728] INFO: PixTest::trimHotPixels() done
[09:50:46.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C0.dat
[09:50:46.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C1.dat
[09:50:46.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C2.dat
[09:50:46.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C3.dat
[09:50:46.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C4.dat
[09:50:46.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C5.dat
[09:50:46.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C6.dat
[09:50:46.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C7.dat
[09:50:46.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C8.dat
[09:50:46.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C9.dat
[09:50:46.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C10.dat
[09:50:46.811] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C11.dat
[09:50:46.816] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C12.dat
[09:50:46.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C13.dat
[09:50:46.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C14.dat
[09:50:46.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C15.dat
[09:50:46.838] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//defaultMaskFile.dat
[09:50:46.850] INFO: enter test to run
[09:51:39.071] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:51:39.071] INFO: running: highrate
[09:51:39.075] INFO: ----------------------------------------------------------------------
[09:51:39.075] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:51:39.075] INFO: ----------------------------------------------------------------------
[09:51:39.075] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:51:39.075] INFO: edge/corner pixel THR is adjusted
[09:51:39.075] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:51:40.032] INFO: Collecting data for 1 seconds...
[09:51:41.037] INFO: Done with hot pixel readout
[09:51:44.961] INFO: PixTest:: pg_setup set to default.
[09:51:44.962] INFO: 0 hot pixels found in step 0
[09:51:44.968] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:51:45.052] INFO: PixTest::trimHotPixels() done
[09:51:45.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C0.dat
[09:51:45.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C1.dat
[09:51:45.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C2.dat
[09:51:45.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C3.dat
[09:51:45.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C4.dat
[09:51:45.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C5.dat
[09:51:45.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C6.dat
[09:51:45.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C7.dat
[09:51:45.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C8.dat
[09:51:45.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C9.dat
[09:51:45.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C10.dat
[09:51:45.117] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C11.dat
[09:51:45.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C12.dat
[09:51:45.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C13.dat
[09:51:45.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C14.dat
[09:51:45.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C15.dat
[09:51:45.144] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-43_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//defaultMaskFile.dat
[09:51:45.155] INFO: enter test to run
[09:52:00.703] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:52:00.703] INFO: running: xray
[09:52:00.704] INFO: ----------------------------------------------------------------------
[09:52:00.704] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:52:00.704] INFO: ----------------------------------------------------------------------
[09:52:01.668] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:52:13.208] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:52:43.535] INFO: Resuming triggers.
[09:52:55.079] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[09:53:24.970] INFO: Resuming triggers.
[09:53:36.506] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:54:06.608] INFO: Resuming triggers.
[09:54:18.147] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[09:54:47.669] INFO: Resuming triggers.
[09:54:59.207] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[09:55:28.530] INFO: Resuming triggers.
[09:55:40.069] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:56:09.355] INFO: Resuming triggers.
[09:56:20.890] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:56:50.207] INFO: Resuming triggers.
[09:57:01.741] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[09:57:31.103] INFO: Resuming triggers.
[09:57:39.161] INFO: data taking finished, elapsed time: 100 seconds.
[09:57:59.935] INFO: PixTest:: pg_setup set to default.
[09:57:59.939] INFO: PixTestXray::doPhRun() done
[09:58:00.157] INFO: enter test to run
[09:58:25.852] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:58:25.852] INFO: running: xray
[09:58:25.853] INFO: ----------------------------------------------------------------------
[09:58:25.853] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:58:25.853] INFO: ----------------------------------------------------------------------
[09:58:26.818] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:58:33.502] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:59:03.765] INFO: Resuming triggers.
[09:59:10.454] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[09:59:40.599] INFO: Resuming triggers.
[09:59:47.293] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:00:17.417] INFO: Resuming triggers.
[10:00:24.107] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:00:54.355] INFO: Resuming triggers.
[10:01:01.044] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:01:31.191] INFO: Resuming triggers.
[10:01:37.885] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:02:08.438] INFO: Resuming triggers.
[10:02:15.130] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:02:46.057] INFO: Resuming triggers.
[10:02:52.746] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[10:03:23.670] INFO: Resuming triggers.
[10:03:30.362] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:04:01.026] INFO: Resuming triggers.
[10:04:07.717] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:04:38.848] INFO: Resuming triggers.
[10:04:45.540] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:05:16.096] INFO: Resuming triggers.
[10:05:22.786] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:05:53.877] INFO: Resuming triggers.
[10:06:00.567] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:06:31.617] INFO: Resuming triggers.
[10:06:38.306] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:07:10.218] INFO: Resuming triggers.
[10:07:16.906] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:07:48.304] INFO: Resuming triggers.
[10:07:48.307] INFO: data taking finished, elapsed time: 100 seconds.
[10:07:48.890] INFO: PixTest:: pg_setup set to default.
[10:07:48.893] INFO: PixTestXray::doPhRun() done
[10:07:49.051] INFO: enter test to run
[10:08:16.256] INFO: test: HighRate no parameter change
[10:08:16.256] INFO: running: highrate
[10:08:16.277] INFO: ----------------------------------------------------------------------
[10:08:16.277] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:08:16.277] INFO: ----------------------------------------------------------------------
[10:08:16.460] INFO: Expecting 768 events.
[10:08:17.617] INFO: 768 events read in total (442ms).
[10:08:17.618] INFO: Test took 1312ms.
[10:08:18.421] INFO: Expecting 41600 events.
[10:08:21.572] INFO: 41600 events read in total (2624ms).
[10:08:21.573] INFO: Test took 3949ms.
[10:08:21.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:22.334] INFO: Expecting 41600 events.
[10:08:25.549] INFO: 41600 events read in total (2688ms).
[10:08:25.550] INFO: Test took 3924ms.
[10:08:25.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:26.306] INFO: Expecting 41600 events.
[10:08:29.560] INFO: 41600 events read in total (2728ms).
[10:08:29.561] INFO: Test took 3957ms.
[10:08:29.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:30.319] INFO: Expecting 41600 events.
[10:08:33.639] INFO: 41600 events read in total (2793ms).
[10:08:33.640] INFO: Test took 4024ms.
[10:08:33.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:34.398] INFO: Expecting 41600 events.
[10:08:37.650] INFO: 41600 events read in total (2725ms).
[10:08:37.651] INFO: Test took 3957ms.
[10:08:37.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:38.407] INFO: Expecting 41600 events.
[10:08:41.664] INFO: 41600 events read in total (2731ms).
[10:08:41.664] INFO: Test took 3958ms.
[10:08:41.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:42.416] INFO: Expecting 41600 events.
[10:08:45.702] INFO: 41600 events read in total (2759ms).
[10:08:45.703] INFO: Test took 3984ms.
[10:08:45.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:46.446] INFO: Expecting 41600 events.
[10:08:49.702] INFO: 41600 events read in total (2729ms).
[10:08:49.703] INFO: Test took 3942ms.
[10:08:49.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:50.453] INFO: Expecting 41600 events.
[10:08:53.763] INFO: 41600 events read in total (2784ms).
[10:08:53.764] INFO: Test took 4007ms.
[10:08:53.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:54.521] INFO: Expecting 41600 events.
[10:08:57.817] INFO: 41600 events read in total (2769ms).
[10:08:57.818] INFO: Test took 4000ms.
[10:08:57.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:58.571] INFO: Expecting 41600 events.
[10:09:01.875] INFO: 41600 events read in total (2777ms).
[10:09:01.876] INFO: Test took 4003ms.
[10:09:01.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:02.632] INFO: Expecting 41600 events.
[10:09:05.894] INFO: 41600 events read in total (2735ms).
[10:09:05.895] INFO: Test took 3965ms.
[10:09:05.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:06.650] INFO: Expecting 41600 events.
[10:09:09.958] INFO: 41600 events read in total (2781ms).
[10:09:09.959] INFO: Test took 4010ms.
[10:09:09.996] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:10.710] INFO: Expecting 41600 events.
[10:09:14.009] INFO: 41600 events read in total (2772ms).
[10:09:14.010] INFO: Test took 3996ms.
[10:09:14.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:14.760] INFO: Expecting 41600 events.
[10:09:18.063] INFO: 41600 events read in total (2777ms).
[10:09:18.064] INFO: Test took 4000ms.
[10:09:18.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:18.821] INFO: Expecting 41600 events.
[10:09:22.195] INFO: 41600 events read in total (2847ms).
[10:09:22.196] INFO: Test took 4077ms.
[10:09:22.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:22.941] INFO: Expecting 41600 events.
[10:09:26.284] INFO: 41600 events read in total (2816ms).
[10:09:26.285] INFO: Test took 4020ms.
[10:09:26.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:27.034] INFO: Expecting 41600 events.
[10:09:30.350] INFO: 41600 events read in total (2790ms).
[10:09:30.351] INFO: Test took 4003ms.
[10:09:30.387] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:31.107] INFO: Expecting 41600 events.
[10:09:34.363] INFO: 41600 events read in total (2729ms).
[10:09:34.364] INFO: Test took 3958ms.
[10:09:34.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:35.120] INFO: Expecting 41600 events.
[10:09:38.241] INFO: 41600 events read in total (2594ms).
[10:09:38.242] INFO: Test took 3824ms.
[10:09:38.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:38.640] INFO: enter test to run
[10:09:54.928] INFO: test: HighRate no parameter change
[10:09:54.928] INFO: running: highrate
[10:09:54.929] INFO: ----------------------------------------------------------------------
[10:09:54.929] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:09:54.929] INFO: ----------------------------------------------------------------------
[10:09:55.543] INFO: Expecting 208000 events.
[10:10:07.450] INFO: 208000 events read in total (11380ms).
[10:10:07.453] INFO: Test took 12516ms.
[10:10:07.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:07.857] INFO: number of dead pixels (per ROC): 0 0 0 0 1 2 0 1 0 0 0 0 0 1 0 0
[10:10:07.857] INFO: number of red-efficiency pixels: 93 48 97 125 158 162 164 112 101 116 125 109 141 65 30 31
[10:10:07.857] INFO: number of X-ray hits detected: 71398 46096 70741 112352 117822 120804 116996 84874 83270 101245 99839 85435 92028 51686 21738 25830
[10:10:07.857] 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:10:07.857] INFO: number of Vcal hits detected: 207906 207951 207902 207867 207788 207734 207831 207834 207898 207883 207872 207888 207851 207885 207970 207969
[10:10:07.857] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:10:07.857] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[10:10:07.857] INFO: X-ray hit rate [MHz/cm2]: 20.9 13.5 20.7 32.9 34.5 35.4 34.3 24.9 24.4 29.7 29.3 25.0 27.0 15.1 6.4 7.6
[10:10:07.857] INFO: PixTestHighRate::doXPixelAlive() done
[10:10:07.907] INFO: PixTest:: pg_setup set to default.
[10:10:07.923] INFO: enter test to run
[10:10:53.535] INFO: test: HighRate no parameter change
[10:10:53.535] INFO: running: highrate
[10:10:53.536] INFO: ----------------------------------------------------------------------
[10:10:53.536] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:10:53.536] INFO: ----------------------------------------------------------------------
[10:10:54.154] INFO: Expecting 208000 events.
[10:11:07.795] INFO: 208000 events read in total (13114ms).
[10:11:07.800] INFO: Test took 14255ms.
[10:11:08.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:08.394] INFO: number of dead pixels (per ROC): 0 0 0 0 1 2 0 1 0 0 0 0 0 1 0 0
[10:11:08.394] INFO: number of red-efficiency pixels: 291 138 296 409 572 600 492 362 263 306 403 306 359 190 74 65
[10:11:08.394] INFO: number of X-ray hits detected: 140741 90933 139683 221635 233835 238058 231560 167976 164339 201029 196981 169380 182275 103144 43159 51409
[10:11:08.394] 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:11:08.394] INFO: number of Vcal hits detected: 207680 207857 207681 207543 207330 207198 207465 207560 207721 207677 207570 207672 207623 207752 207925 207932
[10:11:08.394] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.9 99.8 99.9 99.8 99.9 100.0 100.0
[10:11:08.394] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[10:11:08.394] INFO: X-ray hit rate [MHz/cm2]: 41.3 26.7 40.9 65.0 68.5 69.8 67.9 49.2 48.2 58.9 57.7 49.6 53.4 30.2 12.7 15.1
[10:11:08.394] INFO: PixTestHighRate::doXPixelAlive() done
[10:11:08.442] INFO: PixTest:: pg_setup set to default.
[10:11:08.455] INFO: enter test to run
[10:11:25.791] INFO: test: HighRate no parameter change
[10:11:25.791] INFO: running: highrate
[10:11:25.792] INFO: ----------------------------------------------------------------------
[10:11:25.792] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:11:25.792] INFO: ----------------------------------------------------------------------
[10:11:26.408] INFO: Expecting 208000 events.
[10:11:41.941] INFO: 208000 events read in total (15006ms).
[10:11:41.948] INFO: Test took 16146ms.
[10:11:42.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:42.739] INFO: number of dead pixels (per ROC): 0 0 0 0 1 2 0 1 0 0 0 0 0 1 0 0
[10:11:42.739] INFO: number of red-efficiency pixels: 621 242 713 938 1372 1470 1060 764 534 754 996 603 835 464 104 96
[10:11:42.739] INFO: number of X-ray hits detected: 214115 139145 213447 338193 356467 363870 352877 255237 250701 306861 299676 258342 277053 157349 65808 78691
[10:11:42.739] 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:11:42.739] INFO: number of Vcal hits detected: 207161 207734 207036 206821 206166 205902 206643 206981 207398 207135 206768 207283 207028 207398 207889 207900
[10:11:42.739] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.5 99.2 99.1 99.4 99.6 99.7 99.6 99.5 99.7 99.6 99.8 99.9 100.0
[10:11:42.739] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.5 99.4 99.1 99.0 99.3 99.5 99.7 99.6 99.4 99.7 99.5 99.7 99.9 100.0
[10:11:42.739] INFO: X-ray hit rate [MHz/cm2]: 62.8 40.8 62.6 99.1 104.5 106.7 103.4 74.8 73.5 89.9 87.8 75.7 81.2 46.1 19.3 23.1
[10:11:42.739] INFO: PixTestHighRate::doXPixelAlive() done
[10:11:42.790] INFO: PixTest:: pg_setup set to default.
[10:11:42.802] INFO: enter test to run
[10:11:57.270] INFO: test: exit no parameter change
[10:11:57.753] QUIET: Connection to board 33 closed.
[10:11:57.775] INFO: pXar: this is the end, my friend