[12:16:51.482] INFO: *** Welcome to pxar ***
[12:16:51.482] INFO: *** Today: 2016/09/19
[12:16:53.585] INFO: *** Version: v1.9.0-818-g96727
[12:16:53.585] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//dacParameters35_C15.dat
[12:16:53.003] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:16:53.003] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[12:16:53.003] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[12:16:54.139] INFO: clk: 4
[12:16:54.139] INFO: ctr: 4
[12:16:54.139] INFO: sda: 19
[12:16:54.139] INFO: tin: 9
[12:16:54.139] INFO: level: 15
[12:16:54.139] INFO: triggerdelay: 0
[12:16:54.139] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:16:54.139] INFO: Log level: INFO
[12:16:54.175] QUIET: Connection to board DTB_WREKRL opened.
[12:16:54.179] 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:
------------------------------------------------------
[12:16:54.181] INFO: RPC call hashes of host and DTB match: 398089610
[12:16:55.744] INFO: DUT info:
[12:16:55.744] INFO: The DUT currently contains the following objects:
[12:16:55.744] INFO: 2 TBM Cores tbm08c (2 ON)
[12:16:55.744] INFO: TBM Core alpha (0): 7 registers set
[12:16:55.744] INFO: TBM Core beta (1): 7 registers set
[12:16:55.744] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:16:55.744] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.744] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.744] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:55.745] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:16:56.224] INFO: enter 'restricted' command line mode
[12:16:56.224] INFO: enter test to run
[12:17:03.792] INFO: test: PixelAlive no parameter change
[12:17:03.793] INFO: running: pixelalive
[12:17:03.813] INFO: ----------------------------------------------------------------------
[12:17:03.813] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:17:03.813] INFO: ----------------------------------------------------------------------
[12:17:04.136] INFO: Expecting 41600 events.
[12:17:08.436] INFO: 41600 events read in total (3581ms).
[12:17:08.601] INFO: Test took 4779ms.
[12:17:08.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:09.112] INFO: PixTestAlive::aliveTest() done
[12:17:09.112] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[12:17:09.165] INFO: enter test to run
[12:17:13.816] INFO: test: timing no parameter change
[12:17:13.817] INFO: running: timing
[12:17:13.831] INFO: ######################################################################
[12:17:13.831] INFO: PixTestTiming::doTest()
[12:17:13.831] INFO: ######################################################################
[12:17:13.832] INFO: ----------------------------------------------------------------------
[12:17:13.832] INFO: PixTestTiming::TBMPhaseScan()
[12:17:13.832] INFO: ----------------------------------------------------------------------
[12:24:08.245] INFO: TBM Phase Settings: 248
[12:24:08.245] INFO: 400MHz Phase: 6
[12:24:08.245] INFO: 160MHz Phase: 7
[12:24:08.245] INFO: Functional Phase Area: 3
[12:24:08.265] INFO: Test took 414433 ms.
[12:24:08.265] INFO: PixTestTiming::TBMPhaseScan() done.
[12:24:08.265] INFO: ----------------------------------------------------------------------
[12:24:08.265] INFO: PixTestTiming::ROCDelayScan()
[12:24:08.265] INFO: ----------------------------------------------------------------------
[12:26:11.580] INFO: ROC Delay Settings: 228
[12:26:11.581] INFO: ROC Header-Trailer/Token Delay: 11
[12:26:11.581] INFO: ROC Port 0 Delay: 4
[12:26:11.581] INFO: ROC Port 1 Delay: 4
[12:26:11.581] INFO: Functional ROC Area: 4
[12:26:11.584] INFO: Test took 123319 ms.
[12:26:11.584] INFO: PixTestTiming::ROCDelayScan() done.
[12:26:11.584] INFO: ----------------------------------------------------------------------
[12:26:11.584] INFO: PixTestTiming::TimingTest()
[12:26:11.584] INFO: ----------------------------------------------------------------------
[12:26:27.545] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:42.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:56.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:11.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:26.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:41.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:55.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:10.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:25.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:40.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:40.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: Read back bit status: 1
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: Timings are good!
[12:28:40.453] INFO: ----------------------------------------------------------------------
[12:28:40.453] INFO: Test took 148869 ms.
[12:28:40.453] INFO: PixTestTiming::TimingTest() done.
[12:28:40.498] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:28:40.498] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:28:40.498] INFO: PixTestTiming::doTest took 686670 ms.
[12:28:40.498] INFO: PixTestTiming::doTest() done
[12:28:40.498] INFO: Write out TBMPhaseScan_0_V0
[12:28:40.498] INFO: Write out TBMPhaseScan_1_V0
[12:28:40.498] INFO: Write out CombinedTBMPhaseScan_V0
[12:28:40.639] INFO: Write out ROCDelayScan3_V0
[12:28:40.640] INFO: enter test to run
[12:29:13.252] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:29:13.252] INFO: running: highrate
[12:29:13.252] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:29:14.517] INFO: ----------------------------------------------------------------------
[12:29:14.517] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:29:14.517] INFO: ----------------------------------------------------------------------
[12:29:14.517] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:29:14.517] INFO: edge/corner pixel THR is adjusted
[12:29:14.517] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:29:15.474] INFO: Collecting data for 5 seconds...
[12:29:20.492] INFO: Done with hot pixel readout
[12:29:31.150] INFO: PixTest:: pg_setup set to default.
[12:29:31.151] INFO: 1 hot pixels found in step 0
[12:29:32.140] INFO: Collecting data for 5 seconds...
[12:29:37.158] INFO: Done with hot pixel readout
[12:29:47.934] INFO: PixTest:: pg_setup set to default.
[12:29:47.935] INFO: 0 hot pixels found in step 1
[12:29:47.968] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:29:47.971] INFO: PixTest::trimHotPixels() done
[12:29:47.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat
[12:29:47.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C1.dat
[12:29:47.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C2.dat
[12:29:47.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C3.dat
[12:29:47.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C4.dat
[12:29:47.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C5.dat
[12:29:47.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C6.dat
[12:29:48.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C7.dat
[12:29:48.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C8.dat
[12:29:48.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C9.dat
[12:29:48.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C10.dat
[12:29:48.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C11.dat
[12:29:48.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C12.dat
[12:29:48.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C13.dat
[12:29:48.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C14.dat
[12:29:48.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[12:29:48.058] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[12:29:48.068] INFO: enter test to run
[12:30:11.867] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:30:11.867] INFO: running: highrate
[12:30:11.872] INFO: ----------------------------------------------------------------------
[12:30:11.872] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:30:11.872] INFO: ----------------------------------------------------------------------
[12:30:11.872] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:30:11.872] INFO: edge/corner pixel THR is adjusted
[12:30:11.872] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:30:12.829] INFO: Collecting data for 1 seconds...
[12:30:13.833] INFO: Done with hot pixel readout
[12:30:17.425] INFO: PixTest:: pg_setup set to default.
[12:30:17.426] INFO: 0 hot pixels found in step 0
[12:30:17.433] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:30:17.535] INFO: PixTest::trimHotPixels() done
[12:30:17.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat
[12:30:17.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C1.dat
[12:30:17.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C2.dat
[12:30:17.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C3.dat
[12:30:17.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C4.dat
[12:30:17.569] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C5.dat
[12:30:17.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C6.dat
[12:30:17.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C7.dat
[12:30:17.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C8.dat
[12:30:17.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C9.dat
[12:30:17.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C10.dat
[12:30:17.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C11.dat
[12:30:17.619] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C12.dat
[12:30:17.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C13.dat
[12:30:17.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C14.dat
[12:30:17.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[12:30:17.655] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-23_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[12:30:17.667] INFO: enter test to run
[12:30:42.979] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:30:42.979] INFO: running: xray
[12:30:42.980] INFO: ----------------------------------------------------------------------
[12:30:42.980] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:30:42.980] INFO: ----------------------------------------------------------------------
[12:30:43.943] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:30:55.882] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:31:24.386] INFO: Resuming triggers.
[12:31:36.321] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:32:04.778] INFO: Resuming triggers.
[12:32:16.712] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:32:44.950] INFO: Resuming triggers.
[12:32:56.885] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:33:24.811] INFO: Resuming triggers.
[12:33:36.744] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:34:04.981] INFO: Resuming triggers.
[12:34:16.919] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:34:44.916] INFO: Resuming triggers.
[12:34:56.848] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:35:24.912] INFO: Resuming triggers.
[12:35:36.845] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:36:05.058] INFO: Resuming triggers.
[12:36:09.897] INFO: data taking finished, elapsed time: 100 seconds.
[12:36:21.617] INFO: PixTest:: pg_setup set to default.
[12:36:21.621] INFO: PixTestXray::doPhRun() done
[12:36:21.808] INFO: enter test to run
[12:36:59.521] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:36:59.521] INFO: running: xray
[12:36:59.522] INFO: ----------------------------------------------------------------------
[12:36:59.522] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:36:59.522] INFO: ----------------------------------------------------------------------
[12:37:00.484] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:37:07.969] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:37:37.698] INFO: Resuming triggers.
[12:37:45.181] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:38:14.408] INFO: Resuming triggers.
[12:38:21.891] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:38:50.426] INFO: Resuming triggers.
[12:38:57.915] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:39:26.948] INFO: Resuming triggers.
[12:39:34.437] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[12:40:03.464] INFO: Resuming triggers.
[12:40:10.950] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:40:39.550] INFO: Resuming triggers.
[12:40:47.034] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:41:16.298] INFO: Resuming triggers.
[12:41:23.787] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:41:53.019] INFO: Resuming triggers.
[12:42:00.509] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:42:29.926] INFO: Resuming triggers.
[12:42:37.415] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:43:06.653] INFO: Resuming triggers.
[12:43:14.141] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:43:44.026] INFO: Resuming triggers.
[12:43:51.516] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[12:44:21.081] INFO: Resuming triggers.
[12:44:28.566] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:44:57.835] INFO: Resuming triggers.
[12:45:00.832] INFO: data taking finished, elapsed time: 100 seconds.
[12:45:12.594] INFO: PixTest:: pg_setup set to default.
[12:45:12.597] INFO: PixTestXray::doPhRun() done
[12:45:12.768] INFO: enter test to run
[12:45:44.853] INFO: test: HighRate no parameter change
[12:45:44.853] INFO: running: highrate
[12:45:44.865] INFO: ----------------------------------------------------------------------
[12:45:44.865] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:45:44.865] INFO: ----------------------------------------------------------------------
[12:45:45.022] INFO: Expecting 768 events.
[12:45:46.154] INFO: 768 events read in total (416ms).
[12:45:46.154] INFO: Test took 1267ms.
[12:45:46.958] INFO: Expecting 41600 events.
[12:45:50.032] INFO: 41600 events read in total (2547ms).
[12:45:50.033] INFO: Test took 3828ms.
[12:45:50.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:50.800] INFO: Expecting 41600 events.
[12:45:53.933] INFO: 41600 events read in total (2606ms).
[12:45:53.934] INFO: Test took 3857ms.
[12:45:53.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:54.692] INFO: Expecting 41600 events.
[12:45:57.852] INFO: 41600 events read in total (2633ms).
[12:45:57.853] INFO: Test took 3874ms.
[12:45:57.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:58.617] INFO: Expecting 41600 events.
[12:46:01.768] INFO: 41600 events read in total (2624ms).
[12:46:01.769] INFO: Test took 3870ms.
[12:46:01.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:02.531] INFO: Expecting 41600 events.
[12:46:05.694] INFO: 41600 events read in total (2636ms).
[12:46:05.695] INFO: Test took 3880ms.
[12:46:05.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:06.450] INFO: Expecting 41600 events.
[12:46:09.612] INFO: 41600 events read in total (2635ms).
[12:46:09.613] INFO: Test took 3873ms.
[12:46:09.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:10.377] INFO: Expecting 41600 events.
[12:46:13.532] INFO: 41600 events read in total (2628ms).
[12:46:13.533] INFO: Test took 3873ms.
[12:46:13.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:14.287] INFO: Expecting 41600 events.
[12:46:17.431] INFO: 41600 events read in total (2617ms).
[12:46:17.432] INFO: Test took 3853ms.
[12:46:17.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:18.193] INFO: Expecting 41600 events.
[12:46:21.290] INFO: 41600 events read in total (2571ms).
[12:46:21.291] INFO: Test took 3813ms.
[12:46:21.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:22.056] INFO: Expecting 41600 events.
[12:46:25.120] INFO: 41600 events read in total (2537ms).
[12:46:25.121] INFO: Test took 3782ms.
[12:46:25.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:25.886] INFO: Expecting 41600 events.
[12:46:29.038] INFO: 41600 events read in total (2626ms).
[12:46:29.039] INFO: Test took 3870ms.
[12:46:29.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:29.800] INFO: Expecting 41600 events.
[12:46:32.947] INFO: 41600 events read in total (2620ms).
[12:46:32.948] INFO: Test took 3863ms.
[12:46:32.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:33.707] INFO: Expecting 41600 events.
[12:46:36.849] INFO: 41600 events read in total (2615ms).
[12:46:36.850] INFO: Test took 3855ms.
[12:46:36.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:37.611] INFO: Expecting 41600 events.
[12:46:40.760] INFO: 41600 events read in total (2622ms).
[12:46:40.761] INFO: Test took 3865ms.
[12:46:40.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:41.520] INFO: Expecting 41600 events.
[12:46:44.683] INFO: 41600 events read in total (2636ms).
[12:46:44.684] INFO: Test took 3875ms.
[12:46:44.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:45.444] INFO: Expecting 41600 events.
[12:46:48.581] INFO: 41600 events read in total (2610ms).
[12:46:48.582] INFO: Test took 3845ms.
[12:46:48.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:49.341] INFO: Expecting 41600 events.
[12:46:52.495] INFO: 41600 events read in total (2627ms).
[12:46:52.496] INFO: Test took 3867ms.
[12:46:52.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:53.261] INFO: Expecting 41600 events.
[12:46:56.397] INFO: 41600 events read in total (2609ms).
[12:46:56.398] INFO: Test took 3855ms.
[12:46:56.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:57.159] INFO: Expecting 41600 events.
[12:47:00.259] INFO: 41600 events read in total (2573ms).
[12:47:00.259] INFO: Test took 3812ms.
[12:47:00.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:01.019] INFO: Expecting 41600 events.
[12:47:03.960] INFO: 41600 events read in total (2414ms).
[12:47:03.961] INFO: Test took 3653ms.
[12:47:03.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:04.365] INFO: enter test to run
[12:47:10.668] INFO: test: HighRate no parameter change
[12:47:10.668] INFO: running: highrate
[12:47:10.670] INFO: ----------------------------------------------------------------------
[12:47:10.670] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:10.670] INFO: ----------------------------------------------------------------------
[12:47:11.282] INFO: Expecting 208000 events.
[12:47:22.613] INFO: 208000 events read in total (10804ms).
[12:47:22.615] INFO: Test took 11939ms.
[12:47:22.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:22.985] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[12:47:22.998] INFO: number of red-efficiency pixels: 81 45 68 129 92 104 105 90 73 83 92 87 65 45 16 19
[12:47:22.998] INFO: number of X-ray hits detected: 59750 37530 59174 90057 92339 97723 93949 67601 63742 79756 80809 70191 72845 42142 17095 22284
[12:47:22.998] 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:47:22.998] INFO: number of Vcal hits detected: 207917 207954 207931 207869 207906 207894 207843 207910 207926 207917 207904 207913 207933 207955 207984 207980
[12:47:22.998] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 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:47:22.998] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:47:22.998] INFO: X-ray hit rate [MHz/cm2]: 17.5 11.0 17.3 26.4 27.1 28.6 27.5 19.8 18.7 23.4 23.7 20.6 21.4 12.4 5.0 6.5
[12:47:22.998] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:23.050] INFO: PixTest:: pg_setup set to default.
[12:47:23.060] INFO: enter test to run
[12:47:35.668] INFO: test: HighRate no parameter change
[12:47:35.668] INFO: running: highrate
[12:47:35.669] INFO: ----------------------------------------------------------------------
[12:47:35.669] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:35.669] INFO: ----------------------------------------------------------------------
[12:47:36.284] INFO: Expecting 208000 events.
[12:47:48.710] INFO: 208000 events read in total (11899ms).
[12:47:48.716] INFO: Test took 13038ms.
[12:47:48.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:49.261] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[12:47:49.261] INFO: number of red-efficiency pixels: 206 102 246 362 248 302 288 262 238 271 315 253 222 138 42 47
[12:47:49.261] INFO: number of X-ray hits detected: 125886 79110 125434 191079 196267 206886 198975 143111 135832 168320 171576 149070 153825 89848 37000 47889
[12:47:49.261] 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:47:49.261] INFO: number of Vcal hits detected: 207774 207897 207738 207616 207740 207670 207648 207721 207751 207715 207666 207734 207766 207853 207957 207952
[12:47:49.261] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:47:49.261] INFO: Vcal hit overall 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:47:49.261] INFO: X-ray hit rate [MHz/cm2]: 36.9 23.2 36.8 56.0 57.5 60.6 58.3 41.9 39.8 49.3 50.3 43.7 45.1 26.3 10.8 14.0
[12:47:49.261] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:49.315] INFO: PixTest:: pg_setup set to default.
[12:47:49.329] INFO: enter test to run
[12:48:04.124] INFO: test: HighRate no parameter change
[12:48:04.124] INFO: running: highrate
[12:48:04.125] INFO: ----------------------------------------------------------------------
[12:48:04.125] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:04.125] INFO: ----------------------------------------------------------------------
[12:48:04.746] INFO: Expecting 208000 events.
[12:48:19.089] INFO: 208000 events read in total (13816ms).
[12:48:19.096] INFO: Test took 14962ms.
[12:48:19.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:19.793] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[12:48:19.793] INFO: number of red-efficiency pixels: 474 223 538 816 612 687 684 525 468 522 652 546 506 231 77 71
[12:48:19.793] INFO: number of X-ray hits detected: 187217 117133 185815 284569 291203 306756 296256 213841 202624 250865 253077 222546 229136 134305 54649 70402
[12:48:19.793] 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:48:19.793] INFO: number of Vcal hits detected: 207426 207758 207316 207057 207307 207211 207167 207398 207494 207433 207275 207388 207454 207751 207922 207927
[12:48:19.793] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.7 99.7 99.7 99.7 99.8 99.7 99.7 99.7 99.8 99.9 100.0 100.0
[12:48:19.793] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.7 99.6 99.6 99.7 99.8 99.7 99.7 99.7 99.7 99.9 100.0 100.0
[12:48:19.793] INFO: X-ray hit rate [MHz/cm2]: 54.9 34.3 54.5 83.4 85.4 89.9 86.8 62.7 59.4 73.5 74.2 65.2 67.2 39.4 16.0 20.6
[12:48:19.793] INFO: PixTestHighRate::doXPixelAlive() done
[12:48:19.841] INFO: PixTest:: pg_setup set to default.
[12:48:19.855] INFO: enter test to run
[12:48:22.284] INFO: test: exit no parameter change
[12:48:22.955] QUIET: Connection to board 33 closed.
[12:48:23.127] INFO: pXar: this is the end, my friend