[14:05:42.677] INFO: *** Welcome to pxar ***
[14:05:42.677] INFO: *** Today: 2016/10/12
[14:05:43.735] INFO: *** Version: v1.9.0-818-g96727
[14:05:43.735] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//dacParameters35_C15.dat
[14:05:43.748] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:05:43.769] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//defaultMaskFile.dat
[14:05:43.795] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C15.dat
[14:05:43.890] INFO: clk: 4
[14:05:43.891] INFO: ctr: 4
[14:05:43.891] INFO: sda: 19
[14:05:43.891] INFO: tin: 9
[14:05:43.891] INFO: level: 15
[14:05:43.891] INFO: triggerdelay: 0
[14:05:43.891] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:05:43.909] INFO: Log level: INFO
[14:05:43.926] QUIET: Connection to board DTB_WREKRL opened.
[14:05:43.929] 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:05:43.932] INFO: RPC call hashes of host and DTB match: 398089610
[14:05:45.476] INFO: DUT info:
[14:05:45.476] INFO: The DUT currently contains the following objects:
[14:05:45.476] INFO: 2 TBM Cores tbm08c (2 ON)
[14:05:45.502] INFO: TBM Core alpha (0): 7 registers set
[14:05:45.502] INFO: TBM Core beta (1): 7 registers set
[14:05:45.502] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:05:45.502] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.502] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:05:45.922] INFO: enter 'restricted' command line mode
[14:05:45.923] INFO: enter test to run
[14:05:48.562] INFO: test: PixelAlive no parameter change
[14:05:48.562] INFO: running: pixelalive
[14:05:48.826] INFO: ----------------------------------------------------------------------
[14:05:48.826] 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:05:48.826] INFO: ----------------------------------------------------------------------
[14:05:49.146] INFO: Expecting 41600 events.
[14:05:53.498] INFO: 41600 events read in total (3634ms).
[14:05:53.655] INFO: Test took 4827ms.
[14:05:53.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:54.096] INFO: PixTestAlive::aliveTest() done
[14:05:54.096] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:05:54.311] INFO: enter test to run
[14:06:00.682] INFO: test: timing no parameter change
[14:06:00.682] INFO: running: timing
[14:06:00.686] INFO: ######################################################################
[14:06:00.686] INFO: PixTestTiming::doTest()
[14:06:00.686] INFO: ######################################################################
[14:06:00.686] INFO: ----------------------------------------------------------------------
[14:06:00.686] INFO: PixTestTiming::TBMPhaseScan()
[14:06:00.686] INFO: ----------------------------------------------------------------------
[14:11:07.158] INFO: TBM Phase Settings: 224
[14:11:07.158] INFO: 400MHz Phase: 0
[14:11:07.158] INFO: 160MHz Phase: 7
[14:11:07.158] INFO: Functional Phase Area: 3
[14:11:07.180] INFO: Test took 306494 ms.
[14:11:07.180] INFO: PixTestTiming::TBMPhaseScan() done.
[14:11:07.180] INFO: ----------------------------------------------------------------------
[14:11:07.180] INFO: PixTestTiming::ROCDelayScan()
[14:11:07.180] INFO: ----------------------------------------------------------------------
[14:13:45.440] INFO: ROC Delay Settings: 228
[14:13:45.440] INFO: ROC Header-Trailer/Token Delay: 11
[14:13:45.440] INFO: ROC Port 0 Delay: 4
[14:13:45.440] INFO: ROC Port 1 Delay: 4
[14:13:45.440] INFO: Functional ROC Area: 3
[14:13:45.443] INFO: Test took 158263 ms.
[14:13:45.443] INFO: PixTestTiming::ROCDelayScan() done.
[14:13:45.444] INFO: ----------------------------------------------------------------------
[14:13:45.444] INFO: PixTestTiming::TimingTest()
[14:13:45.444] INFO: ----------------------------------------------------------------------
[14:14:01.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:16.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:31.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:46.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:02.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:17.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:32.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:47.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:02.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:17.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:17.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: Read back bit status: 1
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: Timings are good!
[14:16:17.916] INFO: ----------------------------------------------------------------------
[14:16:17.916] INFO: Test took 152473 ms.
[14:16:17.916] INFO: PixTestTiming::TimingTest() done.
[14:16:17.916] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:16:17.917] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:16:17.917] INFO: PixTestTiming::doTest took 617235 ms.
[14:16:17.917] INFO: PixTestTiming::doTest() done
[14:16:17.917] INFO: Write out TBMPhaseScan_0_V0
[14:16:17.917] INFO: Write out TBMPhaseScan_1_V0
[14:16:17.917] INFO: Write out CombinedTBMPhaseScan_V0
[14:16:17.935] INFO: Write out ROCDelayScan3_V0
[14:16:17.936] INFO: enter test to run
[14:17:24.350] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:17:24.350] INFO: running: highrate
[14:17:24.383] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:17:24.626] INFO: ----------------------------------------------------------------------
[14:17:24.626] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:17:24.626] INFO: ----------------------------------------------------------------------
[14:17:24.626] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:17:24.642] INFO: edge/corner pixel THR is adjusted
[14:17:24.642] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:17:25.620] INFO: Collecting data for 5 seconds...
[14:17:30.639] INFO: Done with hot pixel readout
[14:17:42.099] INFO: PixTest:: pg_setup set to default.
[14:17:42.100] INFO: 0 hot pixels found in step 0
[14:17:42.134] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:17:42.138] INFO: PixTest::trimHotPixels() done
[14:17:42.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C0.dat
[14:17:42.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C1.dat
[14:17:42.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C2.dat
[14:17:42.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C3.dat
[14:17:42.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C4.dat
[14:17:42.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C5.dat
[14:17:42.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C6.dat
[14:17:42.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C7.dat
[14:17:42.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C8.dat
[14:17:42.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C9.dat
[14:17:42.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C10.dat
[14:17:42.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C11.dat
[14:17:42.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C12.dat
[14:17:42.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C13.dat
[14:17:42.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C14.dat
[14:17:42.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C15.dat
[14:17:42.305] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//defaultMaskFile.dat
[14:17:42.315] INFO: enter test to run
[14:18:06.422] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:18:06.422] INFO: running: highrate
[14:18:06.426] INFO: ----------------------------------------------------------------------
[14:18:06.426] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:18:06.426] INFO: ----------------------------------------------------------------------
[14:18:06.426] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:18:06.426] INFO: edge/corner pixel THR is adjusted
[14:18:06.426] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:18:07.384] INFO: Collecting data for 1 seconds...
[14:18:08.388] INFO: Done with hot pixel readout
[14:18:12.144] INFO: PixTest:: pg_setup set to default.
[14:18:12.145] INFO: 0 hot pixels found in step 0
[14:18:12.151] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:18:12.247] INFO: PixTest::trimHotPixels() done
[14:18:12.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C0.dat
[14:18:12.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C1.dat
[14:18:12.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C2.dat
[14:18:12.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C3.dat
[14:18:12.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C4.dat
[14:18:12.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C5.dat
[14:18:12.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C6.dat
[14:18:12.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C7.dat
[14:18:12.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C8.dat
[14:18:12.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C9.dat
[14:18:12.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C10.dat
[14:18:12.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C11.dat
[14:18:12.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C12.dat
[14:18:12.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C13.dat
[14:18:12.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C14.dat
[14:18:12.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//trimParameters35_C15.dat
[14:18:12.340] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-46_FPIXTest-17C-FNAL-161010-1222-150V_2016-10-10_12h22m_1476120169/000_FPIXTest_p17//defaultMaskFile.dat
[14:18:12.349] INFO: enter test to run
[14:19:07.101] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:19:07.101] INFO: running: xray
[14:19:07.103] INFO: ----------------------------------------------------------------------
[14:19:07.103] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:19:07.103] INFO: ----------------------------------------------------------------------
[14:19:08.078] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:19:20.139] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:19:49.497] INFO: Resuming triggers.
[14:20:01.559] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:20:30.933] INFO: Resuming triggers.
[14:20:42.994] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:21:12.343] INFO: Resuming triggers.
[14:21:24.410] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:21:53.896] INFO: Resuming triggers.
[14:22:05.958] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:22:35.208] INFO: Resuming triggers.
[14:22:47.271] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:23:16.562] INFO: Resuming triggers.
[14:23:28.624] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:23:57.883] INFO: Resuming triggers.
[14:24:09.944] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:24:39.213] INFO: Resuming triggers.
[14:24:43.034] INFO: data taking finished, elapsed time: 100 seconds.
[14:24:52.668] INFO: PixTest:: pg_setup set to default.
[14:24:52.672] INFO: PixTestXray::doPhRun() done
[14:24:52.861] INFO: enter test to run
[14:29:04.673] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:29:04.674] INFO: running: xray
[14:29:04.675] INFO: ----------------------------------------------------------------------
[14:29:04.675] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:29:04.675] INFO: ----------------------------------------------------------------------
[14:29:05.638] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:29:12.847] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:29:43.902] INFO: Resuming triggers.
[14:29:51.109] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:30:22.614] INFO: Resuming triggers.
[14:30:29.823] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:31:00.804] INFO: Resuming triggers.
[14:31:08.009] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:31:39.154] INFO: Resuming triggers.
[14:31:46.362] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:32:17.396] INFO: Resuming triggers.
[14:32:24.605] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:32:54.856] INFO: Resuming triggers.
[14:33:02.063] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[14:33:32.289] INFO: Resuming triggers.
[14:33:39.496] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:34:09.711] INFO: Resuming triggers.
[14:34:16.920] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:34:47.237] INFO: Resuming triggers.
[14:34:54.444] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:35:24.704] INFO: Resuming triggers.
[14:35:31.913] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:36:02.085] INFO: Resuming triggers.
[14:36:09.293] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:36:39.509] INFO: Resuming triggers.
[14:36:46.716] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[14:37:16.937] INFO: Resuming triggers.
[14:37:23.578] INFO: data taking finished, elapsed time: 100 seconds.
[14:37:51.502] INFO: PixTest:: pg_setup set to default.
[14:37:51.505] INFO: PixTestXray::doPhRun() done
[14:37:51.671] INFO: enter test to run
[14:38:28.302] INFO: test: HighRate no parameter change
[14:38:28.302] INFO: running: highrate
[14:38:28.366] INFO: ----------------------------------------------------------------------
[14:38:28.366] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:38:28.366] INFO: ----------------------------------------------------------------------
[14:38:28.538] INFO: Expecting 768 events.
[14:38:29.672] INFO: 768 events read in total (419ms).
[14:38:29.672] INFO: Test took 1270ms.
[14:38:30.476] INFO: Expecting 41600 events.
[14:38:33.475] INFO: 41600 events read in total (2473ms).
[14:38:33.476] INFO: Test took 3752ms.
[14:38:33.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:34.243] INFO: Expecting 41600 events.
[14:38:37.383] INFO: 41600 events read in total (2613ms).
[14:38:37.384] INFO: Test took 3863ms.
[14:38:37.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:38.142] INFO: Expecting 41600 events.
[14:38:41.310] INFO: 41600 events read in total (2642ms).
[14:38:41.311] INFO: Test took 3882ms.
[14:38:41.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:42.071] INFO: Expecting 41600 events.
[14:38:45.275] INFO: 41600 events read in total (2677ms).
[14:38:45.276] INFO: Test took 3917ms.
[14:38:45.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:46.039] INFO: Expecting 41600 events.
[14:38:49.260] INFO: 41600 events read in total (2680ms).
[14:38:49.260] INFO: Test took 3936ms.
[14:38:49.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:50.023] INFO: Expecting 41600 events.
[14:38:53.194] INFO: 41600 events read in total (2645ms).
[14:38:53.195] INFO: Test took 3886ms.
[14:38:53.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:53.957] INFO: Expecting 41600 events.
[14:38:57.164] INFO: 41600 events read in total (2680ms).
[14:38:57.165] INFO: Test took 3922ms.
[14:38:57.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:57.926] INFO: Expecting 41600 events.
[14:39:01.139] INFO: 41600 events read in total (2686ms).
[14:39:01.140] INFO: Test took 3927ms.
[14:39:01.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:01.903] INFO: Expecting 41600 events.
[14:39:05.100] INFO: 41600 events read in total (2670ms).
[14:39:05.101] INFO: Test took 3913ms.
[14:39:05.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:05.865] INFO: Expecting 41600 events.
[14:39:09.057] INFO: 41600 events read in total (2665ms).
[14:39:09.058] INFO: Test took 3910ms.
[14:39:09.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:09.819] INFO: Expecting 41600 events.
[14:39:13.029] INFO: 41600 events read in total (2683ms).
[14:39:13.030] INFO: Test took 3924ms.
[14:39:13.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:13.792] INFO: Expecting 41600 events.
[14:39:16.992] INFO: 41600 events read in total (2673ms).
[14:39:16.993] INFO: Test took 3915ms.
[14:39:17.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:17.756] INFO: Expecting 41600 events.
[14:39:20.950] INFO: 41600 events read in total (2667ms).
[14:39:20.951] INFO: Test took 3910ms.
[14:39:20.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:21.713] INFO: Expecting 41600 events.
[14:39:24.912] INFO: 41600 events read in total (2672ms).
[14:39:24.913] INFO: Test took 3915ms.
[14:39:24.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:25.676] INFO: Expecting 41600 events.
[14:39:28.890] INFO: 41600 events read in total (2687ms).
[14:39:28.891] INFO: Test took 3930ms.
[14:39:28.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:29.650] INFO: Expecting 41600 events.
[14:39:32.905] INFO: 41600 events read in total (2729ms).
[14:39:32.905] INFO: Test took 3967ms.
[14:39:32.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:33.668] INFO: Expecting 41600 events.
[14:39:36.901] INFO: 41600 events read in total (2707ms).
[14:39:36.901] INFO: Test took 3947ms.
[14:39:36.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:37.658] INFO: Expecting 41600 events.
[14:39:40.923] INFO: 41600 events read in total (2738ms).
[14:39:40.924] INFO: Test took 3973ms.
[14:39:40.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:41.679] INFO: Expecting 41600 events.
[14:39:44.914] INFO: 41600 events read in total (2708ms).
[14:39:44.914] INFO: Test took 3941ms.
[14:39:44.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:45.677] INFO: Expecting 41600 events.
[14:39:48.717] INFO: 41600 events read in total (2514ms).
[14:39:48.718] INFO: Test took 3755ms.
[14:39:48.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:49.117] INFO: enter test to run
[14:40:41.388] INFO: test: HighRate no parameter change
[14:40:41.388] INFO: running: highrate
[14:40:41.389] INFO: ----------------------------------------------------------------------
[14:40:41.389] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:40:41.389] INFO: ----------------------------------------------------------------------
[14:40:42.034] INFO: Expecting 208000 events.
[14:40:53.740] INFO: 208000 events read in total (11180ms).
[14:40:53.743] INFO: Test took 12320ms.
[14:40:53.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:54.121] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:40:54.132] INFO: number of red-efficiency pixels: 70 32 55 93 77 112 157 89 93 116 108 88 81 60 30 25
[14:40:54.132] INFO: number of X-ray hits detected: 59164 38599 53657 82617 85461 88800 93126 65863 70705 93483 91910 77143 79536 48920 20094 22579
[14:40:54.132] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:40:54.132] INFO: number of Vcal hits detected: 207929 207968 207945 207906 207919 207886 207837 207861 207905 207882 207890 207912 207917 207937 207969 207975
[14:40:54.132] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:40:54.132] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:40:54.132] INFO: X-ray hit rate [MHz/cm2]: 17.3 11.3 15.7 24.2 25.0 26.0 27.3 19.3 20.7 27.4 26.9 22.6 23.3 14.3 5.9 6.6
[14:40:54.132] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:54.178] INFO: PixTest:: pg_setup set to default.
[14:40:54.195] INFO: enter test to run
[14:41:19.164] INFO: test: HighRate no parameter change
[14:41:19.164] INFO: running: highrate
[14:41:19.165] INFO: ----------------------------------------------------------------------
[14:41:19.165] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:41:19.165] INFO: ----------------------------------------------------------------------
[14:41:19.787] INFO: Expecting 208000 events.
[14:41:32.922] INFO: 208000 events read in total (12608ms).
[14:41:32.927] INFO: Test took 13753ms.
[14:41:33.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:33.495] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:41:33.495] INFO: number of red-efficiency pixels: 162 126 153 234 253 344 441 252 244 358 384 299 231 179 62 62
[14:41:33.495] INFO: number of X-ray hits detected: 125815 81383 113450 175316 182100 188621 196323 139468 150667 198697 195909 164715 167942 104421 42595 48713
[14:41:33.495] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:41:33.495] INFO: number of Vcal hits detected: 207831 207871 207840 207752 207737 207641 207521 207685 207739 207612 207585 207679 207759 207812 207936 207938
[14:41:33.495] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:41:33.495] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:41:33.495] INFO: X-ray hit rate [MHz/cm2]: 36.9 23.9 33.3 51.4 53.4 55.3 57.5 40.9 44.2 58.2 57.4 48.3 49.2 30.6 12.5 14.3
[14:41:33.495] INFO: PixTestHighRate::doXPixelAlive() done
[14:41:33.543] INFO: PixTest:: pg_setup set to default.
[14:41:33.558] INFO: enter test to run
[14:41:55.596] INFO: test: HighRate no parameter change
[14:41:55.596] INFO: running: highrate
[14:41:55.597] INFO: ----------------------------------------------------------------------
[14:41:55.597] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:41:55.597] INFO: ----------------------------------------------------------------------
[14:41:56.227] INFO: Expecting 208000 events.
[14:42:10.898] INFO: 208000 events read in total (14144ms).
[14:42:10.905] INFO: Test took 15298ms.
[14:42:11.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:11.642] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:42:11.642] INFO: number of red-efficiency pixels: 331 241 371 545 563 768 988 528 552 916 944 684 482 367 90 98
[14:42:11.642] INFO: number of X-ray hits detected: 188437 121427 171314 264650 271821 281703 294404 208571 227581 297177 292872 247003 253066 156666 63629 74164
[14:42:11.642] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:42:11.642] INFO: number of Vcal hits detected: 207631 207739 207575 207387 207355 207098 206766 207337 207378 206918 206842 207211 207473 207584 207907 207897
[14:42:11.642] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.6 99.5 99.7 99.7 99.5 99.5 99.7 99.8 99.8 100.0 100.0
[14:42:11.642] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.6 99.4 99.7 99.7 99.5 99.4 99.6 99.7 99.8 100.0 100.0
[14:42:11.642] INFO: X-ray hit rate [MHz/cm2]: 55.2 35.6 50.2 77.6 79.7 82.6 86.3 61.1 66.7 87.1 85.8 72.4 74.2 45.9 18.7 21.7
[14:42:11.642] INFO: PixTestHighRate::doXPixelAlive() done
[14:42:11.689] INFO: PixTest:: pg_setup set to default.
[14:42:11.706] INFO: enter test to run
[14:42:17.380] INFO: test: exit no parameter change
[14:42:17.897] QUIET: Connection to board 33 closed.
[14:42:18.036] INFO: pXar: this is the end, my friend