[11:15:09.914] INFO: *** Welcome to pxar ***
[11:15:09.914] INFO: *** Today: 2016/05/05
[11:15:09.945] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:15:09.945] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C15.dat
[11:15:09.981] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:15:09.981] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[11:15:09.987] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[11:15:10.126] INFO: clk: 4
[11:15:10.126] INFO: ctr: 4
[11:15:10.126] INFO: sda: 19
[11:15:10.126] INFO: tin: 9
[11:15:10.126] INFO: level: 15
[11:15:10.126] INFO: triggerdelay: 0
[11:15:10.126] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:15:10.126] INFO: Log level: INFO
[11:15:10.144] QUIET: Connection to board DTB_WREK4U opened.
[11:15:10.148] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[11:15:10.151] INFO: RPC call hashes of host and DTB match: 398089610
[11:15:11.677] INFO: DUT info:
[11:15:11.677] INFO: The DUT currently contains the following objects:
[11:15:11.677] INFO: 2 TBM Cores tbm08c (2 ON)
[11:15:11.677] INFO: TBM Core alpha (0): 7 registers set
[11:15:11.677] INFO: TBM Core beta (1): 7 registers set
[11:15:11.677] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:15:11.677] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.677] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.677] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.677] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:11.678] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:15:12.081] INFO: enter 'restricted' command line mode
[11:15:12.081] INFO: enter test to run
[11:15:19.072] INFO: test: timing no parameter change
[11:15:19.072] INFO: running: timing
[11:15:19.099] INFO: ######################################################################
[11:15:19.099] INFO: PixTestTiming::doTest()
[11:15:19.104] INFO: ######################################################################
[11:15:19.104] INFO: ----------------------------------------------------------------------
[11:15:19.104] INFO: PixTestTiming::TBMPhaseScan()
[11:15:19.104] INFO: ----------------------------------------------------------------------
[11:20:23.239] INFO: TBM Phase Settings: 244
[11:20:23.239] INFO: 400MHz Phase: 5
[11:20:23.239] INFO: 160MHz Phase: 7
[11:20:23.239] INFO: Functional Phase Area: 3
[11:20:23.249] INFO: Test took 304145 ms.
[11:20:23.249] INFO: PixTestTiming::TBMPhaseScan() done.
[11:20:23.249] INFO: ----------------------------------------------------------------------
[11:20:23.249] INFO: PixTestTiming::ROCDelayScan()
[11:20:23.249] INFO: ----------------------------------------------------------------------
[11:22:21.407] INFO: ROC Delay Settings: 228
[11:22:21.407] INFO: ROC Header-Trailer/Token Delay: 11
[11:22:21.408] INFO: ROC Port 0 Delay: 4
[11:22:21.408] INFO: ROC Port 1 Delay: 4
[11:22:21.408] INFO: Functional ROC Area: 4
[11:22:21.411] INFO: Test took 118162 ms.
[11:22:21.411] INFO: PixTestTiming::ROCDelayScan() done.
[11:22:21.411] INFO: ----------------------------------------------------------------------
[11:22:21.411] INFO: PixTestTiming::TimingTest()
[11:22:21.411] INFO: ----------------------------------------------------------------------
[11:22:37.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:52.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:07.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:22.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:37.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:53.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:08.364] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:23.467] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:38.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:53.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:54.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: Read back bit status: 1
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: Timings are good!
[11:24:54.156] INFO: ----------------------------------------------------------------------
[11:24:54.156] INFO: Test took 152745 ms.
[11:24:54.156] INFO: PixTestTiming::TimingTest() done.
[11:24:54.206] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:24:54.206] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:24:54.207] INFO: PixTestTiming::doTest took 575113 ms.
[11:24:54.207] INFO: PixTestTiming::doTest() done
[11:24:54.207] INFO: Write out TBMPhaseScan_0_V0
[11:24:54.232] INFO: Write out TBMPhaseScan_1_V0
[11:24:54.232] INFO: Write out CombinedTBMPhaseScan_V0
[11:24:54.252] INFO: Write out ROCDelayScan3_V0
[11:24:54.253] INFO: enter test to run
[11:25:18.323] INFO: test: PixelAlive no parameter change
[11:25:18.323] INFO: running: pixelalive
[11:25:18.328] INFO: ----------------------------------------------------------------------
[11:25:18.328] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:25:18.328] INFO: ----------------------------------------------------------------------
[11:25:18.649] INFO: Expecting 41600 events.
[11:25:22.960] INFO: 41600 events read in total (3596ms).
[11:25:22.961] INFO: Test took 4631ms.
[11:25:22.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:23.367] INFO: PixTestAlive::aliveTest() done
[11:25:23.367] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:25:23.370] INFO: enter test to run
[11:26:07.499] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:26:07.499] INFO: running: highrate
[11:26:07.499] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:26:07.730] INFO: ----------------------------------------------------------------------
[11:26:07.730] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:26:07.730] INFO: ----------------------------------------------------------------------
[11:26:07.730] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:26:07.730] INFO: edge/corner pixel THR is adjusted
[11:26:07.730] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:26:08.688] INFO: Collecting data for 5 seconds...
[11:26:13.705] INFO: Done with hot pixel readout
[11:26:25.497] INFO: PixTest:: pg_setup set to default.
[11:26:25.498] INFO: 1 hot pixels found in step 0
[11:26:26.490] INFO: Collecting data for 5 seconds...
[11:26:31.506] INFO: Done with hot pixel readout
[11:26:43.329] INFO: PixTest:: pg_setup set to default.
[11:26:43.330] INFO: 1 hot pixels found in step 1
[11:26:44.323] INFO: Collecting data for 5 seconds...
[11:26:49.340] INFO: Done with hot pixel readout
[11:27:01.076] INFO: PixTest:: pg_setup set to default.
[11:27:01.077] INFO: 1 hot pixels found in step 2
[11:27:02.070] INFO: Collecting data for 5 seconds...
[11:27:07.088] INFO: Done with hot pixel readout
[11:27:18.795] INFO: PixTest:: pg_setup set to default.
[11:27:18.796] INFO: 1 hot pixels found in step 3
[11:27:19.789] INFO: Collecting data for 5 seconds...
[11:27:24.808] INFO: Done with hot pixel readout
[11:27:36.635] INFO: PixTest:: pg_setup set to default.
[11:27:36.635] INFO: 0 hot pixels found in step 4
[11:27:36.673] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:27:36.676] INFO: PixTest::trimHotPixels() done
[11:27:36.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[11:27:36.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[11:27:36.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[11:27:36.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[11:27:36.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[11:27:36.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[11:27:36.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[11:27:36.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[11:27:36.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[11:27:36.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[11:27:36.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[11:27:36.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[11:27:36.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[11:27:36.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[11:27:36.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[11:27:36.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[11:27:36.767] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[11:27:36.777] INFO: enter test to run
[11:28:17.306] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:28:17.306] INFO: running: highrate
[11:28:17.310] INFO: ----------------------------------------------------------------------
[11:28:17.310] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:28:17.310] INFO: ----------------------------------------------------------------------
[11:28:17.310] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:28:17.311] INFO: edge/corner pixel THR is adjusted
[11:28:17.311] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:28:18.268] INFO: Collecting data for 1 seconds...
[11:28:19.272] INFO: Done with hot pixel readout
[11:28:23.290] INFO: PixTest:: pg_setup set to default.
[11:28:23.291] INFO: 0 hot pixels found in step 0
[11:28:23.296] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:28:23.382] INFO: PixTest::trimHotPixels() done
[11:28:23.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[11:28:23.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[11:28:23.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[11:28:23.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[11:28:23.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[11:28:23.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[11:28:23.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[11:28:23.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[11:28:23.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[11:28:23.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[11:28:23.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[11:28:23.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[11:28:23.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[11:28:23.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[11:28:23.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[11:28:23.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[11:28:23.469] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-24_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[11:28:23.479] INFO: enter test to run
[11:28:42.930] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:28:42.930] INFO: running: xray
[11:28:42.931] INFO: ----------------------------------------------------------------------
[11:28:42.931] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:28:42.931] INFO: ----------------------------------------------------------------------
[11:28:43.894] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:28:55.359] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:29:24.324] INFO: Resuming triggers.
[11:29:35.788] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:30:04.981] INFO: Resuming triggers.
[11:30:16.445] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:30:45.721] INFO: Resuming triggers.
[11:30:57.191] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:31:26.490] INFO: Resuming triggers.
[11:31:37.956] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:32:07.311] INFO: Resuming triggers.
[11:32:18.777] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:32:48.070] INFO: Resuming triggers.
[11:32:59.534] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:33:28.829] INFO: Resuming triggers.
[11:33:40.297] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:34:09.602] INFO: Resuming triggers.
[11:34:18.204] INFO: data taking finished, elapsed time: 100 seconds.
[11:34:40.716] INFO: PixTest:: pg_setup set to default.
[11:34:40.719] INFO: PixTestXray::doPhRun() done
[11:34:40.857] INFO: enter test to run
[11:35:11.095] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:35:11.095] INFO: running: xray
[11:35:11.096] INFO: ----------------------------------------------------------------------
[11:35:11.096] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:35:11.096] INFO: ----------------------------------------------------------------------
[11:35:12.060] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:35:18.722] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:35:49.999] INFO: Resuming triggers.
[11:35:56.657] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:36:27.011] INFO: Resuming triggers.
[11:36:33.671] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:37:03.727] INFO: Resuming triggers.
[11:37:10.384] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:37:40.516] INFO: Resuming triggers.
[11:37:47.177] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:38:17.980] INFO: Resuming triggers.
[11:38:24.638] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:38:55.363] INFO: Resuming triggers.
[11:39:02.024] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:39:32.059] INFO: Resuming triggers.
[11:39:38.714] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[11:40:08.769] INFO: Resuming triggers.
[11:40:15.428] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:40:45.524] INFO: Resuming triggers.
[11:40:52.184] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:41:22.260] INFO: Resuming triggers.
[11:41:28.919] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[11:41:59.047] INFO: Resuming triggers.
[11:42:05.706] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:42:35.920] INFO: Resuming triggers.
[11:42:42.578] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[11:43:12.615] INFO: Resuming triggers.
[11:43:19.272] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[11:43:49.280] INFO: Resuming triggers.
[11:43:55.937] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[11:44:26.051] INFO: Resuming triggers.
[11:44:26.502] INFO: data taking finished, elapsed time: 100 seconds.
[11:44:28.924] INFO: PixTest:: pg_setup set to default.
[11:44:28.928] INFO: PixTestXray::doPhRun() done
[11:44:29.074] INFO: enter test to run
[11:45:43.762] INFO: test: HighRate no parameter change
[11:45:43.762] INFO: running: highrate
[11:45:43.764] INFO: ----------------------------------------------------------------------
[11:45:43.764] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:45:43.764] INFO: ----------------------------------------------------------------------
[11:45:43.904] INFO: Expecting 768 events.
[11:45:45.049] INFO: 768 events read in total (422ms).
[11:45:45.049] INFO: Test took 1279ms.
[11:45:45.853] INFO: Expecting 41600 events.
[11:45:49.035] INFO: 41600 events read in total (2656ms).
[11:45:49.036] INFO: Test took 3981ms.
[11:45:49.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:49.787] INFO: Expecting 41600 events.
[11:45:53.158] INFO: 41600 events read in total (2844ms).
[11:45:53.159] INFO: Test took 4070ms.
[11:45:53.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:53.911] INFO: Expecting 41600 events.
[11:45:57.158] INFO: 41600 events read in total (2720ms).
[11:45:57.159] INFO: Test took 3946ms.
[11:45:57.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:57.916] INFO: Expecting 41600 events.
[11:46:01.327] INFO: 41600 events read in total (2884ms).
[11:46:01.328] INFO: Test took 4114ms.
[11:46:01.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:02.065] INFO: Expecting 41600 events.
[11:46:05.348] INFO: 41600 events read in total (2756ms).
[11:46:05.349] INFO: Test took 3949ms.
[11:46:05.385] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:06.094] INFO: Expecting 41600 events.
[11:46:09.409] INFO: 41600 events read in total (2788ms).
[11:46:09.410] INFO: Test took 4006ms.
[11:46:09.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:10.160] INFO: Expecting 41600 events.
[11:46:13.484] INFO: 41600 events read in total (2797ms).
[11:46:13.485] INFO: Test took 4022ms.
[11:46:13.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:14.223] INFO: Expecting 41600 events.
[11:46:17.517] INFO: 41600 events read in total (2767ms).
[11:46:17.518] INFO: Test took 3978ms.
[11:46:17.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:18.268] INFO: Expecting 41600 events.
[11:46:21.597] INFO: 41600 events read in total (2803ms).
[11:46:21.598] INFO: Test took 4026ms.
[11:46:21.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:22.335] INFO: Expecting 41600 events.
[11:46:25.610] INFO: 41600 events read in total (2748ms).
[11:46:25.611] INFO: Test took 3938ms.
[11:46:25.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:26.367] INFO: Expecting 41600 events.
[11:46:29.641] INFO: 41600 events read in total (2747ms).
[11:46:29.642] INFO: Test took 3978ms.
[11:46:29.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:30.397] INFO: Expecting 41600 events.
[11:46:33.687] INFO: 41600 events read in total (2763ms).
[11:46:33.687] INFO: Test took 3990ms.
[11:46:33.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:34.444] INFO: Expecting 41600 events.
[11:46:37.703] INFO: 41600 events read in total (2732ms).
[11:46:37.704] INFO: Test took 3962ms.
[11:46:37.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:38.458] INFO: Expecting 41600 events.
[11:46:41.760] INFO: 41600 events read in total (2776ms).
[11:46:41.761] INFO: Test took 4003ms.
[11:46:41.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:42.517] INFO: Expecting 41600 events.
[11:46:45.780] INFO: 41600 events read in total (2736ms).
[11:46:45.781] INFO: Test took 3966ms.
[11:46:45.817] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:46.536] INFO: Expecting 41600 events.
[11:46:49.980] INFO: 41600 events read in total (2918ms).
[11:46:49.981] INFO: Test took 4146ms.
[11:46:50.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:50.734] INFO: Expecting 41600 events.
[11:46:53.989] INFO: 41600 events read in total (2728ms).
[11:46:53.989] INFO: Test took 3954ms.
[11:46:54.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:54.745] INFO: Expecting 41600 events.
[11:46:58.048] INFO: 41600 events read in total (2776ms).
[11:46:58.049] INFO: Test took 4005ms.
[11:46:58.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:58.808] INFO: Expecting 41600 events.
[11:47:02.039] INFO: 41600 events read in total (2705ms).
[11:47:02.041] INFO: Test took 3937ms.
[11:47:02.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:02.795] INFO: Expecting 41600 events.
[11:47:05.938] INFO: 41600 events read in total (2616ms).
[11:47:05.939] INFO: Test took 3845ms.
[11:47:05.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:06.334] INFO: enter test to run
[11:48:05.401] INFO: test: HighRate no parameter change
[11:48:05.401] INFO: running: highrate
[11:48:05.403] INFO: ----------------------------------------------------------------------
[11:48:05.403] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:48:05.403] INFO: ----------------------------------------------------------------------
[11:48:06.018] INFO: Expecting 208000 events.
[11:48:17.909] INFO: 208000 events read in total (11364ms).
[11:48:17.912] INFO: Test took 12501ms.
[11:48:18.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:18.312] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:48:18.312] INFO: number of red-efficiency pixels: 56 56 96 137 147 131 164 98 110 117 117 96 100 69 32 22
[11:48:18.312] INFO: number of X-ray hits detected: 62789 45109 74271 115850 112529 116041 118275 82828 81717 97671 97728 84733 87735 53197 22592 26417
[11:48:18.312] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:48:18.312] INFO: number of Vcal hits detected: 207943 207894 207902 207858 207845 207866 207832 207902 207890 207882 207882 207902 207900 207931 207968 207978
[11:48:18.312] 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 99.9 100.0 100.0 100.0 100.0 100.0
[11:48:18.312] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:48:18.312] INFO: X-ray hit rate [MHz/cm2]: 18.4 13.2 21.8 34.0 33.0 34.0 34.7 24.3 24.0 28.6 28.6 24.8 25.7 15.6 6.6 7.7
[11:48:18.312] INFO: PixTestHighRate::doXPixelAlive() done
[11:48:18.363] INFO: PixTest:: pg_setup set to default.
[11:48:18.376] INFO: enter test to run
[11:49:28.856] INFO: test: HighRate no parameter change
[11:49:28.856] INFO: running: highrate
[11:49:28.857] INFO: ----------------------------------------------------------------------
[11:49:28.857] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:49:28.857] INFO: ----------------------------------------------------------------------
[11:49:29.469] INFO: Expecting 208000 events.
[11:49:43.223] INFO: 208000 events read in total (13228ms).
[11:49:43.228] INFO: Test took 14364ms.
[11:49:43.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:43.851] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:49:43.851] INFO: number of red-efficiency pixels: 183 150 278 461 545 389 575 369 272 409 325 266 288 194 63 48
[11:49:43.851] INFO: number of X-ray hits detected: 129336 94198 151433 238902 230959 239632 244294 170943 169580 203122 202458 174743 181681 109794 46811 53748
[11:49:43.851] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:49:43.851] INFO: number of Vcal hits detected: 207810 207794 207700 207501 207403 207586 207355 207597 207710 207570 207657 207711 207698 207796 207936 207951
[11:49:43.851] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:49:43.851] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:49:43.852] INFO: X-ray hit rate [MHz/cm2]: 37.9 27.6 44.4 70.0 67.7 70.2 71.6 50.1 49.7 59.5 59.3 51.2 53.3 32.2 13.7 15.8
[11:49:43.852] INFO: PixTestHighRate::doXPixelAlive() done
[11:49:43.898] INFO: PixTest:: pg_setup set to default.
[11:49:43.913] INFO: enter test to run
[11:51:44.080] INFO: test: HighRate no parameter change
[11:51:44.080] INFO: running: highrate
[11:51:44.081] INFO: ----------------------------------------------------------------------
[11:51:44.081] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:51:44.081] INFO: ----------------------------------------------------------------------
[11:51:44.695] INFO: Expecting 208000 events.
[11:52:00.345] INFO: 208000 events read in total (15123ms).
[11:52:00.353] INFO: Test took 16264ms.
[11:52:00.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:01.173] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:52:01.173] INFO: number of red-efficiency pixels: 345 330 600 1089 1273 956 1371 825 587 966 776 519 663 474 81 84
[11:52:01.173] INFO: number of X-ray hits detected: 197494 143280 231014 361434 352676 365057 368787 260238 257499 308706 306339 265741 275723 167039 72309 82638
[11:52:01.173] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:52:01.174] INFO: number of Vcal hits detected: 207612 207590 207227 206628 206358 206839 206161 206948 207338 206821 207090 207402 207259 207443 207918 207913
[11:52:01.174] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.4 99.3 99.5 99.2 99.5 99.7 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[11:52:01.174] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.6 99.3 99.2 99.4 99.1 99.5 99.7 99.4 99.6 99.7 99.6 99.7 100.0 100.0
[11:52:01.174] INFO: X-ray hit rate [MHz/cm2]: 57.9 42.0 67.7 105.9 103.4 107.0 108.1 76.3 75.5 90.5 89.8 77.9 80.8 49.0 21.2 24.2
[11:52:01.174] INFO: PixTestHighRate::doXPixelAlive() done
[11:52:01.218] INFO: PixTest:: pg_setup set to default.
[11:52:01.232] INFO: enter test to run
[11:52:24.799] INFO: test: exit no parameter change
[11:52:25.201] QUIET: Connection to board 32 closed.
[11:52:25.202] INFO: pXar: this is the end, my friend