[15:25:47.304] INFO: *** Welcome to pxar ***
[15:25:47.304] INFO: *** Today: 2016/09/07
[15:25:48.118] INFO: *** Version: v1.9.0-818-g96727
[15:25:48.118] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//dacParameters35_C15.dat
[15:25:48.129] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:25:48.129] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//defaultMaskFile.dat
[15:25:48.133] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C15.dat
[15:25:48.260] INFO: clk: 4
[15:25:48.260] INFO: ctr: 4
[15:25:48.260] INFO: sda: 19
[15:25:48.260] INFO: tin: 9
[15:25:48.260] INFO: level: 15
[15:25:48.260] INFO: triggerdelay: 0
[15:25:48.260] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:25:48.261] INFO: Log level: INFO
[15:25:48.278] QUIET: Connection to board DTB_WREKRL opened.
[15:25:48.282] 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:
------------------------------------------------------
[15:25:48.285] INFO: RPC call hashes of host and DTB match: 398089610
[15:25:49.815] INFO: DUT info:
[15:25:49.815] INFO: The DUT currently contains the following objects:
[15:25:49.815] INFO: 2 TBM Cores tbm08c (2 ON)
[15:25:49.815] INFO: TBM Core alpha (0): 7 registers set
[15:25:49.815] INFO: TBM Core beta (1): 7 registers set
[15:25:49.815] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:25:49.815] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.815] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.815] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.815] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.815] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:49.816] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:25:50.219] INFO: enter 'restricted' command line mode
[15:25:50.219] INFO: enter test to run
[15:26:07.144] INFO: test: PixelAlive no parameter change
[15:26:07.144] INFO: running: pixelalive
[15:26:07.236] INFO: ----------------------------------------------------------------------
[15:26:07.236] 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:26:07.236] INFO: ----------------------------------------------------------------------
[15:26:07.566] INFO: Expecting 41600 events.
[15:26:11.937] INFO: 41600 events read in total (3653ms).
[15:26:12.095] INFO: Test took 4848ms.
[15:26:12.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:12.423] INFO: PixTestAlive::aliveTest() done
[15:26:12.423] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:26:12.581] INFO: enter test to run
[15:27:05.087] INFO: test: timing no parameter change
[15:27:05.087] INFO: running: timing
[15:27:05.104] INFO: ######################################################################
[15:27:05.112] INFO: PixTestTiming::doTest()
[15:27:05.112] INFO: ######################################################################
[15:27:05.112] INFO: ----------------------------------------------------------------------
[15:27:05.112] INFO: PixTestTiming::TBMPhaseScan()
[15:27:05.112] INFO: ----------------------------------------------------------------------
[15:31:58.223] INFO: TBM Phase Settings: 236
[15:31:58.223] INFO: 400MHz Phase: 3
[15:31:58.223] INFO: 160MHz Phase: 7
[15:31:58.223] INFO: Functional Phase Area: 4
[15:31:58.239] INFO: Test took 293127 ms.
[15:31:58.239] INFO: PixTestTiming::TBMPhaseScan() done.
[15:31:58.239] INFO: ----------------------------------------------------------------------
[15:31:58.239] INFO: PixTestTiming::ROCDelayScan()
[15:31:58.240] INFO: ----------------------------------------------------------------------
[15:35:09.184] INFO: ROC Delay Settings: 220
[15:35:09.184] INFO: ROC Header-Trailer/Token Delay: 11
[15:35:09.184] INFO: ROC Port 0 Delay: 4
[15:35:09.185] INFO: ROC Port 1 Delay: 3
[15:35:09.185] INFO: Functional ROC Area: 4
[15:35:09.188] INFO: Test took 190949 ms.
[15:35:09.188] INFO: PixTestTiming::ROCDelayScan() done.
[15:35:09.188] INFO: ----------------------------------------------------------------------
[15:35:09.188] INFO: PixTestTiming::TimingTest()
[15:35:09.188] INFO: ----------------------------------------------------------------------
[15:35:25.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:40.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:55.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:10.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:25.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:40.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:55.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:10.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:26.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:41.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:41.540] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: Read back bit status: 1
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: Timings are good!
[15:37:41.558] INFO: ----------------------------------------------------------------------
[15:37:41.558] INFO: Test took 152370 ms.
[15:37:41.558] INFO: PixTestTiming::TimingTest() done.
[15:37:41.610] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:37:41.610] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:37:41.610] INFO: PixTestTiming::doTest took 636509 ms.
[15:37:41.610] INFO: PixTestTiming::doTest() done
[15:37:41.610] INFO: Write out TBMPhaseScan_0_V0
[15:37:41.610] INFO: Write out TBMPhaseScan_1_V0
[15:37:41.610] INFO: Write out CombinedTBMPhaseScan_V0
[15:37:41.652] INFO: Write out ROCDelayScan3_V0
[15:37:41.653] INFO: enter test to run
[15:38:26.307] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:38:26.307] INFO: running: highrate
[15:38:26.328] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:38:26.643] INFO: ----------------------------------------------------------------------
[15:38:26.643] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:38:26.643] INFO: ----------------------------------------------------------------------
[15:38:26.643] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:38:26.643] INFO: edge/corner pixel THR is adjusted
[15:38:26.643] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:38:27.622] INFO: Collecting data for 5 seconds...
[15:38:32.640] INFO: Done with hot pixel readout
[15:38:44.211] INFO: PixTest:: pg_setup set to default.
[15:38:44.212] INFO: 0 hot pixels found in step 0
[15:38:44.248] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:38:44.251] INFO: PixTest::trimHotPixels() done
[15:38:44.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C0.dat
[15:38:44.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C1.dat
[15:38:44.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C2.dat
[15:38:44.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C3.dat
[15:38:44.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C4.dat
[15:38:44.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C5.dat
[15:38:44.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C6.dat
[15:38:44.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C7.dat
[15:38:44.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C8.dat
[15:38:44.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C9.dat
[15:38:44.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C10.dat
[15:38:44.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C11.dat
[15:38:44.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C12.dat
[15:38:44.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C13.dat
[15:38:44.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C14.dat
[15:38:44.355] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C15.dat
[15:38:44.361] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//defaultMaskFile.dat
[15:38:44.371] INFO: enter test to run
[15:39:07.418] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:39:07.418] INFO: running: highrate
[15:39:07.423] INFO: ----------------------------------------------------------------------
[15:39:07.423] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:39:07.423] INFO: ----------------------------------------------------------------------
[15:39:07.423] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:39:07.423] INFO: edge/corner pixel THR is adjusted
[15:39:07.423] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:39:08.380] INFO: Collecting data for 1 seconds...
[15:39:09.385] INFO: Done with hot pixel readout
[15:39:13.638] INFO: PixTest:: pg_setup set to default.
[15:39:13.639] INFO: 0 hot pixels found in step 0
[15:39:13.645] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:39:13.730] INFO: PixTest::trimHotPixels() done
[15:39:13.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C0.dat
[15:39:13.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C1.dat
[15:39:13.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C2.dat
[15:39:13.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C3.dat
[15:39:13.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C4.dat
[15:39:13.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C5.dat
[15:39:13.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C6.dat
[15:39:13.815] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C7.dat
[15:39:13.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C8.dat
[15:39:13.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C9.dat
[15:39:13.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C10.dat
[15:39:13.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C11.dat
[15:39:13.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C12.dat
[15:39:13.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C13.dat
[15:39:13.877] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C14.dat
[15:39:13.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//trimParameters35_C15.dat
[15:39:13.895] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-03_FPIXTest-17C-FNAL-160831-1531-150V_2016-08-31_15h31m_1472675500/000_FPIXTest_p17//defaultMaskFile.dat
[15:39:13.907] INFO: enter test to run
[15:40:02.378] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:40:02.378] INFO: running: xray
[15:40:02.379] INFO: ----------------------------------------------------------------------
[15:40:02.379] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:40:02.379] INFO: ----------------------------------------------------------------------
[15:40:03.362] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:40:15.039] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:40:44.309] INFO: Resuming triggers.
[15:40:55.987] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:41:25.283] INFO: Resuming triggers.
[15:41:36.957] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:42:06.080] INFO: Resuming triggers.
[15:42:17.758] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:42:46.939] INFO: Resuming triggers.
[15:42:58.618] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:43:27.573] INFO: Resuming triggers.
[15:43:39.253] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:44:08.631] INFO: Resuming triggers.
[15:44:20.311] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[15:44:49.583] INFO: Resuming triggers.
[15:45:01.261] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:45:30.492] INFO: Resuming triggers.
[15:45:37.414] INFO: data taking finished, elapsed time: 100 seconds.
[15:45:55.152] INFO: PixTest:: pg_setup set to default.
[15:45:55.156] INFO: PixTestXray::doPhRun() done
[15:45:55.372] INFO: enter test to run
[15:46:23.671] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:46:23.671] INFO: running: xray
[15:46:23.673] INFO: ----------------------------------------------------------------------
[15:46:23.673] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:46:23.673] INFO: ----------------------------------------------------------------------
[15:46:24.637] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:46:31.266] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:47:01.446] INFO: Resuming triggers.
[15:47:08.076] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:47:38.231] INFO: Resuming triggers.
[15:47:44.860] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:48:15.473] INFO: Resuming triggers.
[15:48:22.098] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:48:52.354] INFO: Resuming triggers.
[15:48:58.980] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:49:29.833] INFO: Resuming triggers.
[15:49:36.459] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:50:07.458] INFO: Resuming triggers.
[15:50:14.079] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:50:45.128] INFO: Resuming triggers.
[15:50:51.754] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:51:22.625] INFO: Resuming triggers.
[15:51:29.252] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:51:59.762] INFO: Resuming triggers.
[15:52:06.387] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:52:38.394] INFO: Resuming triggers.
[15:52:45.025] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:53:16.278] INFO: Resuming triggers.
[15:53:22.904] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:53:54.059] INFO: Resuming triggers.
[15:54:00.689] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:54:31.976] INFO: Resuming triggers.
[15:54:38.601] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:55:09.806] INFO: Resuming triggers.
[15:55:16.433] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:55:46.718] INFO: Resuming triggers.
[15:55:47.685] INFO: data taking finished, elapsed time: 100 seconds.
[15:55:52.474] INFO: PixTest:: pg_setup set to default.
[15:55:52.478] INFO: PixTestXray::doPhRun() done
[15:55:52.633] INFO: enter test to run
[15:56:11.316] INFO: test: HighRate no parameter change
[15:56:11.316] INFO: running: highrate
[15:56:11.329] INFO: ----------------------------------------------------------------------
[15:56:11.329] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:56:11.329] INFO: ----------------------------------------------------------------------
[15:56:11.516] INFO: Expecting 768 events.
[15:56:12.650] INFO: 768 events read in total (419ms).
[15:56:12.650] INFO: Test took 1269ms.
[15:56:13.453] INFO: Expecting 41600 events.
[15:56:16.523] INFO: 41600 events read in total (2543ms).
[15:56:16.524] INFO: Test took 3762ms.
[15:56:16.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:17.289] INFO: Expecting 41600 events.
[15:56:20.468] INFO: 41600 events read in total (2652ms).
[15:56:20.468] INFO: Test took 3897ms.
[15:56:20.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:21.225] INFO: Expecting 41600 events.
[15:56:24.434] INFO: 41600 events read in total (2682ms).
[15:56:24.435] INFO: Test took 3917ms.
[15:56:24.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:25.197] INFO: Expecting 41600 events.
[15:56:28.425] INFO: 41600 events read in total (2701ms).
[15:56:28.426] INFO: Test took 3940ms.
[15:56:28.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:29.182] INFO: Expecting 41600 events.
[15:56:32.397] INFO: 41600 events read in total (2688ms).
[15:56:32.397] INFO: Test took 3921ms.
[15:56:32.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:33.154] INFO: Expecting 41600 events.
[15:56:36.382] INFO: 41600 events read in total (2701ms).
[15:56:36.383] INFO: Test took 3936ms.
[15:56:36.416] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:37.143] INFO: Expecting 41600 events.
[15:56:40.388] INFO: 41600 events read in total (2718ms).
[15:56:40.388] INFO: Test took 3955ms.
[15:56:40.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:41.144] INFO: Expecting 41600 events.
[15:56:44.366] INFO: 41600 events read in total (2696ms).
[15:56:44.367] INFO: Test took 3928ms.
[15:56:44.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:45.128] INFO: Expecting 41600 events.
[15:56:48.347] INFO: 41600 events read in total (2692ms).
[15:56:48.348] INFO: Test took 3931ms.
[15:56:48.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:49.105] INFO: Expecting 41600 events.
[15:56:52.322] INFO: 41600 events read in total (2690ms).
[15:56:52.323] INFO: Test took 3924ms.
[15:56:52.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:53.084] INFO: Expecting 41600 events.
[15:56:56.304] INFO: 41600 events read in total (2693ms).
[15:56:56.305] INFO: Test took 3924ms.
[15:56:56.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:57.066] INFO: Expecting 41600 events.
[15:57:00.298] INFO: 41600 events read in total (2706ms).
[15:57:00.299] INFO: Test took 3944ms.
[15:57:00.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:01.057] INFO: Expecting 41600 events.
[15:57:04.296] INFO: 41600 events read in total (2712ms).
[15:57:04.297] INFO: Test took 3946ms.
[15:57:04.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:05.057] INFO: Expecting 41600 events.
[15:57:08.289] INFO: 41600 events read in total (2706ms).
[15:57:08.290] INFO: Test took 3943ms.
[15:57:08.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:09.045] INFO: Expecting 41600 events.
[15:57:12.273] INFO: 41600 events read in total (2701ms).
[15:57:12.274] INFO: Test took 3932ms.
[15:57:12.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:13.031] INFO: Expecting 41600 events.
[15:57:16.259] INFO: 41600 events read in total (2701ms).
[15:57:16.260] INFO: Test took 3934ms.
[15:57:16.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:17.019] INFO: Expecting 41600 events.
[15:57:20.241] INFO: 41600 events read in total (2695ms).
[15:57:20.242] INFO: Test took 3933ms.
[15:57:20.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:20.999] INFO: Expecting 41600 events.
[15:57:24.229] INFO: 41600 events read in total (2703ms).
[15:57:24.230] INFO: Test took 3938ms.
[15:57:24.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:24.992] INFO: Expecting 41600 events.
[15:57:28.199] INFO: 41600 events read in total (2680ms).
[15:57:28.200] INFO: Test took 3919ms.
[15:57:28.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:28.959] INFO: Expecting 41600 events.
[15:57:32.023] INFO: 41600 events read in total (2538ms).
[15:57:32.024] INFO: Test took 3766ms.
[15:57:32.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:32.425] INFO: enter test to run
[15:57:43.691] INFO: test: HighRate no parameter change
[15:57:43.691] INFO: running: highrate
[15:57:43.694] INFO: ----------------------------------------------------------------------
[15:57:43.694] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:57:43.694] INFO: ----------------------------------------------------------------------
[15:57:44.396] INFO: Expecting 208000 events.
[15:57:56.104] INFO: 208000 events read in total (11181ms).
[15:57:56.107] INFO: Test took 12315ms.
[15:57:56.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:56.493] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:57:56.506] INFO: number of red-efficiency pixels: 71 56 72 127 114 143 153 80 83 100 106 104 101 61 22 32
[15:57:56.506] INFO: number of X-ray hits detected: 61617 39113 62613 101448 107544 108084 112315 81535 75274 95570 94256 78979 78805 47739 19218 24101
[15:57:56.506] 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:57:56.506] INFO: number of Vcal hits detected: 207929 207943 207928 207866 207883 207852 207839 207917 207917 207899 207891 207894 207898 207939 207976 207968
[15:57:56.506] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:57:56.506] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0
[15:57:56.506] INFO: X-ray hit rate [MHz/cm2]: 18.1 11.5 18.4 29.7 31.5 31.7 32.9 23.9 22.1 28.0 27.6 23.1 23.1 14.0 5.6 7.1
[15:57:56.506] INFO: PixTestHighRate::doXPixelAlive() done
[15:57:56.557] INFO: PixTest:: pg_setup set to default.
[15:57:56.572] INFO: enter test to run
[15:58:11.539] INFO: test: HighRate no parameter change
[15:58:11.539] INFO: running: highrate
[15:58:11.540] INFO: ----------------------------------------------------------------------
[15:58:11.540] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:58:11.540] INFO: ----------------------------------------------------------------------
[15:58:12.153] INFO: Expecting 208000 events.
[15:58:25.783] INFO: 208000 events read in total (13103ms).
[15:58:25.788] INFO: Test took 14237ms.
[15:58:26.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:26.373] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:58:26.373] INFO: number of red-efficiency pixels: 195 128 228 380 443 617 621 310 206 410 338 296 315 174 41 67
[15:58:26.373] INFO: number of X-ray hits detected: 134598 85626 136748 220151 233457 235594 242704 178239 164386 209067 204530 172594 171163 103728 41708 52778
[15:58:26.373] 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:58:26.373] INFO: number of Vcal hits detected: 207793 207869 207762 207600 207530 207315 207300 207671 207784 207561 207643 207687 207659 207820 207957 207933
[15:58:26.373] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:58:26.373] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:58:26.373] INFO: X-ray hit rate [MHz/cm2]: 39.5 25.1 40.1 64.5 68.4 69.1 71.1 52.2 48.2 61.3 59.9 50.6 50.2 30.4 12.2 15.5
[15:58:26.373] INFO: PixTestHighRate::doXPixelAlive() done
[15:58:26.427] INFO: PixTest:: pg_setup set to default.
[15:58:26.442] INFO: enter test to run
[15:58:46.322] INFO: test: HighRate no parameter change
[15:58:46.323] INFO: running: highrate
[15:58:46.324] INFO: ----------------------------------------------------------------------
[15:58:46.324] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:58:46.324] INFO: ----------------------------------------------------------------------
[15:58:46.939] INFO: Expecting 208000 events.
[15:59:02.454] INFO: 208000 events read in total (14988ms).
[15:59:02.461] INFO: Test took 16128ms.
[15:59:02.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:03.250] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:59:03.250] INFO: number of red-efficiency pixels: 424 277 537 943 983 1384 1491 741 462 823 716 680 708 415 81 95
[15:59:03.250] INFO: number of X-ray hits detected: 204059 130121 208840 335351 354684 356545 368877 272862 249919 317462 310839 262656 260753 158114 63763 80904
[15:59:03.250] 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:59:03.250] INFO: number of Vcal hits detected: 207514 207696 207328 206838 206778 206065 205962 207082 207490 207007 207190 207200 207188 207517 207918 207901
[15:59:03.250] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.2 99.1 99.6 99.8 99.6 99.6 99.7 99.6 99.8 100.0 100.0
[15:59:03.250] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.4 99.1 99.0 99.6 99.8 99.5 99.6 99.6 99.6 99.8 100.0 100.0
[15:59:03.250] INFO: X-ray hit rate [MHz/cm2]: 59.8 38.1 61.2 98.3 104.0 104.5 108.1 80.0 73.3 93.1 91.1 77.0 76.4 46.3 18.7 23.7
[15:59:03.250] INFO: PixTestHighRate::doXPixelAlive() done
[15:59:03.298] INFO: PixTest:: pg_setup set to default.
[15:59:03.316] INFO: enter test to run
[15:59:12.578] INFO: test: exit no parameter change
[15:59:13.385] QUIET: Connection to board 33 closed.
[15:59:13.566] INFO: pXar: this is the end, my friend