[15:13:09.454] INFO: *** Welcome to pxar ***
[15:13:09.454] INFO: *** Today: 2016/11/16
[15:13:11.055] INFO: *** Version: v1.9.0-818-g96727
[15:13:11.055] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//dacParameters35_C15.dat
[15:13:11.149] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:13:11.167] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//defaultMaskFile.dat
[15:13:11.189] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C15.dat
[15:13:11.850] INFO: clk: 4
[15:13:11.850] INFO: ctr: 4
[15:13:11.850] INFO: sda: 19
[15:13:11.850] INFO: tin: 9
[15:13:11.850] INFO: level: 15
[15:13:11.850] INFO: triggerdelay: 0
[15:13:11.850] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:13:11.850] INFO: Log level: INFO
[15:13:11.898] QUIET: Connection to board DTB_WREHUL opened.
[15:13:11.901] 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:
------------------------------------------------------
[15:13:11.904] INFO: RPC call hashes of host and DTB match: 398089610
[15:13:13.504] INFO: DUT info:
[15:13:13.504] INFO: The DUT currently contains the following objects:
[15:13:13.504] INFO: 2 TBM Cores tbm08c (2 ON)
[15:13:13.505] INFO: TBM Core alpha (0): 7 registers set
[15:13:13.505] INFO: TBM Core beta (1): 7 registers set
[15:13:13.505] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:13:13.505] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:13.505] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:13:14.013] INFO: enter 'restricted' command line mode
[15:13:14.013] INFO: enter test to run
[15:13:17.946] INFO: test: PixelAlive no parameter change
[15:13:17.946] INFO: running: pixelalive
[15:13:17.983] INFO: ----------------------------------------------------------------------
[15:13:17.983] 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:13:17.983] INFO: ----------------------------------------------------------------------
[15:13:18.309] INFO: Expecting 41600 events.
[15:13:22.647] INFO: 41600 events read in total (3620ms).
[15:13:22.813] INFO: Test took 4828ms.
[15:13:22.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:23.125] INFO: PixTestAlive::aliveTest() done
[15:13:23.125] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 10 0 0 0 0 0 0 0 0 0
[15:13:23.159] INFO: enter test to run
[15:13:59.801] INFO: test: timing no parameter change
[15:13:59.801] INFO: running: timing
[15:13:59.805] INFO: ######################################################################
[15:13:59.805] INFO: PixTestTiming::doTest()
[15:13:59.805] INFO: ######################################################################
[15:13:59.805] INFO: ----------------------------------------------------------------------
[15:13:59.805] INFO: PixTestTiming::TBMPhaseScan()
[15:13:59.805] INFO: ----------------------------------------------------------------------
[15:20:53.899] INFO: TBM Phase Settings: 232
[15:20:53.899] INFO: 400MHz Phase: 2
[15:20:53.899] INFO: 160MHz Phase: 7
[15:20:53.899] INFO: Functional Phase Area: 3
[15:20:53.902] INFO: Test took 414097 ms.
[15:20:53.902] INFO: PixTestTiming::TBMPhaseScan() done.
[15:20:53.902] INFO: ----------------------------------------------------------------------
[15:20:53.902] INFO: PixTestTiming::ROCDelayScan()
[15:20:53.902] INFO: ----------------------------------------------------------------------
[15:23:48.995] INFO: ROC Delay Settings: 228
[15:23:48.995] INFO: ROC Header-Trailer/Token Delay: 11
[15:23:48.995] INFO: ROC Port 0 Delay: 4
[15:23:48.995] INFO: ROC Port 1 Delay: 4
[15:23:48.995] INFO: Functional ROC Area: 6
[15:23:48.998] INFO: Test took 175096 ms.
[15:23:48.998] INFO: PixTestTiming::ROCDelayScan() done.
[15:23:48.998] INFO: ----------------------------------------------------------------------
[15:23:48.999] INFO: PixTestTiming::TimingTest()
[15:23:48.999] INFO: ----------------------------------------------------------------------
[15:24:05.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:20.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:35.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:50.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:05.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:20.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:35.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:50.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:04.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:20.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:20.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:20.583] INFO: ----------------------------------------------------------------------
[15:26:20.583] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:26:20.583] INFO: ----------------------------------------------------------------------
[15:26:20.584] INFO: ----------------------------------------------------------------------
[15:26:20.584] INFO: Read back bit status: 1
[15:26:20.584] INFO: ----------------------------------------------------------------------
[15:26:20.584] INFO: ----------------------------------------------------------------------
[15:26:20.584] INFO: Timings are good!
[15:26:20.584] INFO: ----------------------------------------------------------------------
[15:26:20.584] INFO: Test took 151586 ms.
[15:26:20.584] INFO: PixTestTiming::TimingTest() done.
[15:26:20.605] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:26:20.605] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:26:20.605] INFO: PixTestTiming::doTest took 740803 ms.
[15:26:20.605] INFO: PixTestTiming::doTest() done
[15:26:20.605] INFO: Write out TBMPhaseScan_0_V0
[15:26:20.606] INFO: Write out TBMPhaseScan_1_V0
[15:26:20.606] INFO: Write out CombinedTBMPhaseScan_V0
[15:26:20.637] INFO: Write out ROCDelayScan3_V0
[15:26:20.638] INFO: enter test to run
[15:27:36.460] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:27:36.460] INFO: running: highrate
[15:27:36.531] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:27:37.088] INFO: ----------------------------------------------------------------------
[15:27:37.088] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:27:37.088] INFO: ----------------------------------------------------------------------
[15:27:37.088] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:27:37.088] INFO: edge/corner pixel THR is adjusted
[15:27:37.088] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:27:38.101] INFO: Collecting data for 5 seconds...
[15:27:43.119] INFO: Done with hot pixel readout
[15:27:54.801] INFO: PixTest:: pg_setup set to default.
[15:27:54.802] INFO: 3 hot pixels found in step 0
[15:27:55.795] INFO: Collecting data for 5 seconds...
[15:28:00.813] INFO: Done with hot pixel readout
[15:28:12.567] INFO: PixTest:: pg_setup set to default.
[15:28:12.568] INFO: 2 hot pixels found in step 1
[15:28:13.560] INFO: Collecting data for 5 seconds...
[15:28:18.578] INFO: Done with hot pixel readout
[15:28:30.247] INFO: PixTest:: pg_setup set to default.
[15:28:30.248] INFO: 2 hot pixels found in step 2
[15:28:31.240] INFO: Collecting data for 5 seconds...
[15:28:36.259] INFO: Done with hot pixel readout
[15:28:47.853] INFO: PixTest:: pg_setup set to default.
[15:28:47.854] INFO: 1 hot pixels found in step 3
[15:28:48.846] INFO: Collecting data for 5 seconds...
[15:28:53.864] INFO: Done with hot pixel readout
[15:29:05.512] INFO: PixTest:: pg_setup set to default.
[15:29:05.513] INFO: 1 hot pixels found in step 4
[15:29:06.505] INFO: Collecting data for 5 seconds...
[15:29:11.526] INFO: Done with hot pixel readout
[15:29:23.057] INFO: PixTest:: pg_setup set to default.
[15:29:23.058] INFO: 0 hot pixels found in step 5
[15:29:23.095] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:29:23.098] INFO: PixTest::trimHotPixels() done
[15:29:23.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C0.dat
[15:29:23.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C1.dat
[15:29:23.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C2.dat
[15:29:23.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C3.dat
[15:29:23.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C4.dat
[15:29:23.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C5.dat
[15:29:23.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C6.dat
[15:29:23.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C7.dat
[15:29:23.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C8.dat
[15:29:23.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C9.dat
[15:29:23.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C10.dat
[15:29:23.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C11.dat
[15:29:23.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C12.dat
[15:29:23.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C13.dat
[15:29:23.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C14.dat
[15:29:23.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C15.dat
[15:29:23.221] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//defaultMaskFile.dat
[15:29:23.231] INFO: enter test to run
[15:30:25.531] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:30:25.531] INFO: running: highrate
[15:30:25.535] INFO: ----------------------------------------------------------------------
[15:30:25.535] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:30:25.535] INFO: ----------------------------------------------------------------------
[15:30:25.535] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:30:25.535] INFO: edge/corner pixel THR is adjusted
[15:30:25.535] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:30:26.492] INFO: Collecting data for 1 seconds...
[15:30:27.496] INFO: Done with hot pixel readout
[15:30:31.604] INFO: PixTest:: pg_setup set to default.
[15:30:31.605] INFO: 0 hot pixels found in step 0
[15:30:31.610] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:30:31.692] INFO: PixTest::trimHotPixels() done
[15:30:31.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C0.dat
[15:30:31.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C1.dat
[15:30:31.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C2.dat
[15:30:31.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C3.dat
[15:30:31.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C4.dat
[15:30:31.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C5.dat
[15:30:31.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C6.dat
[15:30:31.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C7.dat
[15:30:31.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C8.dat
[15:30:31.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C9.dat
[15:30:31.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C10.dat
[15:30:31.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C11.dat
[15:30:31.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C12.dat
[15:30:31.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C13.dat
[15:30:31.776] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C14.dat
[15:30:31.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//trimParameters35_C15.dat
[15:30:31.787] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-45_FPIXTest-17C-FNAL-161108-1225-150V_2016-11-08_12h25m_1478629520/000_FPIXTest_p17//defaultMaskFile.dat
[15:30:31.797] INFO: enter test to run
[15:31:13.539] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:31:13.539] INFO: running: xray
[15:31:13.554] INFO: ----------------------------------------------------------------------
[15:31:13.554] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:31:13.554] INFO: ----------------------------------------------------------------------
[15:31:14.518] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:31:25.979] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:31:56.194] INFO: Resuming triggers.
[15:32:07.661] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:32:38.417] INFO: Resuming triggers.
[15:32:49.880] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:33:19.924] INFO: Resuming triggers.
[15:33:31.388] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:34:00.751] INFO: Resuming triggers.
[15:34:12.215] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:34:41.584] INFO: Resuming triggers.
[15:34:53.046] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:35:22.498] INFO: Resuming triggers.
[15:35:33.961] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:36:03.372] INFO: Resuming triggers.
[15:36:14.834] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:36:44.224] INFO: Resuming triggers.
[15:36:52.862] INFO: data taking finished, elapsed time: 100 seconds.
[15:37:15.166] INFO: PixTest:: pg_setup set to default.
[15:37:15.169] INFO: PixTestXray::doPhRun() done
[15:37:15.435] INFO: enter test to run
[15:38:08.744] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:38:08.744] INFO: running: xray
[15:38:08.745] INFO: ----------------------------------------------------------------------
[15:38:08.745] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:38:08.745] INFO: ----------------------------------------------------------------------
[15:38:09.727] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:38:16.364] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:38:46.638] INFO: Resuming triggers.
[15:38:53.279] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:39:23.669] INFO: Resuming triggers.
[15:39:30.306] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:40:00.575] INFO: Resuming triggers.
[15:40:07.216] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:40:38.160] INFO: Resuming triggers.
[15:40:44.798] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:41:15.755] INFO: Resuming triggers.
[15:41:22.393] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:41:53.063] INFO: Resuming triggers.
[15:41:59.706] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:42:30.662] INFO: Resuming triggers.
[15:42:37.299] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:43:08.191] INFO: Resuming triggers.
[15:43:14.829] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:43:45.780] INFO: Resuming triggers.
[15:43:52.420] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:44:23.626] INFO: Resuming triggers.
[15:44:30.263] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:45:01.466] INFO: Resuming triggers.
[15:45:08.106] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:45:40.354] INFO: Resuming triggers.
[15:45:46.993] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:46:18.534] INFO: Resuming triggers.
[15:46:25.172] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:46:56.719] INFO: Resuming triggers.
[15:47:03.356] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:47:34.484] INFO: Resuming triggers.
[15:47:35.264] INFO: data taking finished, elapsed time: 100 seconds.
[15:47:39.518] INFO: PixTest:: pg_setup set to default.
[15:47:39.521] INFO: PixTestXray::doPhRun() done
[15:47:39.762] INFO: enter test to run
[15:51:30.042] INFO: test: HighRate no parameter change
[15:51:30.043] INFO: running: highrate
[15:51:30.060] INFO: ----------------------------------------------------------------------
[15:51:30.060] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:51:30.060] INFO: ----------------------------------------------------------------------
[15:51:30.218] INFO: Expecting 768 events.
[15:51:31.352] INFO: 768 events read in total (419ms).
[15:51:31.353] INFO: Test took 1269ms.
[15:51:32.155] INFO: Expecting 41600 events.
[15:51:35.241] INFO: 41600 events read in total (2559ms).
[15:51:35.242] INFO: Test took 3834ms.
[15:51:35.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:35.005] INFO: Expecting 41600 events.
[15:51:39.200] INFO: 41600 events read in total (2669ms).
[15:51:39.201] INFO: Test took 3911ms.
[15:51:39.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:39.958] INFO: Expecting 41600 events.
[15:51:43.166] INFO: 41600 events read in total (2681ms).
[15:51:43.167] INFO: Test took 3913ms.
[15:51:43.200] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:43.929] INFO: Expecting 41600 events.
[15:51:47.146] INFO: 41600 events read in total (2692ms).
[15:51:47.147] INFO: Test took 3929ms.
[15:51:47.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:47.904] INFO: Expecting 41600 events.
[15:51:51.131] INFO: 41600 events read in total (2700ms).
[15:51:51.132] INFO: Test took 3934ms.
[15:51:51.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:51.890] INFO: Expecting 41600 events.
[15:51:55.126] INFO: 41600 events read in total (2709ms).
[15:51:55.127] INFO: Test took 3945ms.
[15:51:55.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:55.884] INFO: Expecting 41600 events.
[15:51:59.113] INFO: 41600 events read in total (2702ms).
[15:51:59.114] INFO: Test took 3935ms.
[15:51:59.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:59.875] INFO: Expecting 41600 events.
[15:52:03.108] INFO: 41600 events read in total (2706ms).
[15:52:03.109] INFO: Test took 3944ms.
[15:52:03.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:03.868] INFO: Expecting 41600 events.
[15:52:07.102] INFO: 41600 events read in total (2707ms).
[15:52:07.103] INFO: Test took 3943ms.
[15:52:07.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:07.862] INFO: Expecting 41600 events.
[15:52:11.100] INFO: 41600 events read in total (2711ms).
[15:52:11.101] INFO: Test took 3946ms.
[15:52:11.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:11.860] INFO: Expecting 41600 events.
[15:52:15.097] INFO: 41600 events read in total (2710ms).
[15:52:15.098] INFO: Test took 3946ms.
[15:52:15.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:15.858] INFO: Expecting 41600 events.
[15:52:19.091] INFO: 41600 events read in total (2706ms).
[15:52:19.092] INFO: Test took 3943ms.
[15:52:19.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:19.850] INFO: Expecting 41600 events.
[15:52:23.099] INFO: 41600 events read in total (2722ms).
[15:52:23.100] INFO: Test took 3955ms.
[15:52:23.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:23.859] INFO: Expecting 41600 events.
[15:52:27.084] INFO: 41600 events read in total (2698ms).
[15:52:27.085] INFO: Test took 3933ms.
[15:52:27.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:27.843] INFO: Expecting 41600 events.
[15:52:31.068] INFO: 41600 events read in total (2698ms).
[15:52:31.069] INFO: Test took 3932ms.
[15:52:31.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:31.828] INFO: Expecting 41600 events.
[15:52:35.053] INFO: 41600 events read in total (2698ms).
[15:52:35.054] INFO: Test took 3932ms.
[15:52:35.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:35.814] INFO: Expecting 41600 events.
[15:52:39.010] INFO: 41600 events read in total (2669ms).
[15:52:39.011] INFO: Test took 3905ms.
[15:52:39.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:39.767] INFO: Expecting 41600 events.
[15:52:43.009] INFO: 41600 events read in total (2715ms).
[15:52:43.010] INFO: Test took 3947ms.
[15:52:43.043] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:43.769] INFO: Expecting 41600 events.
[15:52:46.001] INFO: 41600 events read in total (2705ms).
[15:52:46.002] INFO: Test took 3941ms.
[15:52:47.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:47.758] INFO: Expecting 41600 events.
[15:52:50.863] INFO: 41600 events read in total (2578ms).
[15:52:50.864] INFO: Test took 3811ms.
[15:52:50.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:51.261] INFO: enter test to run
[15:54:19.865] INFO: test: HighRate no parameter change
[15:54:19.865] INFO: running: highrate
[15:54:19.866] INFO: ----------------------------------------------------------------------
[15:54:19.866] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:54:19.866] INFO: ----------------------------------------------------------------------
[15:54:20.488] INFO: Expecting 208000 events.
[15:54:32.339] INFO: 208000 events read in total (11324ms).
[15:54:32.342] INFO: Test took 12465ms.
[15:54:32.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:32.735] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 10 0 0 0 0 0 0 0 0 0
[15:54:32.750] INFO: number of red-efficiency pixels: 80 65 67 132 160 145 155 100 78 133 104 110 148 55 23 30
[15:54:32.751] INFO: number of X-ray hits detected: 67830 46580 67309 103967 107255 109646 111485 71695 70656 95233 96316 81725 84960 54341 19966 22463
[15:54:32.751] 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:54:32.751] INFO: number of Vcal hits detected: 207920 207933 207882 207865 207838 207852 207332 207898 207921 207864 207894 207884 207845 207942 207977 207969
[15:54:32.751] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[15:54:32.751] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.7 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:54:32.751] INFO: X-ray hit rate [MHz/cm2]: 19.9 13.7 19.7 30.5 31.4 32.1 32.7 21.0 20.7 27.9 28.2 24.0 24.9 15.9 5.9 6.6
[15:54:32.751] INFO: PixTestHighRate::doXPixelAlive() done
[15:54:32.800] INFO: PixTest:: pg_setup set to default.
[15:54:32.813] INFO: enter test to run
[15:54:47.369] INFO: test: HighRate no parameter change
[15:54:47.369] INFO: running: highrate
[15:54:47.370] INFO: ----------------------------------------------------------------------
[15:54:47.370] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:54:47.370] INFO: ----------------------------------------------------------------------
[15:54:47.984] INFO: Expecting 208000 events.
[15:55:01.723] INFO: 208000 events read in total (13212ms).
[15:55:01.728] INFO: Test took 14349ms.
[15:55:02.037] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:02.345] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 10 0 0 0 0 0 0 0 0 0
[15:55:02.345] INFO: number of red-efficiency pixels: 247 180 241 492 537 493 463 300 230 320 338 355 399 192 52 62
[15:55:02.345] INFO: number of X-ray hits detected: 148140 101300 147672 226140 232536 238273 241224 157624 154250 207512 209774 180286 185769 118675 44149 49186
[15:55:02.345] 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:55:02.345] INFO: number of Vcal hits detected: 207731 207815 207693 207451 207406 207458 207003 207671 207754 207664 207647 207613 207566 207795 207947 207936
[15:55:02.345] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:55:02.345] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.5 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:55:02.345] INFO: X-ray hit rate [MHz/cm2]: 43.4 29.7 43.3 66.3 68.2 69.8 70.7 46.2 45.2 60.8 61.5 52.8 54.5 34.8 12.9 14.4
[15:55:02.345] INFO: PixTestHighRate::doXPixelAlive() done
[15:55:02.396] INFO: PixTest:: pg_setup set to default.
[15:55:02.411] INFO: enter test to run
[15:55:17.401] INFO: test: HighRate no parameter change
[15:55:17.401] INFO: running: highrate
[15:55:17.402] INFO: ----------------------------------------------------------------------
[15:55:17.402] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:55:17.402] INFO: ----------------------------------------------------------------------
[15:55:18.023] INFO: Expecting 208000 events.
[15:55:33.858] INFO: 208000 events read in total (15308ms).
[15:55:33.865] INFO: Test took 16454ms.
[15:55:34.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:34.688] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 10 0 0 0 0 0 0 0 0 0
[15:55:34.688] INFO: number of red-efficiency pixels: 587 351 577 1120 1268 1121 1023 678 539 745 746 827 801 412 95 89
[15:55:34.688] INFO: number of X-ray hits detected: 222745 152252 221680 337923 349311 358848 364429 236623 232042 311113 313687 269838 279141 178614 66291 73316
[15:55:34.688] 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:55:34.688] INFO: number of Vcal hits detected: 207265 207608 207245 206606 206359 206571 206227 207125 207365 207142 207162 207018 207067 207530 207902 207910
[15:55:34.688] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.4 99.3 99.4 99.5 99.6 99.7 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[15:55:34.688] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.6 99.3 99.2 99.3 99.1 99.6 99.7 99.6 99.6 99.5 99.6 99.8 100.0 100.0
[15:55:34.688] INFO: X-ray hit rate [MHz/cm2]: 65.3 44.6 65.0 99.0 102.4 105.2 106.8 69.4 68.0 91.2 91.9 79.1 81.8 52.4 19.4 21.5
[15:55:34.688] INFO: PixTestHighRate::doXPixelAlive() done
[15:55:34.734] INFO: PixTest:: pg_setup set to default.
[15:55:34.756] INFO: enter test to run
[15:55:49.072] INFO: test: exit no parameter change
[15:55:50.082] QUIET: Connection to board 30 closed.
[15:55:50.280] INFO: pXar: this is the end, my friend