[12:11:05.192] INFO: *** Welcome to pxar ***
[12:11:05.192] INFO: *** Today: 2016/08/31
[12:11:06.017] INFO: *** Version: v1.9.0-818-g96727
[12:11:06.017] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//dacParameters35_C15.dat
[12:11:06.018] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:11:06.035] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[12:11:06.035] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[12:11:06.162] INFO: clk: 4
[12:11:06.162] INFO: ctr: 4
[12:11:06.162] INFO: sda: 19
[12:11:06.162] INFO: tin: 9
[12:11:06.162] INFO: level: 15
[12:11:06.162] INFO: triggerdelay: 0
[12:11:06.163] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:11:06.163] INFO: Log level: INFO
[12:11:06.196] QUIET: Connection to board DTB_WREK4U opened.
[12:11:06.199] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[12:11:06.202] INFO: RPC call hashes of host and DTB match: 398089610
[12:11:07.746] INFO: DUT info:
[12:11:07.746] INFO: The DUT currently contains the following objects:
[12:11:07.746] INFO: 2 TBM Cores tbm08c (2 ON)
[12:11:07.746] INFO: TBM Core alpha (0): 7 registers set
[12:11:07.746] INFO: TBM Core beta (1): 7 registers set
[12:11:07.746] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:11:07.746] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.746] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.747] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:07.747] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:08.171] INFO: enter 'restricted' command line mode
[12:11:08.171] INFO: enter test to run
[12:11:17.148] INFO: test: PixelAlive no parameter change
[12:11:17.148] INFO: running: pixelalive
[12:11:17.177] INFO: ----------------------------------------------------------------------
[12:11:17.177] 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:11:17.177] INFO: ----------------------------------------------------------------------
[12:11:17.501] INFO: Expecting 41600 events.
[12:11:21.835] INFO: 41600 events read in total (3615ms).
[12:11:21.004] INFO: Test took 4824ms.
[12:11:22.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:22.298] INFO: PixTestAlive::aliveTest() done
[12:11:22.298] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[12:11:22.329] INFO: enter test to run
[12:11:36.516] INFO: test: timing no parameter change
[12:11:36.516] INFO: running: timing
[12:11:36.519] INFO: ######################################################################
[12:11:36.519] INFO: PixTestTiming::doTest()
[12:11:36.519] INFO: ######################################################################
[12:11:36.519] INFO: ----------------------------------------------------------------------
[12:11:36.519] INFO: PixTestTiming::TBMPhaseScan()
[12:11:36.519] INFO: ----------------------------------------------------------------------
[12:20:04.524] INFO: TBM Phase Settings: 240
[12:20:04.524] INFO: 400MHz Phase: 4
[12:20:04.524] INFO: 160MHz Phase: 7
[12:20:04.524] INFO: Functional Phase Area: 5
[12:20:04.543] INFO: Test took 508024 ms.
[12:20:04.543] INFO: PixTestTiming::TBMPhaseScan() done.
[12:20:04.544] INFO: ----------------------------------------------------------------------
[12:20:04.544] INFO: PixTestTiming::ROCDelayScan()
[12:20:04.544] INFO: ----------------------------------------------------------------------
[12:22:12.462] INFO: ROC Delay Settings: 228
[12:22:12.462] INFO: ROC Header-Trailer/Token Delay: 11
[12:22:12.462] INFO: ROC Port 0 Delay: 4
[12:22:12.462] INFO: ROC Port 1 Delay: 4
[12:22:12.462] INFO: Functional ROC Area: 5
[12:22:12.465] INFO: Test took 127921 ms.
[12:22:12.465] INFO: PixTestTiming::ROCDelayScan() done.
[12:22:12.466] INFO: ----------------------------------------------------------------------
[12:22:12.466] INFO: PixTestTiming::TimingTest()
[12:22:12.466] INFO: ----------------------------------------------------------------------
[12:22:28.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:43.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:58.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:13.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:28.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:43.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:58.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:13.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:28.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:42.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:43.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: Read back bit status: 1
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: Timings are good!
[12:24:43.328] INFO: ----------------------------------------------------------------------
[12:24:43.328] INFO: Test took 150862 ms.
[12:24:43.328] INFO: PixTestTiming::TimingTest() done.
[12:24:43.367] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:24:43.367] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:24:43.367] INFO: PixTestTiming::doTest took 786851 ms.
[12:24:43.367] INFO: PixTestTiming::doTest() done
[12:24:43.367] INFO: Write out TBMPhaseScan_0_V0
[12:24:43.367] INFO: Write out TBMPhaseScan_1_V0
[12:24:43.367] INFO: Write out CombinedTBMPhaseScan_V0
[12:24:43.399] INFO: Write out ROCDelayScan3_V0
[12:24:43.399] INFO: enter test to run
[12:25:24.742] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:25:24.743] INFO: running: highrate
[12:25:24.766] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:25:25.098] INFO: ----------------------------------------------------------------------
[12:25:25.098] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:25:25.098] INFO: ----------------------------------------------------------------------
[12:25:25.098] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:25:25.099] INFO: edge/corner pixel THR is adjusted
[12:25:25.099] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:25:26.077] INFO: Collecting data for 5 seconds...
[12:25:31.094] INFO: Done with hot pixel readout
[12:25:42.729] INFO: PixTest:: pg_setup set to default.
[12:25:42.730] INFO: 2 hot pixels found in step 0
[12:25:43.723] INFO: Collecting data for 5 seconds...
[12:25:48.741] INFO: Done with hot pixel readout
[12:26:00.337] INFO: PixTest:: pg_setup set to default.
[12:26:00.338] INFO: 1 hot pixels found in step 1
[12:26:01.331] INFO: Collecting data for 5 seconds...
[12:26:06.348] INFO: Done with hot pixel readout
[12:26:17.245] INFO: PixTest:: pg_setup set to default.
[12:26:17.246] INFO: 1 hot pixels found in step 2
[12:26:18.239] INFO: Collecting data for 5 seconds...
[12:26:23.257] INFO: Done with hot pixel readout
[12:26:34.975] INFO: PixTest:: pg_setup set to default.
[12:26:34.976] INFO: 0 hot pixels found in step 3
[12:26:35.012] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:26:35.015] INFO: PixTest::trimHotPixels() done
[12:26:35.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat
[12:26:35.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C1.dat
[12:26:35.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C2.dat
[12:26:35.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C3.dat
[12:26:35.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C4.dat
[12:26:35.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C5.dat
[12:26:35.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C6.dat
[12:26:35.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C7.dat
[12:26:35.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C8.dat
[12:26:35.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C9.dat
[12:26:35.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C10.dat
[12:26:35.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C11.dat
[12:26:35.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C12.dat
[12:26:35.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C13.dat
[12:26:35.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C14.dat
[12:26:35.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[12:26:35.132] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[12:26:35.141] INFO: enter test to run
[12:27:10.638] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:27:10.638] INFO: running: highrate
[12:27:10.642] INFO: ----------------------------------------------------------------------
[12:27:10.642] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:27:10.642] INFO: ----------------------------------------------------------------------
[12:27:10.642] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:27:10.642] INFO: edge/corner pixel THR is adjusted
[12:27:10.642] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:27:11.600] INFO: Collecting data for 1 seconds...
[12:27:12.604] INFO: Done with hot pixel readout
[12:27:16.618] INFO: PixTest:: pg_setup set to default.
[12:27:16.619] INFO: 0 hot pixels found in step 0
[12:27:16.625] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:27:16.710] INFO: PixTest::trimHotPixels() done
[12:27:16.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat
[12:27:16.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C1.dat
[12:27:16.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C2.dat
[12:27:16.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C3.dat
[12:27:16.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C4.dat
[12:27:16.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C5.dat
[12:27:16.768] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C6.dat
[12:27:16.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C7.dat
[12:27:16.779] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C8.dat
[12:27:16.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C9.dat
[12:27:16.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C10.dat
[12:27:16.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C11.dat
[12:27:16.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C12.dat
[12:27:16.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C13.dat
[12:27:16.810] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C14.dat
[12:27:16.815] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[12:27:16.821] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-16_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[12:27:16.831] INFO: enter test to run
[12:27:48.485] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:27:48.485] INFO: running: xray
[12:27:48.487] INFO: ----------------------------------------------------------------------
[12:27:48.487] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:27:48.487] INFO: ----------------------------------------------------------------------
[12:27:49.490] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:28:00.976] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:28:30.189] INFO: Resuming triggers.
[12:28:41.775] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:29:10.956] INFO: Resuming triggers.
[12:29:22.446] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:29:51.890] INFO: Resuming triggers.
[12:30:03.374] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:30:32.784] INFO: Resuming triggers.
[12:30:44.268] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:31:14.126] INFO: Resuming triggers.
[12:31:25.614] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:31:56.048] INFO: Resuming triggers.
[12:32:07.536] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:32:37.609] INFO: Resuming triggers.
[12:32:49.097] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:33:18.818] INFO: Resuming triggers.
[12:33:27.293] INFO: data taking finished, elapsed time: 100 seconds.
[12:33:49.885] INFO: PixTest:: pg_setup set to default.
[12:33:49.888] INFO: PixTestXray::doPhRun() done
[12:33:50.101] INFO: enter test to run
[12:34:56.658] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:34:56.659] INFO: running: xray
[12:34:56.660] INFO: ----------------------------------------------------------------------
[12:34:56.660] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:34:56.660] INFO: ----------------------------------------------------------------------
[12:34:57.623] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:35:04.418] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:35:34.496] INFO: Resuming triggers.
[12:35:41.287] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:36:09.932] INFO: Resuming triggers.
[12:36:16.726] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:36:46.839] INFO: Resuming triggers.
[12:36:53.633] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[12:37:23.811] INFO: Resuming triggers.
[12:37:30.607] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:38:00.636] INFO: Resuming triggers.
[12:38:07.434] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:38:36.783] INFO: Resuming triggers.
[12:38:43.576] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:39:13.012] INFO: Resuming triggers.
[12:39:19.809] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:39:49.748] INFO: Resuming triggers.
[12:39:56.540] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:40:26.540] INFO: Resuming triggers.
[12:40:33.335] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:41:03.799] INFO: Resuming triggers.
[12:41:10.594] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:41:41.200] INFO: Resuming triggers.
[12:41:47.989] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:42:18.439] INFO: Resuming triggers.
[12:42:25.226] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:42:55.989] INFO: Resuming triggers.
[12:43:02.777] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:43:33.125] INFO: Resuming triggers.
[12:43:38.367] INFO: data taking finished, elapsed time: 100 seconds.
[12:44:02.538] INFO: PixTest:: pg_setup set to default.
[12:44:02.541] INFO: PixTestXray::doPhRun() done
[12:44:02.693] INFO: enter test to run
[12:44:27.863] INFO: test: HighRate no parameter change
[12:44:27.863] INFO: running: highrate
[12:44:27.874] INFO: ----------------------------------------------------------------------
[12:44:27.874] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:44:27.874] INFO: ----------------------------------------------------------------------
[12:44:28.020] INFO: Expecting 768 events.
[12:44:29.170] INFO: 768 events read in total (434ms).
[12:44:29.170] INFO: Test took 1284ms.
[12:44:29.973] INFO: Expecting 41600 events.
[12:44:33.211] INFO: 41600 events read in total (2712ms).
[12:44:33.213] INFO: Test took 4035ms.
[12:44:33.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:33.963] INFO: Expecting 41600 events.
[12:44:37.263] INFO: 41600 events read in total (2774ms).
[12:44:37.264] INFO: Test took 3997ms.
[12:44:37.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:38.023] INFO: Expecting 41600 events.
[12:44:41.295] INFO: 41600 events read in total (2746ms).
[12:44:41.296] INFO: Test took 3978ms.
[12:44:41.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:42.054] INFO: Expecting 41600 events.
[12:44:45.367] INFO: 41600 events read in total (2787ms).
[12:44:45.368] INFO: Test took 4020ms.
[12:44:45.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:46.109] INFO: Expecting 41600 events.
[12:44:49.379] INFO: 41600 events read in total (2744ms).
[12:44:49.380] INFO: Test took 3948ms.
[12:44:49.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:50.134] INFO: Expecting 41600 events.
[12:44:53.411] INFO: 41600 events read in total (2750ms).
[12:44:53.412] INFO: Test took 3978ms.
[12:44:53.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:54.167] INFO: Expecting 41600 events.
[12:44:57.520] INFO: 41600 events read in total (2826ms).
[12:44:57.521] INFO: Test took 4056ms.
[12:44:57.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:58.280] INFO: Expecting 41600 events.
[12:45:01.624] INFO: 41600 events read in total (2817ms).
[12:45:01.625] INFO: Test took 4050ms.
[12:45:01.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:02.381] INFO: Expecting 41600 events.
[12:45:05.688] INFO: 41600 events read in total (2780ms).
[12:45:05.689] INFO: Test took 4013ms.
[12:45:05.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:06.443] INFO: Expecting 41600 events.
[12:45:09.714] INFO: 41600 events read in total (2745ms).
[12:45:09.714] INFO: Test took 3972ms.
[12:45:09.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:10.470] INFO: Expecting 41600 events.
[12:45:13.842] INFO: 41600 events read in total (2845ms).
[12:45:13.844] INFO: Test took 4076ms.
[12:45:13.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:14.592] INFO: Expecting 41600 events.
[12:45:17.844] INFO: 41600 events read in total (2725ms).
[12:45:17.845] INFO: Test took 3945ms.
[12:45:17.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:18.600] INFO: Expecting 41600 events.
[12:45:21.853] INFO: 41600 events read in total (2726ms).
[12:45:21.854] INFO: Test took 3957ms.
[12:45:21.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:22.612] INFO: Expecting 41600 events.
[12:45:25.906] INFO: 41600 events read in total (2768ms).
[12:45:25.907] INFO: Test took 4001ms.
[12:45:25.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:26.660] INFO: Expecting 41600 events.
[12:45:29.987] INFO: 41600 events read in total (2800ms).
[12:45:29.988] INFO: Test took 4027ms.
[12:45:30.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:30.743] INFO: Expecting 41600 events.
[12:45:33.988] INFO: 41600 events read in total (2718ms).
[12:45:33.989] INFO: Test took 3949ms.
[12:45:34.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:34.747] INFO: Expecting 41600 events.
[12:45:38.066] INFO: 41600 events read in total (2792ms).
[12:45:38.067] INFO: Test took 4025ms.
[12:45:38.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:38.822] INFO: Expecting 41600 events.
[12:45:42.114] INFO: 41600 events read in total (2765ms).
[12:45:42.115] INFO: Test took 3996ms.
[12:45:42.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:42.861] INFO: Expecting 41600 events.
[12:45:46.078] INFO: 41600 events read in total (2690ms).
[12:45:46.079] INFO: Test took 3899ms.
[12:45:46.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:46.833] INFO: Expecting 41600 events.
[12:45:49.955] INFO: 41600 events read in total (2595ms).
[12:45:49.956] INFO: Test took 3825ms.
[12:45:49.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:50.360] INFO: enter test to run
[12:46:17.790] INFO: test: HighRate no parameter change
[12:46:17.790] INFO: running: highrate
[12:46:17.791] INFO: ----------------------------------------------------------------------
[12:46:17.791] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:17.791] INFO: ----------------------------------------------------------------------
[12:46:18.409] INFO: Expecting 208000 events.
[12:46:30.561] INFO: 208000 events read in total (11626ms).
[12:46:30.564] INFO: Test took 12765ms.
[12:46:30.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:30.978] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[12:46:30.978] INFO: number of red-efficiency pixels: 72 49 77 108 151 136 146 106 126 154 143 111 152 55 27 23
[12:46:30.978] INFO: number of X-ray hits detected: 66139 40228 60549 95181 101882 106146 106149 77225 83230 111212 110047 89873 97351 55030 22069 25361
[12:46:30.978] 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:46:30.978] INFO: number of Vcal hits detected: 207926 207950 207922 207889 207846 207858 207854 207891 207873 207844 207853 207882 207848 207926 207777 207976
[12:46:30.978] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:46:30.978] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0
[12:46:30.978] INFO: X-ray hit rate [MHz/cm2]: 19.4 11.8 17.7 27.9 29.9 31.1 31.1 22.6 24.4 32.6 32.3 26.3 28.5 16.1 6.5 7.4
[12:46:30.978] INFO: PixTestHighRate::doXPixelAlive() done
[12:46:31.023] INFO: PixTest:: pg_setup set to default.
[12:46:31.037] INFO: enter test to run
[12:46:50.038] INFO: test: HighRate no parameter change
[12:46:50.038] INFO: running: highrate
[12:46:50.039] INFO: ----------------------------------------------------------------------
[12:46:50.039] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:50.039] INFO: ----------------------------------------------------------------------
[12:46:50.662] INFO: Expecting 208000 events.
[12:47:04.307] INFO: 208000 events read in total (13118ms).
[12:47:04.312] INFO: Test took 14263ms.
[12:47:04.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:04.910] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[12:47:04.910] INFO: number of red-efficiency pixels: 237 107 234 305 452 363 470 313 325 523 391 307 453 176 66 45
[12:47:04.910] INFO: number of X-ray hits detected: 134505 81614 123267 193667 204622 215829 214928 157979 170946 226048 222591 183115 197527 112211 45040 51607
[12:47:04.910] 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:04.910] INFO: number of Vcal hits detected: 207751 207891 207753 207674 207520 207603 207482 207668 207654 207410 207589 207659 207520 207784 207737 207954
[12:47:04.910] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.8 99.7 99.8 99.9 99.8 99.9 100.0 100.0
[12:47:04.910] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.9 99.9 100.0
[12:47:04.910] INFO: X-ray hit rate [MHz/cm2]: 39.4 23.9 36.1 56.8 60.0 63.3 63.0 46.3 50.1 66.3 65.2 53.7 57.9 32.9 13.2 15.1
[12:47:04.910] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:04.958] INFO: PixTest:: pg_setup set to default.
[12:47:04.973] INFO: enter test to run
[12:47:26.133] INFO: test: HighRate no parameter change
[12:47:26.133] INFO: running: highrate
[12:47:26.135] INFO: ----------------------------------------------------------------------
[12:47:26.135] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:26.135] INFO: ----------------------------------------------------------------------
[12:47:26.747] INFO: Expecting 208000 events.
[12:47:42.133] INFO: 208000 events read in total (14859ms).
[12:47:42.141] INFO: Test took 15996ms.
[12:47:42.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:42.918] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[12:47:42.918] INFO: number of red-efficiency pixels: 484 251 552 717 1096 839 1151 717 721 1267 895 747 980 372 111 96
[12:47:42.918] INFO: number of X-ray hits detected: 203374 123635 185472 292710 309195 326003 325339 238705 256770 341501 337339 276217 298154 169603 68963 78581
[12:47:42.918] 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:42.918] INFO: number of Vcal hits detected: 207403 207730 207307 207180 206681 207003 206547 207106 207141 206351 206927 207100 206797 207530 207690 207902
[12:47:42.918] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.6 99.4 99.6 99.6 99.3 99.5 99.6 99.5 99.8 99.9 100.0
[12:47:42.918] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.5 99.3 99.6 99.6 99.2 99.5 99.6 99.4 99.8 99.9 100.0
[12:47:42.918] INFO: X-ray hit rate [MHz/cm2]: 59.6 36.2 54.4 85.8 90.6 95.6 95.4 70.0 75.3 100.1 98.9 81.0 87.4 49.7 20.2 23.0
[12:47:42.918] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:42.968] INFO: PixTest:: pg_setup set to default.
[12:47:42.988] INFO: enter test to run
[12:47:53.517] INFO: test: exit no parameter change
[12:47:53.909] QUIET: Connection to board 32 closed.
[12:47:53.920] INFO: pXar: this is the end, my friend