[14:35:21.083] INFO: *** Welcome to pxar ***
[14:35:21.083] INFO: *** Today: 2016/09/28
[14:35:21.103] INFO: *** Version: v1.9.0-818-g96727
[14:35:21.103] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C15.dat
[14:35:21.126] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:35:21.126] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:35:21.137] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:35:21.293] INFO: clk: 4
[14:35:21.293] INFO: ctr: 4
[14:35:21.293] INFO: sda: 19
[14:35:21.293] INFO: tin: 9
[14:35:21.293] INFO: level: 15
[14:35:21.293] INFO: triggerdelay: 0
[14:35:21.293] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:35:21.293] INFO: Log level: INFO
[14:35:21.310] QUIET: Connection to board DTB_WREKRL opened.
[14:35:21.314] 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:35:21.316] INFO: RPC call hashes of host and DTB match: 398089610
[14:35:22.851] INFO: DUT info:
[14:35:22.851] INFO: The DUT currently contains the following objects:
[14:35:22.851] INFO: 2 TBM Cores tbm08c (2 ON)
[14:35:22.851] INFO: TBM Core alpha (0): 7 registers set
[14:35:22.851] INFO: TBM Core beta (1): 7 registers set
[14:35:22.851] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:35:22.851] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.851] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.851] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.851] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:22.852] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:35:23.255] INFO: enter 'restricted' command line mode
[14:35:23.255] INFO: enter test to run
[14:35:45.706] INFO: test: PixelAlive no parameter change
[14:35:45.706] INFO: running: pixelalive
[14:35:45.716] INFO: ----------------------------------------------------------------------
[14:35:45.716] 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:35:45.716] INFO: ----------------------------------------------------------------------
[14:35:46.037] INFO: Expecting 41600 events.
[14:35:50.357] INFO: 41600 events read in total (3602ms).
[14:35:50.527] INFO: Test took 4809ms.
[14:35:50.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:50.819] INFO: PixTestAlive::aliveTest() done
[14:35:50.819] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:35:50.852] INFO: enter test to run
[14:35:58.586] INFO: test: timing no parameter change
[14:35:58.586] INFO: running: timing
[14:35:58.590] INFO: ######################################################################
[14:35:58.590] INFO: PixTestTiming::doTest()
[14:35:58.590] INFO: ######################################################################
[14:35:58.590] INFO: ----------------------------------------------------------------------
[14:35:58.590] INFO: PixTestTiming::TBMPhaseScan()
[14:35:58.590] INFO: ----------------------------------------------------------------------
[14:42:13.224] INFO: TBM Phase Settings: 240
[14:42:13.224] INFO: 400MHz Phase: 4
[14:42:13.224] INFO: 160MHz Phase: 7
[14:42:13.224] INFO: Functional Phase Area: 5
[14:42:13.227] INFO: Test took 374638 ms.
[14:42:13.228] INFO: PixTestTiming::TBMPhaseScan() done.
[14:42:13.228] INFO: ----------------------------------------------------------------------
[14:42:13.228] INFO: PixTestTiming::ROCDelayScan()
[14:42:13.228] INFO: ----------------------------------------------------------------------
[14:44:57.777] INFO: ROC Delay Settings: 228
[14:44:57.777] INFO: ROC Header-Trailer/Token Delay: 11
[14:44:57.777] INFO: ROC Port 0 Delay: 4
[14:44:57.777] INFO: ROC Port 1 Delay: 4
[14:44:57.777] INFO: Functional ROC Area: 5
[14:44:57.780] INFO: Test took 164552 ms.
[14:44:57.781] INFO: PixTestTiming::ROCDelayScan() done.
[14:44:57.781] INFO: ----------------------------------------------------------------------
[14:44:57.781] INFO: PixTestTiming::TimingTest()
[14:44:57.781] INFO: ----------------------------------------------------------------------
[14:45:13.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:28.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:44.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:58.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:13.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:28.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:43.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:58.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:13.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:28.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:29.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: Read back bit status: 1
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: Timings are good!
[14:47:29.220] INFO: ----------------------------------------------------------------------
[14:47:29.220] INFO: Test took 151439 ms.
[14:47:29.220] INFO: PixTestTiming::TimingTest() done.
[14:47:29.237] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:47:29.237] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:47:29.237] INFO: PixTestTiming::doTest took 690651 ms.
[14:47:29.237] INFO: PixTestTiming::doTest() done
[14:47:29.237] INFO: Write out TBMPhaseScan_0_V0
[14:47:29.238] INFO: Write out TBMPhaseScan_1_V0
[14:47:29.238] INFO: Write out CombinedTBMPhaseScan_V0
[14:47:29.253] INFO: Write out ROCDelayScan3_V0
[14:47:29.254] INFO: enter test to run
[14:49:02.613] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:49:02.613] INFO: running: highrate
[14:49:02.637] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:49:02.942] INFO: ----------------------------------------------------------------------
[14:49:02.942] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:49:02.942] INFO: ----------------------------------------------------------------------
[14:49:02.942] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:49:02.942] INFO: edge/corner pixel THR is adjusted
[14:49:02.942] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:49:03.900] INFO: Collecting data for 5 seconds...
[14:49:08.916] INFO: Done with hot pixel readout
[14:49:20.690] INFO: PixTest:: pg_setup set to default.

[14:49:20.691] INFO: 4 hot pixels found in step 0
[14:49:21.684] INFO: Collecting data for 5 seconds...
[14:49:26.699] INFO: Done with hot pixel readout
[14:49:38.464] INFO: PixTest:: pg_setup set to default.


[14:49:38.465] INFO: 9 hot pixels found in step 1
[14:49:39.457] INFO: Collecting data for 5 seconds...
[14:49:44.472] INFO: Done with hot pixel readout
[14:49:56.221] INFO: PixTest:: pg_setup set to default.



[14:49:56.222] INFO: 7 hot pixels found in step 2
[14:49:57.215] INFO: Collecting data for 5 seconds...
[14:50:02.232] INFO: Done with hot pixel readout
[14:50:13.878] INFO: PixTest:: pg_setup set to default.


[14:50:13.879] INFO: 6 hot pixels found in step 3
[14:50:14.872] INFO: Collecting data for 5 seconds...
[14:50:19.888] INFO: Done with hot pixel readout
[14:50:31.574] INFO: PixTest:: pg_setup set to default.


[14:50:31.575] INFO: 6 hot pixels found in step 4
[14:50:32.567] INFO: Collecting data for 5 seconds...
[14:50:37.583] INFO: Done with hot pixel readout
[14:50:49.327] INFO: PixTest:: pg_setup set to default.


[14:50:49.329] INFO: 2 hot pixels found in step 5
[14:50:49.365] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:50:49.368] INFO: PixTest::trimHotPixels() done
[14:50:49.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[14:50:49.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[14:50:49.387] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[14:50:49.392] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[14:50:49.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[14:50:49.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[14:50:49.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[14:50:49.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[14:50:49.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[14:50:49.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[14:50:49.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[14:50:49.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[14:50:49.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[14:50:49.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[14:50:49.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[14:50:49.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:50:49.460] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:50:49.470] INFO: enter test to run
[14:51:13.524] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:51:13.524] INFO: running: highrate
[14:51:13.528] INFO: ----------------------------------------------------------------------
[14:51:13.528] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:51:13.529] INFO: ----------------------------------------------------------------------
[14:51:13.529] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:51:13.529] INFO: edge/corner pixel THR is adjusted
[14:51:13.529] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:51:14.487] INFO: Collecting data for 1 seconds...
[14:51:15.490] INFO: Done with hot pixel readout
[14:51:19.499] INFO: PixTest:: pg_setup set to default.
[14:51:19.500] INFO: 0 hot pixels found in step 0
[14:51:19.505] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:51:19.597] INFO: PixTest::trimHotPixels() done
[14:51:19.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[14:51:19.615] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[14:51:19.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[14:51:19.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[14:51:19.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[14:51:19.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[14:51:19.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[14:51:19.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[14:51:19.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[14:51:19.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[14:51:19.664] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[14:51:19.669] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[14:51:19.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[14:51:19.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[14:51:19.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[14:51:19.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[14:51:19.695] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-07_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[14:51:19.704] INFO: enter test to run
[14:52:02.796] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:52:02.796] INFO: running: xray
[14:52:02.797] INFO: ----------------------------------------------------------------------
[14:52:02.797] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:52:02.797] INFO: ----------------------------------------------------------------------
[14:52:03.761] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:52:15.346] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:52:44.847] INFO: Resuming triggers.
[14:52:56.430] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:53:26.192] INFO: Resuming triggers.
[14:53:37.780] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:54:07.491] INFO: Resuming triggers.
[14:54:19.080] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:54:48.632] INFO: Resuming triggers.
[14:55:00.225] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:55:29.205] INFO: Resuming triggers.
[14:55:40.796] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:56:11.057] INFO: Resuming triggers.
[14:56:22.646] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:56:52.841] INFO: Resuming triggers.
[14:57:04.427] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:57:34.636] INFO: Resuming triggers.
[14:57:42.297] INFO: data taking finished, elapsed time: 100 seconds.
[14:58:01.942] INFO: PixTest:: pg_setup set to default.
[14:58:01.945] INFO: PixTestXray::doPhRun() done
[14:58:02.134] INFO: enter test to run
[15:00:22.200] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:00:22.200] INFO: running: xray
[15:00:22.201] INFO: ----------------------------------------------------------------------
[15:00:22.201] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:00:22.201] INFO: ----------------------------------------------------------------------
[15:00:23.174] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:00:29.986] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:01:00.232] INFO: Resuming triggers.
[15:01:07.042] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:01:37.252] INFO: Resuming triggers.
[15:01:44.061] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:02:14.174] INFO: Resuming triggers.
[15:02:20.988] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:02:51.277] INFO: Resuming triggers.
[15:02:58.088] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:03:28.245] INFO: Resuming triggers.
[15:03:35.057] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[15:04:05.273] INFO: Resuming triggers.
[15:04:12.085] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:04:42.331] INFO: Resuming triggers.
[15:04:49.144] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[15:05:19.378] INFO: Resuming triggers.
[15:05:26.191] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:05:57.054] INFO: Resuming triggers.
[15:06:03.866] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:06:34.853] INFO: Resuming triggers.
[15:06:41.666] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[15:07:12.473] INFO: Resuming triggers.
[15:07:19.286] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[15:07:49.785] INFO: Resuming triggers.
[15:07:56.596] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:08:27.506] INFO: Resuming triggers.
[15:08:34.320] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:09:05.332] INFO: Resuming triggers.
[15:09:10.315] INFO: data taking finished, elapsed time: 100 seconds.
[15:09:33.943] INFO: PixTest:: pg_setup set to default.
[15:09:33.946] INFO: PixTestXray::doPhRun() done
[15:09:34.098] INFO: enter test to run
[15:11:16.892] INFO: test: HighRate no parameter change
[15:11:16.892] INFO: running: highrate
[15:11:16.909] INFO: ----------------------------------------------------------------------
[15:11:16.909] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:11:16.909] INFO: ----------------------------------------------------------------------
[15:11:17.064] INFO: Expecting 768 events.
[15:11:18.198] INFO: 768 events read in total (419ms).
[15:11:18.198] INFO: Test took 1268ms.
[15:11:18.002] INFO: Expecting 41600 events.
[15:11:22.112] INFO: 41600 events read in total (2584ms).
[15:11:22.113] INFO: Test took 3906ms.
[15:11:22.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:22.874] INFO: Expecting 41600 events.
[15:11:26.063] INFO: 41600 events read in total (2663ms).
[15:11:26.064] INFO: Test took 3900ms.
[15:11:26.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:26.825] INFO: Expecting 41600 events.
[15:11:30.037] INFO: 41600 events read in total (2685ms).
[15:11:30.038] INFO: Test took 3923ms.
[15:11:30.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:30.798] INFO: Expecting 41600 events.
[15:11:34.031] INFO: 41600 events read in total (2706ms).
[15:11:34.032] INFO: Test took 3942ms.
[15:11:34.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:34.789] INFO: Expecting 41600 events.
[15:11:38.027] INFO: 41600 events read in total (2711ms).
[15:11:38.028] INFO: Test took 3944ms.
[15:11:38.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:38.785] INFO: Expecting 41600 events.
[15:11:42.013] INFO: 41600 events read in total (2701ms).
[15:11:42.014] INFO: Test took 3934ms.
[15:11:42.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:42.773] INFO: Expecting 41600 events.
[15:11:46.019] INFO: 41600 events read in total (2720ms).
[15:11:46.020] INFO: Test took 3954ms.
[15:11:46.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:46.777] INFO: Expecting 41600 events.
[15:11:50.017] INFO: 41600 events read in total (2713ms).
[15:11:50.018] INFO: Test took 3946ms.
[15:11:50.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:50.777] INFO: Expecting 41600 events.
[15:11:53.973] INFO: 41600 events read in total (2670ms).
[15:11:53.974] INFO: Test took 3903ms.
[15:11:54.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:54.728] INFO: Expecting 41600 events.
[15:11:57.947] INFO: 41600 events read in total (2692ms).
[15:11:57.948] INFO: Test took 3922ms.
[15:11:57.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:58.705] INFO: Expecting 41600 events.
[15:12:01.943] INFO: 41600 events read in total (2711ms).
[15:12:01.944] INFO: Test took 3944ms.
[15:12:01.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:02.701] INFO: Expecting 41600 events.
[15:12:05.918] INFO: 41600 events read in total (2691ms).
[15:12:05.919] INFO: Test took 3923ms.
[15:12:05.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:06.679] INFO: Expecting 41600 events.
[15:12:09.912] INFO: 41600 events read in total (2706ms).
[15:12:09.913] INFO: Test took 3943ms.
[15:12:09.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:10.671] INFO: Expecting 41600 events.
[15:12:13.881] INFO: 41600 events read in total (2683ms).
[15:12:13.882] INFO: Test took 3918ms.
[15:12:13.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:14.638] INFO: Expecting 41600 events.
[15:12:17.866] INFO: 41600 events read in total (2701ms).
[15:12:17.867] INFO: Test took 3933ms.
[15:12:17.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:18.623] INFO: Expecting 41600 events.
[15:12:21.852] INFO: 41600 events read in total (2702ms).
[15:12:21.853] INFO: Test took 3934ms.
[15:12:21.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:22.612] INFO: Expecting 41600 events.
[15:12:25.847] INFO: 41600 events read in total (2708ms).
[15:12:25.848] INFO: Test took 3943ms.
[15:12:25.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:26.604] INFO: Expecting 41600 events.
[15:12:29.842] INFO: 41600 events read in total (2711ms).
[15:12:29.843] INFO: Test took 3942ms.
[15:12:29.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:30.598] INFO: Expecting 41600 events.
[15:12:33.815] INFO: 41600 events read in total (2690ms).
[15:12:33.816] INFO: Test took 3921ms.
[15:12:33.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:34.574] INFO: Expecting 41600 events.
[15:12:37.660] INFO: 41600 events read in total (2559ms).
[15:12:37.661] INFO: Test took 3793ms.
[15:12:37.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:38.052] INFO: enter test to run
[15:13:37.443] INFO: test: HighRate no parameter change
[15:13:37.443] INFO: running: highrate
[15:13:37.444] INFO: ----------------------------------------------------------------------
[15:13:37.444] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:13:37.444] INFO: ----------------------------------------------------------------------
[15:13:38.060] INFO: Expecting 208000 events.
[15:13:49.878] INFO: 208000 events read in total (11292ms).
[15:13:49.881] INFO: Test took 12428ms.
[15:13:50.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:50.277] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:13:50.277] INFO: number of red-efficiency pixels: 83 45 76 102 112 148 148 80 77 124 156 101 83 61 27 27
[15:13:50.277] INFO: number of X-ray hits detected: 65999 42228 64277 102022 107677 108714 108350 77922 74979 104980 104597 82714 86401 54158 20239 22313
[15:13:50.277] 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:13:50.277] INFO: number of Vcal hits detected: 207911 207955 207922 207897 207888 207849 207850 207920 207921 207854 207839 207899 207916 207937 207973 207973
[15:13:50.277] 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 100.0 100.0 100.0 100.0 100.0
[15:13:50.277] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:13:50.277] INFO: X-ray hit rate [MHz/cm2]: 19.3 12.4 18.8 29.9 31.6 31.9 31.8 22.8 22.0 30.8 30.7 24.2 25.3 15.9 5.9 6.5
[15:13:50.277] INFO: PixTestHighRate::doXPixelAlive() done
[15:13:50.326] INFO: PixTest:: pg_setup set to default.
[15:13:50.343] INFO: enter test to run
[15:14:14.251] INFO: test: HighRate no parameter change
[15:14:14.251] INFO: running: highrate
[15:14:14.252] INFO: ----------------------------------------------------------------------
[15:14:14.252] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:14:14.252] INFO: ----------------------------------------------------------------------
[15:14:14.872] INFO: Expecting 208000 events.
[15:14:28.374] INFO: 208000 events read in total (12975ms).
[15:14:28.380] INFO: Test took 14118ms.
[15:14:28.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:28.960] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:14:28.960] INFO: number of red-efficiency pixels: 241 106 252 326 362 412 454 330 225 374 480 299 353 216 43 59
[15:14:28.960] INFO: number of X-ray hits detected: 133928 85078 130288 206606 217480 219568 218804 158511 152797 212830 213465 168107 175880 109618 41113 45661
[15:14:28.960] 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:14:28.960] INFO: number of Vcal hits detected: 207722 207887 207726 207656 207610 207557 207501 207644 207770 207577 207474 207682 207634 207773 207956 207938
[15:14:28.960] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:14:28.960] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[15:14:28.960] INFO: X-ray hit rate [MHz/cm2]: 39.3 24.9 38.2 60.6 63.7 64.4 64.1 46.5 44.8 62.4 62.6 49.3 51.6 32.1 12.1 13.4
[15:14:28.961] INFO: PixTestHighRate::doXPixelAlive() done
[15:14:29.012] INFO: PixTest:: pg_setup set to default.
[15:14:29.024] INFO: enter test to run
[15:14:53.650] INFO: test: HighRate no parameter change
[15:14:53.650] INFO: running: highrate
[15:14:53.652] INFO: ----------------------------------------------------------------------
[15:14:53.652] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:14:53.652] INFO: ----------------------------------------------------------------------
[15:14:54.263] INFO: Expecting 208000 events.
[15:15:09.645] INFO: 208000 events read in total (14855ms).
[15:15:09.652] INFO: Test took 15990ms.
[15:15:10.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:10.437] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:15:10.437] INFO: number of red-efficiency pixels: 512 190 585 747 876 960 1092 808 528 921 1135 686 815 467 88 65
[15:15:10.437] INFO: number of X-ray hits detected: 204072 131077 199886 315557 334543 335177 333786 240405 233659 326405 325548 257439 268546 167711 63721 70006
[15:15:10.437] 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:15:10.437] INFO: number of Vcal hits detected: 207358 207795 207202 207160 206972 206810 206627 206963 207392 206867 206549 207207 207048 207440 207910 207931
[15:15:10.437] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.5 99.5 99.4 99.5 99.7 99.5 99.4 99.7 99.6 99.8 100.0 100.0
[15:15:10.437] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.6 99.5 99.4 99.3 99.5 99.7 99.5 99.3 99.6 99.5 99.7 100.0 100.0
[15:15:10.437] INFO: X-ray hit rate [MHz/cm2]: 59.8 38.4 58.6 92.5 98.1 98.2 97.8 70.5 68.5 95.7 95.4 75.5 78.7 49.2 18.7 20.5
[15:15:10.437] INFO: PixTestHighRate::doXPixelAlive() done
[15:15:10.489] INFO: PixTest:: pg_setup set to default.
[15:15:10.506] INFO: enter test to run
[15:15:13.794] INFO: test: exit no parameter change
[15:15:14.240] QUIET: Connection to board 33 closed.
[15:15:14.254] INFO: pXar: this is the end, my friend