[15:24:44.126] INFO: *** Welcome to pxar ***
[15:24:44.126] INFO: *** Today: 2016/09/29
[15:24:45.557] INFO: *** Version: v1.9.0-818-g96727
[15:24:45.557] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C15.dat
[15:24:45.628] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:24:45.628] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[15:24:45.639] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[15:24:46.207] INFO: clk: 4
[15:24:46.207] INFO: ctr: 4
[15:24:46.207] INFO: sda: 19
[15:24:46.207] INFO: tin: 9
[15:24:46.207] INFO: level: 15
[15:24:46.207] INFO: triggerdelay: 0
[15:24:46.207] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:24:46.207] INFO: Log level: INFO
[15:24:46.306] QUIET: Connection to board DTB_WREKRL opened.
[15:24:46.309] 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:
------------------------------------------------------
[15:24:46.312] INFO: RPC call hashes of host and DTB match: 398089610
[15:24:47.850] INFO: DUT info:
[15:24:47.850] INFO: The DUT currently contains the following objects:
[15:24:47.850] INFO: 2 TBM Cores tbm08c (2 ON)
[15:24:47.850] INFO: TBM Core alpha (0): 7 registers set
[15:24:47.850] INFO: TBM Core beta (1): 7 registers set
[15:24:47.850] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:24:47.850] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.850] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.851] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.851] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.851] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:47.851] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:48.331] INFO: enter 'restricted' command line mode
[15:24:48.331] INFO: enter test to run
[15:24:51.714] INFO: test: PixelAlive no parameter change
[15:24:51.714] INFO: running: pixelalive
[15:24:51.788] INFO: ----------------------------------------------------------------------
[15:24:51.788] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:24:51.788] INFO: ----------------------------------------------------------------------
[15:24:52.113] INFO: Expecting 41600 events.
[15:24:56.491] INFO: 41600 events read in total (3660ms).
[15:24:56.653] INFO: Test took 4861ms.
[15:24:56.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:57.519] INFO: PixTestAlive::aliveTest() done
[15:24:57.519] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:24:57.874] INFO: enter test to run
[15:25:00.498] INFO: test: timing no parameter change
[15:25:00.498] INFO: running: timing
[15:25:00.501] INFO: ######################################################################
[15:25:00.501] INFO: PixTestTiming::doTest()
[15:25:00.501] INFO: ######################################################################
[15:25:00.502] INFO: ----------------------------------------------------------------------
[15:25:00.502] INFO: PixTestTiming::TBMPhaseScan()
[15:25:00.502] INFO: ----------------------------------------------------------------------
[15:29:37.315] INFO: TBM Phase Settings: 240
[15:29:37.315] INFO: 400MHz Phase: 4
[15:29:37.315] INFO: 160MHz Phase: 7
[15:29:37.315] INFO: Functional Phase Area: 4
[15:29:37.332] INFO: Test took 276830 ms.
[15:29:37.332] INFO: PixTestTiming::TBMPhaseScan() done.
[15:29:37.332] INFO: ----------------------------------------------------------------------
[15:29:37.332] INFO: PixTestTiming::ROCDelayScan()
[15:29:37.332] INFO: ----------------------------------------------------------------------
[15:31:34.221] INFO: ROC Delay Settings: 220
[15:31:34.221] INFO: ROC Header-Trailer/Token Delay: 11
[15:31:34.221] INFO: ROC Port 0 Delay: 4
[15:31:34.221] INFO: ROC Port 1 Delay: 3
[15:31:34.221] INFO: Functional ROC Area: 3
[15:31:34.225] INFO: Test took 116893 ms.
[15:31:34.225] INFO: PixTestTiming::ROCDelayScan() done.
[15:31:34.225] INFO: ----------------------------------------------------------------------
[15:31:34.225] INFO: PixTestTiming::TimingTest()
[15:31:34.225] INFO: ----------------------------------------------------------------------
[15:31:50.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:05.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:20.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:35.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:50.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:05.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:20.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:34.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:49.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:04.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:05.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: Read back bit status: 1
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: Timings are good!
[15:34:05.198] INFO: ----------------------------------------------------------------------
[15:34:05.198] INFO: Test took 150973 ms.
[15:34:05.198] INFO: PixTestTiming::TimingTest() done.
[15:34:05.212] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:34:05.212] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:34:05.212] INFO: PixTestTiming::doTest took 544714 ms.
[15:34:05.212] INFO: PixTestTiming::doTest() done
[15:34:05.212] INFO: Write out TBMPhaseScan_0_V0
[15:34:05.212] INFO: Write out TBMPhaseScan_1_V0
[15:34:05.213] INFO: Write out CombinedTBMPhaseScan_V0
[15:34:05.214] INFO: Write out ROCDelayScan3_V0
[15:34:05.215] INFO: enter test to run
[15:35:31.134] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:35:31.134] INFO: running: highrate
[15:35:31.154] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:35:31.436] INFO: ----------------------------------------------------------------------
[15:35:31.436] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:35:31.436] INFO: ----------------------------------------------------------------------
[15:35:31.436] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:35:31.436] INFO: edge/corner pixel THR is adjusted
[15:35:31.436] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:35:32.394] INFO: Collecting data for 5 seconds...
[15:35:37.411] INFO: Done with hot pixel readout
[15:35:49.234] INFO: PixTest:: pg_setup set to default.
[15:35:49.234] INFO: 1 hot pixels found in step 0
[15:35:50.228] INFO: Collecting data for 5 seconds...
[15:35:55.244] INFO: Done with hot pixel readout
[15:36:07.007] INFO: PixTest:: pg_setup set to default.
[15:36:07.008] INFO: 1 hot pixels found in step 1
[15:36:07.000] INFO: Collecting data for 5 seconds...
[15:36:13.016] INFO: Done with hot pixel readout
[15:36:24.822] INFO: PixTest:: pg_setup set to default.
[15:36:24.823] INFO: 1 hot pixels found in step 2
[15:36:25.816] INFO: Collecting data for 5 seconds...
[15:36:30.832] INFO: Done with hot pixel readout
[15:36:42.585] INFO: PixTest:: pg_setup set to default.
[15:36:42.586] INFO: 2 hot pixels found in step 3
[15:36:43.580] INFO: Collecting data for 5 seconds...
[15:36:48.596] INFO: Done with hot pixel readout
[15:37:00.402] INFO: PixTest:: pg_setup set to default.
[15:37:00.403] INFO: 1 hot pixels found in step 4
[15:37:01.397] INFO: Collecting data for 5 seconds...
[15:37:06.414] INFO: Done with hot pixel readout
[15:37:18.154] INFO: PixTest:: pg_setup set to default.
[15:37:18.155] INFO: 2 hot pixels found in step 5
[15:37:19.148] INFO: Collecting data for 5 seconds...
[15:37:24.163] INFO: Done with hot pixel readout
[15:37:35.985] INFO: PixTest:: pg_setup set to default.

[15:37:35.986] INFO: 3 hot pixels found in step 6
[15:37:36.978] INFO: Collecting data for 5 seconds...
[15:37:41.995] INFO: Done with hot pixel readout
[15:37:53.709] INFO: PixTest:: pg_setup set to default.
[15:37:53.710] INFO: 0 hot pixels found in step 7
[15:37:53.746] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:37:53.750] INFO: PixTest::trimHotPixels() done
[15:37:53.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat
[15:37:53.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C1.dat
[15:37:53.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C2.dat
[15:37:53.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C3.dat
[15:37:53.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C4.dat
[15:37:53.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C5.dat
[15:37:53.783] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C6.dat
[15:37:53.788] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C7.dat
[15:37:53.793] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C8.dat
[15:37:53.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C9.dat
[15:37:53.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C10.dat
[15:37:53.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C11.dat
[15:37:53.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C12.dat
[15:37:53.818] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C13.dat
[15:37:53.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C14.dat
[15:37:53.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[15:37:53.834] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[15:37:53.844] INFO: enter test to run
[15:38:27.629] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:38:27.629] INFO: running: highrate
[15:38:27.633] INFO: ----------------------------------------------------------------------
[15:38:27.633] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:38:27.633] INFO: ----------------------------------------------------------------------
[15:38:27.633] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:38:27.633] INFO: edge/corner pixel THR is adjusted
[15:38:27.633] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:38:28.590] INFO: Collecting data for 1 seconds...
[15:38:29.594] INFO: Done with hot pixel readout
[15:38:33.595] INFO: PixTest:: pg_setup set to default.
[15:38:33.596] INFO: 0 hot pixels found in step 0
[15:38:33.602] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:38:33.690] INFO: PixTest::trimHotPixels() done
[15:38:33.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat
[15:38:33.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C1.dat
[15:38:33.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C2.dat
[15:38:33.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C3.dat
[15:38:33.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C4.dat
[15:38:33.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C5.dat
[15:38:33.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C6.dat
[15:38:33.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C7.dat
[15:38:33.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C8.dat
[15:38:33.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C9.dat
[15:38:33.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C10.dat
[15:38:33.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C11.dat
[15:38:33.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C12.dat
[15:38:33.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C13.dat
[15:38:33.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C14.dat
[15:38:33.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[15:38:33.782] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-F-1-22_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[15:38:33.812] INFO: enter test to run
[15:39:10.381] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:39:10.381] INFO: running: xray
[15:39:10.382] INFO: ----------------------------------------------------------------------
[15:39:10.382] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:39:10.382] INFO: ----------------------------------------------------------------------
[15:39:11.361] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:39:22.757] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:39:52.359] INFO: Resuming triggers.
[15:40:03.757] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:40:33.325] INFO: Resuming triggers.
[15:40:44.728] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:41:13.905] INFO: Resuming triggers.
[15:41:25.308] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:41:55.486] INFO: Resuming triggers.
[15:42:06.888] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:42:35.982] INFO: Resuming triggers.
[15:42:47.382] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:43:17.636] INFO: Resuming triggers.
[15:43:29.044] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:43:59.771] INFO: Resuming triggers.
[15:44:11.172] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:44:41.761] INFO: Resuming triggers.
[15:44:50.918] INFO: data taking finished, elapsed time: 100 seconds.
[15:45:15.080] INFO: PixTest:: pg_setup set to default.
[15:45:15.083] INFO: PixTestXray::doPhRun() done
[15:45:15.301] INFO: enter test to run
[15:45:50.178] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:45:50.178] INFO: running: xray
[15:45:50.179] INFO: ----------------------------------------------------------------------
[15:45:50.179] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:45:50.179] INFO: ----------------------------------------------------------------------
[15:45:51.142] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:45:57.790] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:46:27.864] INFO: Resuming triggers.
[15:46:34.512] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:47:04.554] INFO: Resuming triggers.
[15:47:11.200] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:47:41.268] INFO: Resuming triggers.
[15:47:47.913] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:48:17.920] INFO: Resuming triggers.
[15:48:24.563] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:48:54.726] INFO: Resuming triggers.
[15:49:01.369] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:49:31.548] INFO: Resuming triggers.
[15:49:38.190] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:50:07.002] INFO: Resuming triggers.
[15:50:14.644] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:50:44.819] INFO: Resuming triggers.
[15:50:51.462] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:51:22.415] INFO: Resuming triggers.
[15:51:29.058] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:52:00.170] INFO: Resuming triggers.
[15:52:06.814] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:52:37.609] INFO: Resuming triggers.
[15:52:44.251] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:53:15.117] INFO: Resuming triggers.
[15:53:21.759] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:53:52.017] INFO: Resuming triggers.
[15:53:58.661] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:54:29.565] INFO: Resuming triggers.
[15:54:36.211] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:55:08.126] INFO: Resuming triggers.
[15:55:08.810] INFO: data taking finished, elapsed time: 100 seconds.
[15:55:12.578] INFO: PixTest:: pg_setup set to default.
[15:55:12.581] INFO: PixTestXray::doPhRun() done
[15:55:12.737] INFO: enter test to run
[15:55:40.566] INFO: test: HighRate no parameter change
[15:55:40.566] INFO: running: highrate
[15:55:40.645] INFO: ----------------------------------------------------------------------
[15:55:40.645] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:55:40.645] INFO: ----------------------------------------------------------------------
[15:55:40.902] INFO: Expecting 768 events.
[15:55:42.072] INFO: 768 events read in total (455ms).
[15:55:42.072] INFO: Test took 1340ms.
[15:55:42.875] INFO: Expecting 41600 events.
[15:55:46.011] INFO: 41600 events read in total (2609ms).
[15:55:46.012] INFO: Test took 3777ms.
[15:55:46.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:46.764] INFO: Expecting 41600 events.
[15:55:49.960] INFO: 41600 events read in total (2669ms).
[15:55:49.962] INFO: Test took 3896ms.
[15:55:49.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:50.717] INFO: Expecting 41600 events.
[15:55:53.869] INFO: 41600 events read in total (2625ms).
[15:55:53.870] INFO: Test took 3856ms.
[15:55:53.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:54.626] INFO: Expecting 41600 events.
[15:55:57.955] INFO: 41600 events read in total (2803ms).
[15:55:57.956] INFO: Test took 4031ms.
[15:55:57.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:58.702] INFO: Expecting 41600 events.
[15:56:01.899] INFO: 41600 events read in total (2671ms).
[15:56:01.900] INFO: Test took 3890ms.
[15:56:01.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:02.653] INFO: Expecting 41600 events.
[15:56:05.855] INFO: 41600 events read in total (2676ms).
[15:56:05.856] INFO: Test took 3903ms.
[15:56:05.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:06.609] INFO: Expecting 41600 events.
[15:56:09.853] INFO: 41600 events read in total (2717ms).
[15:56:09.854] INFO: Test took 3946ms.
[15:56:09.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:10.613] INFO: Expecting 41600 events.
[15:56:13.828] INFO: 41600 events read in total (2688ms).
[15:56:13.829] INFO: Test took 3921ms.
[15:56:13.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:14.586] INFO: Expecting 41600 events.
[15:56:17.892] INFO: 41600 events read in total (2779ms).
[15:56:17.893] INFO: Test took 4010ms.
[15:56:17.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:18.647] INFO: Expecting 41600 events.
[15:56:21.898] INFO: 41600 events read in total (2724ms).
[15:56:21.899] INFO: Test took 3954ms.
[15:56:21.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:22.650] INFO: Expecting 41600 events.
[15:56:25.929] INFO: 41600 events read in total (2753ms).
[15:56:25.930] INFO: Test took 3978ms.
[15:56:25.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:26.680] INFO: Expecting 41600 events.
[15:56:29.928] INFO: 41600 events read in total (2722ms).
[15:56:29.930] INFO: Test took 3948ms.
[15:56:29.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:30.674] INFO: Expecting 41600 events.
[15:56:33.855] INFO: 41600 events read in total (2654ms).
[15:56:33.856] INFO: Test took 3865ms.
[15:56:33.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:34.612] INFO: Expecting 41600 events.
[15:56:37.942] INFO: 41600 events read in total (2803ms).
[15:56:37.943] INFO: Test took 4033ms.
[15:56:37.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:38.696] INFO: Expecting 41600 events.
[15:56:41.965] INFO: 41600 events read in total (2743ms).
[15:56:41.966] INFO: Test took 3968ms.
[15:56:41.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:42.722] INFO: Expecting 41600 events.
[15:56:45.987] INFO: 41600 events read in total (2738ms).
[15:56:45.988] INFO: Test took 3967ms.
[15:56:46.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:46.745] INFO: Expecting 41600 events.
[15:56:50.080] INFO: 41600 events read in total (2808ms).
[15:56:50.081] INFO: Test took 4040ms.
[15:56:50.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:50.839] INFO: Expecting 41600 events.
[15:56:54.096] INFO: 41600 events read in total (2730ms).
[15:56:54.097] INFO: Test took 3963ms.
[15:56:54.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:54.853] INFO: Expecting 41600 events.
[15:56:58.130] INFO: 41600 events read in total (2751ms).
[15:56:58.130] INFO: Test took 3979ms.
[15:56:58.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:58.883] INFO: Expecting 41600 events.
[15:57:02.010] INFO: 41600 events read in total (2600ms).
[15:57:02.011] INFO: Test took 3826ms.
[15:57:02.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:02.403] INFO: enter test to run
[15:57:16.749] INFO: test: HighRate no parameter change
[15:57:16.749] INFO: running: highrate
[15:57:16.750] INFO: ----------------------------------------------------------------------
[15:57:16.750] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:57:16.750] INFO: ----------------------------------------------------------------------
[15:57:17.372] INFO: Expecting 208000 events.
[15:57:29.462] INFO: 208000 events read in total (11563ms).
[15:57:29.465] INFO: Test took 12706ms.
[15:57:29.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:29.864] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:57:29.864] INFO: number of red-efficiency pixels: 98 49 94 130 172 160 138 124 93 108 107 100 88 50 29 29
[15:57:29.864] INFO: number of X-ray hits detected: 72817 44513 72140 109856 117199 119002 118935 84428 75562 95232 93624 79530 84431 50407 20178 27137
[15:57:29.864] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:57:29.864] INFO: number of Vcal hits detected: 207900 207950 207804 207866 207825 207837 207858 207871 207904 207889 207892 207899 207911 207948 207971 207971
[15:57:29.864] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:57:29.864] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:57:29.864] INFO: X-ray hit rate [MHz/cm2]: 21.3 13.0 21.1 32.2 34.4 34.9 34.9 24.7 22.1 27.9 27.4 23.3 24.7 14.8 5.9 8.0
[15:57:29.864] INFO: PixTestHighRate::doXPixelAlive() done
[15:57:29.909] INFO: PixTest:: pg_setup set to default.
[15:57:29.920] INFO: enter test to run
[15:58:04.853] INFO: test: HighRate no parameter change
[15:58:04.853] INFO: running: highrate
[15:58:04.854] INFO: ----------------------------------------------------------------------
[15:58:04.854] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:58:04.854] INFO: ----------------------------------------------------------------------
[15:58:05.470] INFO: Expecting 208000 events.
[15:58:19.070] INFO: 208000 events read in total (13073ms).
[15:58:19.076] INFO: Test took 14212ms.
[15:58:19.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:19.677] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:58:19.677] INFO: number of red-efficiency pixels: 303 151 319 488 587 576 490 346 242 328 289 298 314 149 51 56
[15:58:19.677] INFO: number of X-ray hits detected: 149726 92134 147815 225046 239839 243204 242475 172398 155823 195357 192580 161921 172493 103363 41492 55502
[15:58:19.677] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:58:19.677] INFO: number of Vcal hits detected: 207669 207841 207553 207456 207346 207363 207454 207600 207747 207659 207696 207681 207664 207847 207948 207944
[15:58:19.677] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[15:58:19.677] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.9 99.8 99.8 99.9 100.0 100.0
[15:58:19.678] INFO: X-ray hit rate [MHz/cm2]: 43.9 27.0 43.3 66.0 70.3 71.3 71.1 50.5 45.7 57.3 56.4 47.5 50.6 30.3 12.2 16.3
[15:58:19.678] INFO: PixTestHighRate::doXPixelAlive() done
[15:58:19.731] INFO: PixTest:: pg_setup set to default.
[15:58:19.746] INFO: enter test to run
[15:58:44.420] INFO: test: HighRate no parameter change
[15:58:44.420] INFO: running: highrate
[15:58:44.421] INFO: ----------------------------------------------------------------------
[15:58:44.421] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:58:44.421] INFO: ----------------------------------------------------------------------
[15:58:45.029] INFO: Expecting 208000 events.
[15:59:00.540] INFO: 208000 events read in total (14984ms).
[15:59:00.548] INFO: Test took 16119ms.
[15:59:00.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:01.340] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:59:01.340] INFO: number of red-efficiency pixels: 635 288 760 1238 1463 1401 1085 837 604 765 689 725 761 358 90 119
[15:59:01.340] INFO: number of X-ray hits detected: 228244 138636 223945 342327 365133 369030 370454 261361 237320 296277 292112 247562 262451 156539 64131 84858
[15:59:01.340] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:59:01.340] INFO: number of Vcal hits detected: 207163 207678 206858 206424 206038 206092 206648 206879 207319 207120 207211 207152 207135 207593 207909 207876
[15:59:01.340] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.3 99.2 99.2 99.4 99.5 99.7 99.6 99.7 99.6 99.6 99.8 100.0 99.9
[15:59:01.340] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.2 99.1 99.1 99.4 99.5 99.7 99.6 99.6 99.6 99.6 99.8 100.0 99.9
[15:59:01.340] INFO: X-ray hit rate [MHz/cm2]: 66.9 40.6 65.6 100.3 107.0 108.2 108.6 76.6 69.6 86.8 85.6 72.6 76.9 45.9 18.8 24.9
[15:59:01.340] INFO: PixTestHighRate::doXPixelAlive() done
[15:59:01.389] INFO: PixTest:: pg_setup set to default.
[15:59:01.401] INFO: enter test to run
[15:59:27.212] INFO: test: exit no parameter change
[15:59:27.758] QUIET: Connection to board 33 closed.
[15:59:27.798] INFO: pXar: this is the end, my friend