[14:20:13.320] INFO: *** Welcome to pxar ***
[14:20:13.320] INFO: *** Today: 2016/09/14
[14:20:13.341] INFO: *** Version: v1.9.0-818-g96727
[14:20:13.341] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C15.dat
[14:20:13.342] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:20:13.342] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:20:13.342] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:20:13.419] INFO: clk: 4
[14:20:13.419] INFO: ctr: 4
[14:20:13.419] INFO: sda: 19
[14:20:13.419] INFO: tin: 9
[14:20:13.419] INFO: level: 15
[14:20:13.419] INFO: triggerdelay: 0
[14:20:13.419] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:20:13.419] INFO: Log level: INFO
[14:20:13.437] QUIET: Connection to board DTB_WREKRL opened.
[14:20:13.440] 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:
------------------------------------------------------
[14:20:13.443] INFO: RPC call hashes of host and DTB match: 398089610
[14:20:14.971] INFO: DUT info:
[14:20:14.971] INFO: The DUT currently contains the following objects:
[14:20:14.971] INFO: 2 TBM Cores tbm08c (2 ON)
[14:20:14.971] INFO: TBM Core alpha (0): 7 registers set
[14:20:14.971] INFO: TBM Core beta (1): 7 registers set
[14:20:14.971] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:20:14.971] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.971] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.972] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.972] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:14.972] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:20:15.375] INFO: enter 'restricted' command line mode
[14:20:15.375] INFO: enter test to run
[14:20:25.380] INFO: test: PixelAlive no parameter change
[14:20:25.380] INFO: running: pixelalive
[14:20:25.387] INFO: ----------------------------------------------------------------------
[14:20:25.387] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:20:25.387] INFO: ----------------------------------------------------------------------
[14:20:25.710] INFO: Expecting 41600 events.
[14:20:30.011] INFO: 41600 events read in total (3583ms).
[14:20:30.170] INFO: Test took 4781ms.
[14:20:30.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:30.445] INFO: PixTestAlive::aliveTest() done
[14:20:30.445] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 1 0 0 0 0 0
[14:20:30.477] INFO: enter test to run
[14:20:38.460] INFO: test: timing no parameter change
[14:20:38.460] INFO: running: timing
[14:20:38.464] INFO: ######################################################################
[14:20:38.464] INFO: PixTestTiming::doTest()
[14:20:38.464] INFO: ######################################################################
[14:20:38.464] INFO: ----------------------------------------------------------------------
[14:20:38.464] INFO: PixTestTiming::TBMPhaseScan()
[14:20:38.464] INFO: ----------------------------------------------------------------------
[14:25:19.425] INFO: TBM Phase Settings: 236
[14:25:19.425] INFO: 400MHz Phase: 3
[14:25:19.425] INFO: 160MHz Phase: 7
[14:25:19.425] INFO: Functional Phase Area: 5
[14:25:19.434] INFO: Test took 280970 ms.
[14:25:19.434] INFO: PixTestTiming::TBMPhaseScan() done.
[14:25:19.435] INFO: ----------------------------------------------------------------------
[14:25:19.435] INFO: PixTestTiming::ROCDelayScan()
[14:25:19.435] INFO: ----------------------------------------------------------------------
[14:27:27.946] INFO: ROC Delay Settings: 228
[14:27:27.946] INFO: ROC Header-Trailer/Token Delay: 11
[14:27:27.946] INFO: ROC Port 0 Delay: 4
[14:27:27.946] INFO: ROC Port 1 Delay: 4
[14:27:27.946] INFO: Functional ROC Area: 5
[14:27:27.949] INFO: Test took 128515 ms.
[14:27:27.949] INFO: PixTestTiming::ROCDelayScan() done.
[14:27:27.949] INFO: ----------------------------------------------------------------------
[14:27:27.950] INFO: PixTestTiming::TimingTest()
[14:27:27.950] INFO: ----------------------------------------------------------------------
[14:27:44.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:59.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:14.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:29.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:44.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:59.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:14.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:29.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:44.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:59.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:00.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: Read back bit status: 1
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: Timings are good!
[14:30:00.088] INFO: ----------------------------------------------------------------------
[14:30:00.088] INFO: Test took 152139 ms.
[14:30:00.088] INFO: PixTestTiming::TimingTest() done.
[14:30:00.105] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:30:00.105] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:30:00.105] INFO: PixTestTiming::doTest took 561645 ms.
[14:30:00.105] INFO: PixTestTiming::doTest() done
[14:30:00.106] INFO: Write out TBMPhaseScan_0_V0
[14:30:00.106] INFO: Write out TBMPhaseScan_1_V0
[14:30:00.106] INFO: Write out CombinedTBMPhaseScan_V0
[14:30:00.283] INFO: Write out ROCDelayScan3_V0
[14:30:00.284] INFO: enter test to run
[14:31:06.544] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:31:06.544] INFO: running: highrate
[14:31:06.556] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:31:06.839] INFO: ----------------------------------------------------------------------
[14:31:06.839] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:31:06.839] INFO: ----------------------------------------------------------------------
[14:31:06.839] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:31:06.839] INFO: edge/corner pixel THR is adjusted
[14:31:06.839] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:31:07.817] INFO: Collecting data for 5 seconds...
[14:31:12.833] INFO: Done with hot pixel readout
[14:31:24.414] INFO: PixTest:: pg_setup set to default.
[14:31:24.415] INFO: 0 hot pixels found in step 0
[14:31:24.448] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:31:24.452] INFO: PixTest::trimHotPixels() done
[14:31:24.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[14:31:24.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[14:31:24.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[14:31:24.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[14:31:24.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[14:31:24.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[14:31:24.501] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[14:31:24.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[14:31:24.512] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[14:31:24.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[14:31:24.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[14:31:24.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[14:31:24.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[14:31:24.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[14:31:24.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[14:31:24.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:31:24.553] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:31:24.563] INFO: enter test to run
[14:31:46.736] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:31:46.736] INFO: running: highrate
[14:31:46.740] INFO: ----------------------------------------------------------------------
[14:31:46.740] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:31:46.740] INFO: ----------------------------------------------------------------------
[14:31:46.740] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:31:46.740] INFO: edge/corner pixel THR is adjusted
[14:31:46.740] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:31:47.698] INFO: Collecting data for 1 seconds...
[14:31:48.701] INFO: Done with hot pixel readout
[14:31:52.420] INFO: PixTest:: pg_setup set to default.
[14:31:52.421] INFO: 0 hot pixels found in step 0
[14:31:52.427] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:31:52.523] INFO: PixTest::trimHotPixels() done
[14:31:52.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[14:31:52.536] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[14:31:52.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[14:31:52.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[14:31:52.553] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[14:31:52.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[14:31:52.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[14:31:52.569] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[14:31:52.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[14:31:52.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[14:31:52.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[14:31:52.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[14:31:52.596] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[14:31:52.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[14:31:52.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[14:31:52.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:31:52.617] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-36_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:31:52.627] INFO: enter test to run
[14:32:08.823] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:32:08.823] INFO: running: xray
[14:32:08.840] INFO: ----------------------------------------------------------------------
[14:32:08.840] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:32:08.840] INFO: ----------------------------------------------------------------------
[14:32:09.816] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:32:21.842] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:32:50.985] INFO: Resuming triggers.
[14:33:03.009] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:33:32.192] INFO: Resuming triggers.
[14:33:44.224] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:34:12.832] INFO: Resuming triggers.
[14:34:24.861] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:34:54.140] INFO: Resuming triggers.
[14:35:06.168] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:35:35.361] INFO: Resuming triggers.
[14:35:47.390] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:36:16.523] INFO: Resuming triggers.
[14:36:28.555] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:36:57.772] INFO: Resuming triggers.
[14:37:09.803] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:37:38.000] INFO: Resuming triggers.
[14:37:43.094] INFO: data taking finished, elapsed time: 100 seconds.
[14:37:53.352] INFO: PixTest:: pg_setup set to default.
[14:37:53.356] INFO: PixTestXray::doPhRun() done
[14:37:53.574] INFO: enter test to run
[14:39:11.413] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:39:11.413] INFO: running: xray
[14:39:11.414] INFO: ----------------------------------------------------------------------
[14:39:11.414] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:39:11.414] INFO: ----------------------------------------------------------------------
[14:39:12.377] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:39:19.524] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:39:50.067] INFO: Resuming triggers.
[14:39:57.214] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:40:28.083] INFO: Resuming triggers.
[14:40:35.230] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:41:06.566] INFO: Resuming triggers.
[14:41:13.715] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:41:44.610] INFO: Resuming triggers.
[14:41:51.760] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:42:23.153] INFO: Resuming triggers.
[14:42:30.302] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:43:01.557] INFO: Resuming triggers.
[14:43:08.709] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:43:38.858] INFO: Resuming triggers.
[14:43:46.008] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:44:16.180] INFO: Resuming triggers.
[14:44:23.330] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:44:53.602] INFO: Resuming triggers.
[14:45:00.753] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:45:30.925] INFO: Resuming triggers.
[14:45:38.079] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:46:07.670] INFO: Resuming triggers.
[14:46:14.826] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:46:45.015] INFO: Resuming triggers.
[14:46:52.170] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:47:22.024] INFO: Resuming triggers.
[14:47:29.180] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:47:59.328] INFO: Resuming triggers.
[14:47:59.568] INFO: data taking finished, elapsed time: 100 seconds.
[14:48:00.966] INFO: PixTest:: pg_setup set to default.
[14:48:00.970] INFO: PixTestXray::doPhRun() done
[14:48:01.137] INFO: enter test to run
[14:48:51.505] INFO: test: HighRate no parameter change
[14:48:51.505] INFO: running: highrate
[14:48:51.516] INFO: ----------------------------------------------------------------------
[14:48:51.516] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:48:51.516] INFO: ----------------------------------------------------------------------
[14:48:51.674] INFO: Expecting 768 events.
[14:48:52.809] INFO: 768 events read in total (419ms).
[14:48:52.809] INFO: Test took 1269ms.
[14:48:53.612] INFO: Expecting 41600 events.
[14:48:56.648] INFO: 41600 events read in total (2509ms).
[14:48:56.649] INFO: Test took 3785ms.
[14:48:56.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:57.416] INFO: Expecting 41600 events.
[14:49:00.569] INFO: 41600 events read in total (2626ms).
[14:49:00.570] INFO: Test took 3876ms.
[14:49:00.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:01.330] INFO: Expecting 41600 events.
[14:49:04.506] INFO: 41600 events read in total (2649ms).
[14:49:04.507] INFO: Test took 3890ms.
[14:49:04.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:05.266] INFO: Expecting 41600 events.
[14:49:08.447] INFO: 41600 events read in total (2654ms).
[14:49:08.448] INFO: Test took 3893ms.
[14:49:08.500] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:09.211] INFO: Expecting 41600 events.
[14:49:12.404] INFO: 41600 events read in total (2666ms).
[14:49:12.405] INFO: Test took 3887ms.
[14:49:12.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:13.165] INFO: Expecting 41600 events.
[14:49:16.351] INFO: 41600 events read in total (2659ms).
[14:49:16.352] INFO: Test took 3899ms.
[14:49:16.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:17.113] INFO: Expecting 41600 events.
[14:49:20.302] INFO: 41600 events read in total (2662ms).
[14:49:20.303] INFO: Test took 3904ms.
[14:49:20.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:21.065] INFO: Expecting 41600 events.
[14:49:24.261] INFO: 41600 events read in total (2669ms).
[14:49:24.262] INFO: Test took 3912ms.
[14:49:24.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:25.025] INFO: Expecting 41600 events.
[14:49:28.236] INFO: 41600 events read in total (2684ms).
[14:49:28.237] INFO: Test took 3929ms.
[14:49:28.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:28.000] INFO: Expecting 41600 events.
[14:49:32.203] INFO: 41600 events read in total (2676ms).
[14:49:32.204] INFO: Test took 3919ms.
[14:49:32.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:32.962] INFO: Expecting 41600 events.
[14:49:36.164] INFO: 41600 events read in total (2675ms).
[14:49:36.165] INFO: Test took 3915ms.
[14:49:36.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:36.926] INFO: Expecting 41600 events.
[14:49:40.134] INFO: 41600 events read in total (2681ms).
[14:49:40.135] INFO: Test took 3923ms.
[14:49:40.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:40.894] INFO: Expecting 41600 events.
[14:49:44.097] INFO: 41600 events read in total (2676ms).
[14:49:44.098] INFO: Test took 3915ms.
[14:49:44.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:44.860] INFO: Expecting 41600 events.
[14:49:48.056] INFO: 41600 events read in total (2669ms).
[14:49:48.057] INFO: Test took 3913ms.
[14:49:48.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:48.817] INFO: Expecting 41600 events.
[14:49:52.019] INFO: 41600 events read in total (2675ms).
[14:49:52.020] INFO: Test took 3915ms.
[14:49:52.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:52.784] INFO: Expecting 41600 events.
[14:49:55.986] INFO: 41600 events read in total (2675ms).
[14:49:55.987] INFO: Test took 3920ms.
[14:49:56.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:56.745] INFO: Expecting 41600 events.
[14:49:59.935] INFO: 41600 events read in total (2663ms).
[14:49:59.936] INFO: Test took 3903ms.
[14:49:59.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:00.696] INFO: Expecting 41600 events.
[14:50:03.896] INFO: 41600 events read in total (2673ms).
[14:50:03.897] INFO: Test took 3914ms.
[14:50:03.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:04.656] INFO: Expecting 41600 events.
[14:50:07.855] INFO: 41600 events read in total (2672ms).
[14:50:07.856] INFO: Test took 3910ms.
[14:50:07.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:08.614] INFO: Expecting 41600 events.
[14:50:11.695] INFO: 41600 events read in total (2554ms).
[14:50:11.696] INFO: Test took 3793ms.
[14:50:11.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:12.097] INFO: enter test to run
[14:50:58.960] INFO: test: HighRate no parameter change
[14:50:58.960] INFO: running: highrate
[14:50:58.961] INFO: ----------------------------------------------------------------------
[14:50:58.961] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:50:58.961] INFO: ----------------------------------------------------------------------
[14:50:59.588] INFO: Expecting 208000 events.
[14:51:11.349] INFO: 208000 events read in total (11234ms).
[14:51:11.352] INFO: Test took 12380ms.
[14:51:11.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:11.727] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 1 0 0 0 160 0
[14:51:11.727] INFO: number of red-efficiency pixels: 56 40 62 111 123 133 128 75 225 104 99 81 80 46 174 21
[14:51:11.727] INFO: number of X-ray hits detected: 60265 39838 59313 87907 93643 99764 97940 67203 60230 82162 83052 69648 75514 44749 17773 21475
[14:51:11.727] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:51:11.727] INFO: number of Vcal hits detected: 207942 207960 207934 207887 207873 207863 207870 207874 205152 207896 207850 207917 207917 207953 199986 207979
[14:51:11.727] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 98.6 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:51:11.727] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 98.6 100.0 99.9 100.0 100.0 100.0 96.1 100.0
[14:51:11.727] INFO: X-ray hit rate [MHz/cm2]: 17.7 11.7 17.4 25.8 27.4 29.2 28.7 19.7 17.7 24.1 24.3 20.4 22.1 13.1 5.2 6.3
[14:51:11.727] INFO: PixTestHighRate::doXPixelAlive() done
[14:51:11.775] INFO: PixTest:: pg_setup set to default.
[14:51:11.790] INFO: enter test to run
[14:51:54.311] INFO: test: HighRate no parameter change
[14:51:54.311] INFO: running: highrate
[14:51:54.312] INFO: ----------------------------------------------------------------------
[14:51:54.312] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:51:54.312] INFO: ----------------------------------------------------------------------
[14:51:54.933] INFO: Expecting 208000 events.
[14:52:08.224] INFO: 208000 events read in total (12764ms).
[14:52:08.229] INFO: Test took 13907ms.
[14:52:08.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:08.778] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 65 0 1 0 0 0 159 0
[14:52:08.779] INFO: number of red-efficiency pixels: 186 117 256 384 443 365 430 223 299 280 234 228 238 141 193 45
[14:52:08.779] INFO: number of X-ray hits detected: 128236 84937 126796 187668 199830 213468 207409 142978 128483 174816 176629 148744 160871 94596 37835 45846
[14:52:08.779] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:52:08.779] INFO: number of Vcal hits detected: 207809 207879 207717 207586 207524 207609 207541 207710 200444 207706 207702 207760 207749 207853 199968 207955
[14:52:08.779] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 97.8 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:52:08.779] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 96.4 99.9 99.9 99.9 99.9 99.9 96.1 100.0
[14:52:08.779] INFO: X-ray hit rate [MHz/cm2]: 37.6 24.9 37.2 55.0 58.6 62.6 60.8 41.9 37.7 51.2 51.8 43.6 47.2 27.7 11.1 13.4
[14:52:08.779] INFO: PixTestHighRate::doXPixelAlive() done
[14:52:08.824] INFO: PixTest:: pg_setup set to default.
[14:52:08.838] INFO: enter test to run
[14:52:27.191] INFO: test: HighRate no parameter change
[14:52:27.191] INFO: running: highrate
[14:52:27.193] INFO: ----------------------------------------------------------------------
[14:52:27.193] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:52:27.193] INFO: ----------------------------------------------------------------------
[14:52:27.814] INFO: Expecting 208000 events.
[14:52:42.688] INFO: 208000 events read in total (14347ms).
[14:52:42.695] INFO: Test took 15494ms.
[14:52:43.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:43.428] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 21 0 1 0 0 0 160 0
[14:52:43.428] INFO: number of red-efficiency pixels: 427 254 578 876 950 804 1063 648 458 736 505 581 524 328 230 95
[14:52:43.428] INFO: number of X-ray hits detected: 196881 129943 194005 287542 305825 325815 316810 221229 196334 267559 271354 227898 248658 145036 58610 70629
[14:52:43.428] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:52:43.428] INFO: number of Vcal hits detected: 207511 207720 207264 206956 206841 207031 206657 207165 200351 207165 207399 207350 207415 207616 199926 207902
[14:52:43.428] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.6 99.4 99.7 96.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[14:52:43.428] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.5 99.4 99.5 99.4 99.6 96.3 99.6 99.7 99.7 99.7 99.8 96.1 100.0
[14:52:43.429] INFO: X-ray hit rate [MHz/cm2]: 57.7 38.1 56.9 84.3 89.6 95.5 92.9 64.8 57.5 78.4 79.5 66.8 72.9 42.5 17.2 20.7
[14:52:43.429] INFO: PixTestHighRate::doXPixelAlive() done
[14:52:43.474] INFO: PixTest:: pg_setup set to default.
[14:52:43.489] INFO: enter test to run
[14:53:15.975] INFO: test: exit no parameter change
[14:53:16.579] QUIET: Connection to board 33 closed.
[14:53:16.668] INFO: pXar: this is the end, my friend