[16:33:38.948] INFO: *** Welcome to pxar ***
[16:33:38.948] INFO: *** Today: 2016/10/27
[16:33:38.964] INFO: *** Version: v1.9.0-818-g96727
[16:33:38.964] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//dacParameters35_C15.dat
[16:33:38.965] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:33:38.965] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//defaultMaskFile.dat
[16:33:38.965] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C15.dat
[16:33:39.035] INFO: clk: 4
[16:33:39.035] INFO: ctr: 4
[16:33:39.035] INFO: sda: 19
[16:33:39.035] INFO: tin: 9
[16:33:39.035] INFO: level: 15
[16:33:39.035] INFO: triggerdelay: 0
[16:33:39.035] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:33:39.035] INFO: Log level: INFO
[16:33:39.051] QUIET: Connection to board DTB_WREHUL opened.
[16:33:39.054] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 30
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREHUL
MAC address: 40D85511801E
Hostname: pixelDTB030
Comment:
------------------------------------------------------
[16:33:39.056] INFO: RPC call hashes of host and DTB match: 398089610
[16:33:40.608] INFO: DUT info:
[16:33:40.608] INFO: The DUT currently contains the following objects:
[16:33:40.608] INFO: 2 TBM Cores tbm08c (2 ON)
[16:33:40.608] INFO: TBM Core alpha (0): 7 registers set
[16:33:40.608] INFO: TBM Core beta (1): 7 registers set
[16:33:40.608] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:33:40.608] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.608] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.608] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.608] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.608] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.608] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:40.609] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:33:41.012] INFO: enter 'restricted' command line mode
[16:33:41.012] INFO: enter test to run
[16:33:50.415] INFO: test: PixelAlive no parameter change
[16:33:50.415] INFO: running: pixelalive
[16:33:50.424] INFO: ----------------------------------------------------------------------
[16:33:50.424] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:33:50.424] INFO: ----------------------------------------------------------------------
[16:33:50.748] INFO: Expecting 41600 events.
[16:33:55.095] INFO: 41600 events read in total (3628ms).
[16:33:55.265] INFO: Test took 4839ms.
[16:33:55.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:55.545] INFO: PixTestAlive::aliveTest() done
[16:33:55.545] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:33:55.574] INFO: enter test to run
[16:41:38.156] INFO: test: timing no parameter change
[16:41:38.156] INFO: running: timing
[16:41:38.175] INFO: ######################################################################
[16:41:38.182] INFO: PixTestTiming::doTest()
[16:41:38.182] INFO: ######################################################################
[16:41:38.182] INFO: ----------------------------------------------------------------------
[16:41:38.182] INFO: PixTestTiming::TBMPhaseScan()
[16:41:38.182] INFO: ----------------------------------------------------------------------
[16:47:05.566] INFO: TBM Phase Settings: 236
[16:47:05.566] INFO: 400MHz Phase: 3
[16:47:05.566] INFO: 160MHz Phase: 7
[16:47:05.566] INFO: Functional Phase Area: 5
[16:47:05.576] INFO: Test took 327394 ms.
[16:47:05.576] INFO: PixTestTiming::TBMPhaseScan() done.
[16:47:05.576] INFO: ----------------------------------------------------------------------
[16:47:05.577] INFO: PixTestTiming::ROCDelayScan()
[16:47:05.577] INFO: ----------------------------------------------------------------------
[16:51:02.263] INFO: ROC Delay Settings: 228
[16:51:02.263] INFO: ROC Header-Trailer/Token Delay: 11
[16:51:02.263] INFO: ROC Port 0 Delay: 4
[16:51:02.263] INFO: ROC Port 1 Delay: 4
[16:51:02.263] INFO: Functional ROC Area: 4
[16:51:02.266] INFO: Test took 236690 ms.
[16:51:02.266] INFO: PixTestTiming::ROCDelayScan() done.
[16:51:02.266] INFO: ----------------------------------------------------------------------
[16:51:02.266] INFO: PixTestTiming::TimingTest()
[16:51:02.266] INFO: ----------------------------------------------------------------------
[16:51:18.770] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:34.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:49.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:04.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:19.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:34.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:49.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:04.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:19.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:34.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:34.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: Read back bit status: 1
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: Timings are good!
[16:53:34.748] INFO: ----------------------------------------------------------------------
[16:53:34.748] INFO: Test took 152482 ms.
[16:53:34.749] INFO: PixTestTiming::TimingTest() done.
[16:53:34.762] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:53:34.762] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:53:34.763] INFO: PixTestTiming::doTest took 716591 ms.
[16:53:34.763] INFO: PixTestTiming::doTest() done
[16:53:34.763] INFO: Write out TBMPhaseScan_0_V0
[16:53:34.763] INFO: Write out TBMPhaseScan_1_V0
[16:53:34.763] INFO: Write out CombinedTBMPhaseScan_V0
[16:53:34.789] INFO: Write out ROCDelayScan3_V0
[16:53:34.789] INFO: enter test to run
[16:54:15.295] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:54:15.295] INFO: running: highrate
[16:54:15.295] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:54:15.547] INFO: ----------------------------------------------------------------------
[16:54:15.547] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:54:15.547] INFO: ----------------------------------------------------------------------
[16:54:15.547] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:54:15.547] INFO: edge/corner pixel THR is adjusted
[16:54:15.547] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:54:16.505] INFO: Collecting data for 5 seconds...
[16:54:21.523] INFO: Done with hot pixel readout
[16:54:33.021] INFO: PixTest:: pg_setup set to default.
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.021] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:33.022] INFO: 10 hot pixels found in step 0
[16:54:34.021] INFO: Collecting data for 5 seconds...
[16:54:39.038] INFO: Done with hot pixel readout
[16:54:50.182] INFO: PixTest:: pg_setup set to default.
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.182] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:54:50.183] INFO: 6 hot pixels found in step 1
[16:54:50.219] INFO: 6 hot pixels could not be trimmed and have been masked.
[16:54:50.223] INFO: PixTest::trimHotPixels() done
[16:54:50.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C0.dat
[16:54:50.228] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C1.dat
[16:54:50.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C2.dat
[16:54:50.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C3.dat
[16:54:50.246] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C4.dat
[16:54:50.253] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C5.dat
[16:54:50.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C6.dat
[16:54:50.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C7.dat
[16:54:50.269] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C8.dat
[16:54:50.274] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C9.dat
[16:54:50.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C10.dat
[16:54:50.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C11.dat
[16:54:50.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C12.dat
[16:54:50.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C13.dat
[16:54:50.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C14.dat
[16:54:50.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C15.dat
[16:54:50.312] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//defaultMaskFile.dat
[16:54:50.322] INFO: enter test to run
[16:55:39.382] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:55:39.382] INFO: running: highrate
[16:55:39.386] INFO: ----------------------------------------------------------------------
[16:55:39.386] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:55:39.386] INFO: ----------------------------------------------------------------------
[16:55:39.387] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:55:39.387] INFO: edge/corner pixel THR is adjusted
[16:55:39.387] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:55:40.344] INFO: Collecting data for 1 seconds...
[16:55:41.347] INFO: Done with hot pixel readout
[16:55:45.331] INFO: PixTest:: pg_setup set to default.
[16:55:45.331] INFO: 0 hot pixels found in step 0
[16:55:45.337] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:55:45.424] INFO: PixTest::trimHotPixels() done
[16:55:45.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C0.dat
[16:55:45.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C1.dat
[16:55:45.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C2.dat
[16:55:45.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C3.dat
[16:55:45.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C4.dat
[16:55:45.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C5.dat
[16:55:45.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C6.dat
[16:55:45.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C7.dat
[16:55:45.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C8.dat
[16:55:45.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C9.dat
[16:55:45.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C10.dat
[16:55:45.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C11.dat
[16:55:45.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C12.dat
[16:55:45.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C13.dat
[16:55:45.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C14.dat
[16:55:45.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//trimParameters35_C15.dat
[16:55:45.515] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-15_FPIXTest-17C-FNAL-161019-1034-150V_2016-10-19_10h34m_1476891274/000_FPIXTest_p17//defaultMaskFile.dat
[16:55:45.525] INFO: enter test to run
[16:56:18.182] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:56:18.182] INFO: running: xray
[16:56:18.183] INFO: ----------------------------------------------------------------------
[16:56:18.183] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:56:18.183] INFO: ----------------------------------------------------------------------
[16:56:19.146] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:56:30.805] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:57:00.580] INFO: Resuming triggers.
[16:57:12.238] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:57:41.759] INFO: Resuming triggers.
[16:57:53.418] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:58:20.469] INFO: Resuming triggers.
[16:58:32.129] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:59:01.767] INFO: Resuming triggers.
[16:59:13.425] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[16:59:42.665] INFO: Resuming triggers.
[16:59:54.323] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:00:24.313] INFO: Resuming triggers.
[17:00:35.973] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:01:05.847] INFO: Resuming triggers.
[17:01:17.509] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:01:47.326] INFO: Resuming triggers.
[17:01:54.396] INFO: data taking finished, elapsed time: 100 seconds.
[17:02:12.612] INFO: PixTest:: pg_setup set to default.
[17:02:12.615] INFO: PixTestXray::doPhRun() done
[17:02:12.899] INFO: enter test to run
[17:03:05.979] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:03:05.979] INFO: running: xray
[17:03:05.981] INFO: ----------------------------------------------------------------------
[17:03:05.981] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:03:05.981] INFO: ----------------------------------------------------------------------
[17:03:06.944] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:03:13.837] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:03:45.040] INFO: Resuming triggers.
[17:03:51.931] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:04:23.642] INFO: Resuming triggers.
[17:04:30.533] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[17:05:02.567] INFO: Resuming triggers.
[17:05:09.458] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[17:05:41.078] INFO: Resuming triggers.
[17:05:47.966] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:06:19.194] INFO: Resuming triggers.
[17:06:26.084] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[17:06:57.551] INFO: Resuming triggers.
[17:07:04.440] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[17:07:35.490] INFO: Resuming triggers.
[17:07:42.378] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[17:08:12.823] INFO: Resuming triggers.
[17:08:19.711] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[17:08:50.031] INFO: Resuming triggers.
[17:08:56.919] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[17:09:27.175] INFO: Resuming triggers.
[17:09:34.065] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[17:10:04.552] INFO: Resuming triggers.
[17:10:11.443] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[17:10:41.793] INFO: Resuming triggers.
[17:10:48.685] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[17:11:19.310] INFO: Resuming triggers.
[17:11:26.202] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[17:11:56.754] INFO: Resuming triggers.
[17:12:00.644] INFO: data taking finished, elapsed time: 100 seconds.
[17:12:17.959] INFO: PixTest:: pg_setup set to default.
[17:12:17.963] INFO: PixTestXray::doPhRun() done
[17:12:18.132] INFO: enter test to run
[17:13:05.535] INFO: test: HighRate no parameter change
[17:13:05.535] INFO: running: highrate
[17:13:05.589] INFO: ----------------------------------------------------------------------
[17:13:05.589] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:13:05.589] INFO: ----------------------------------------------------------------------
[17:13:05.769] INFO: Expecting 768 events.
[17:13:06.903] INFO: 768 events read in total (418ms).
[17:13:06.904] INFO: Test took 1270ms.
[17:13:07.707] INFO: Expecting 41600 events.
[17:13:10.820] INFO: 41600 events read in total (2586ms).
[17:13:10.821] INFO: Test took 3909ms.
[17:13:10.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:11.583] INFO: Expecting 41600 events.
[17:13:14.781] INFO: 41600 events read in total (2671ms).
[17:13:14.781] INFO: Test took 3908ms.
[17:13:14.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:15.540] INFO: Expecting 41600 events.
[17:13:18.754] INFO: 41600 events read in total (2688ms).
[17:13:18.755] INFO: Test took 3923ms.
[17:13:18.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:19.514] INFO: Expecting 41600 events.
[17:13:22.740] INFO: 41600 events read in total (2699ms).
[17:13:22.741] INFO: Test took 3934ms.
[17:13:22.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:23.500] INFO: Expecting 41600 events.
[17:13:26.723] INFO: 41600 events read in total (2696ms).
[17:13:26.724] INFO: Test took 3932ms.
[17:13:26.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:27.482] INFO: Expecting 41600 events.
[17:13:30.709] INFO: 41600 events read in total (2700ms).
[17:13:30.710] INFO: Test took 3935ms.
[17:13:30.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:31.471] INFO: Expecting 41600 events.
[17:13:34.704] INFO: 41600 events read in total (2706ms).
[17:13:34.705] INFO: Test took 3943ms.
[17:13:34.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:35.465] INFO: Expecting 41600 events.
[17:13:38.649] INFO: 41600 events read in total (2657ms).
[17:13:38.650] INFO: Test took 3893ms.
[17:13:38.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:39.404] INFO: Expecting 41600 events.
[17:13:42.651] INFO: 41600 events read in total (2720ms).
[17:13:42.652] INFO: Test took 3951ms.
[17:13:42.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:43.413] INFO: Expecting 41600 events.
[17:13:46.656] INFO: 41600 events read in total (2716ms).
[17:13:46.657] INFO: Test took 3953ms.
[17:13:46.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:47.414] INFO: Expecting 41600 events.
[17:13:50.664] INFO: 41600 events read in total (2723ms).
[17:13:50.665] INFO: Test took 3956ms.
[17:13:50.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:51.424] INFO: Expecting 41600 events.
[17:13:54.706] INFO: 41600 events read in total (2755ms).
[17:13:54.707] INFO: Test took 3992ms.
[17:13:54.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:55.461] INFO: Expecting 41600 events.
[17:13:58.771] INFO: 41600 events read in total (2784ms).
[17:13:58.773] INFO: Test took 4014ms.
[17:13:58.806] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:59.526] INFO: Expecting 41600 events.
[17:14:02.819] INFO: 41600 events read in total (2766ms).
[17:14:02.820] INFO: Test took 3995ms.
[17:14:02.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:03.577] INFO: Expecting 41600 events.
[17:14:06.821] INFO: 41600 events read in total (2717ms).
[17:14:06.822] INFO: Test took 3951ms.
[17:14:06.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:07.564] INFO: Expecting 41600 events.
[17:14:10.929] INFO: 41600 events read in total (2838ms).
[17:14:10.930] INFO: Test took 4038ms.
[17:14:10.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:11.674] INFO: Expecting 41600 events.
[17:14:14.993] INFO: 41600 events read in total (2793ms).
[17:14:14.994] INFO: Test took 4014ms.
[17:14:15.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:15.733] INFO: Expecting 41600 events.
[17:14:18.922] INFO: 41600 events read in total (2662ms).
[17:14:18.923] INFO: Test took 3878ms.
[17:14:18.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:19.676] INFO: Expecting 41600 events.
[17:14:22.924] INFO: 41600 events read in total (2721ms).
[17:14:22.925] INFO: Test took 3951ms.
[17:14:22.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:23.673] INFO: Expecting 41600 events.
[17:14:26.734] INFO: 41600 events read in total (2534ms).
[17:14:26.735] INFO: Test took 3754ms.
[17:14:26.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:27.123] INFO: enter test to run
[17:15:40.678] INFO: test: HighRate no parameter change
[17:15:40.678] INFO: running: highrate
[17:15:40.679] INFO: ----------------------------------------------------------------------
[17:15:40.679] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:15:40.679] INFO: ----------------------------------------------------------------------
[17:15:41.294] INFO: Expecting 208000 events.
[17:15:53.359] INFO: 208000 events read in total (11538ms).
[17:15:53.362] INFO: Test took 12675ms.
[17:15:53.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:53.756] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:15:53.756] INFO: number of red-efficiency pixels: 82 46 82 106 138 114 111 91 100 126 172 140 103 74 21 26
[17:15:53.756] INFO: number of X-ray hits detected: 64482 40700 60127 96542 100545 104814 104700 74097 74343 102583 101107 86655 87169 51154 20770 23174
[17:15:53.756] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:15:53.756] INFO: number of Vcal hits detected: 207914 207953 207916 207892 207860 207883 207884 207909 207897 207868 207822 207859 207896 207925 207979 207974
[17:15:53.756] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:15:53.756] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:15:53.756] INFO: X-ray hit rate [MHz/cm2]: 18.9 11.9 17.6 28.3 29.5 30.7 30.7 21.7 21.8 30.1 29.6 25.4 25.5 15.0 6.1 6.8
[17:15:53.756] INFO: PixTestHighRate::doXPixelAlive() done
[17:15:53.808] INFO: PixTest:: pg_setup set to default.
[17:15:53.823] INFO: enter test to run
[17:16:21.405] INFO: test: HighRate no parameter change
[17:16:21.406] INFO: running: highrate
[17:16:21.407] INFO: ----------------------------------------------------------------------
[17:16:21.407] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:16:21.407] INFO: ----------------------------------------------------------------------
[17:16:22.022] INFO: Expecting 208000 events.
[17:16:35.545] INFO: 208000 events read in total (12996ms).
[17:16:35.550] INFO: Test took 14135ms.
[17:16:35.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:36.137] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:16:36.137] INFO: number of red-efficiency pixels: 263 109 230 380 338 362 367 276 295 367 484 355 361 189 66 66
[17:16:36.137] INFO: number of X-ray hits detected: 131875 82907 121934 198647 206170 214715 214683 152380 151872 210661 207385 177955 178238 104537 43589 48181
[17:16:36.137] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:16:36.137] INFO: number of Vcal hits detected: 207709 207886 207753 207578 207651 207614 207606 207706 207685 207596 207471 207621 207609 207798 207934 207933
[17:16:36.137] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[17:16:36.137] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[17:16:36.137] INFO: X-ray hit rate [MHz/cm2]: 38.7 24.3 35.7 58.2 60.4 62.9 62.9 44.7 44.5 61.7 60.8 52.2 52.2 30.6 12.8 14.1
[17:16:36.137] INFO: PixTestHighRate::doXPixelAlive() done
[17:16:36.183] INFO: PixTest:: pg_setup set to default.
[17:16:36.199] INFO: enter test to run
[17:16:58.197] INFO: test: HighRate no parameter change
[17:16:58.197] INFO: running: highrate
[17:16:58.198] INFO: ----------------------------------------------------------------------
[17:16:58.198] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:16:58.198] INFO: ----------------------------------------------------------------------
[17:16:58.820] INFO: Expecting 208000 events.
[17:17:14.232] INFO: 208000 events read in total (14885ms).
[17:17:14.239] INFO: Test took 16032ms.
[17:17:14.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:15.021] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:17:15.021] INFO: number of red-efficiency pixels: 570 234 561 852 758 896 850 713 619 863 1103 823 799 442 85 61
[17:17:15.021] INFO: number of X-ray hits detected: 200221 125524 186284 301127 312707 327986 324784 230030 230764 319923 314247 270176 272480 160017 65146 73437
[17:17:15.021] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:17:15.021] INFO: number of Vcal hits detected: 207290 207749 207308 206978 207122 206950 206959 207139 207288 206949 206597 207007 207079 207457 207915 207937
[17:17:15.021] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.6 99.5 99.5 99.6 99.7 99.5 99.4 99.6 99.6 99.8 100.0 100.0
[17:17:15.021] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.6 99.5 99.5 99.6 99.7 99.5 99.3 99.5 99.6 99.7 100.0 100.0
[17:17:15.021] INFO: X-ray hit rate [MHz/cm2]: 58.7 36.8 54.6 88.3 91.7 96.1 95.2 67.4 67.6 93.8 92.1 79.2 79.9 46.9 19.1 21.5
[17:17:15.021] INFO: PixTestHighRate::doXPixelAlive() done
[17:17:15.069] INFO: PixTest:: pg_setup set to default.
[17:17:15.087] INFO: enter test to run
[17:17:33.461] INFO: test: exit no parameter change
[17:17:34.041] QUIET: Connection to board 30 closed.
[17:17:34.067] INFO: pXar: this is the end, my friend