[15:18:16.083] INFO: *** Welcome to pxar ***
[15:18:16.084] INFO: *** Today: 2016/10/11
[15:18:16.945] INFO: *** Version: v1.9.0-818-g96727
[15:18:16.945] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//dacParameters35_C15.dat
[15:18:16.973] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:18:16.973] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//defaultMaskFile.dat
[15:18:16.994] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C15.dat
[15:18:17.118] INFO: clk: 4
[15:18:17.118] INFO: ctr: 4
[15:18:17.118] INFO: sda: 19
[15:18:17.118] INFO: tin: 9
[15:18:17.118] INFO: level: 15
[15:18:17.118] INFO: triggerdelay: 0
[15:18:17.118] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:18:17.118] INFO: Log level: INFO
[15:18:17.136] QUIET: Connection to board DTB_WREKRL opened.
[15:18:17.140] 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:18:17.143] INFO: RPC call hashes of host and DTB match: 398089610
[15:18:18.676] INFO: DUT info:
[15:18:18.676] INFO: The DUT currently contains the following objects:
[15:18:18.676] INFO: 2 TBM Cores tbm08c (2 ON)
[15:18:18.676] INFO: TBM Core alpha (0): 7 registers set
[15:18:18.676] INFO: TBM Core beta (1): 7 registers set
[15:18:18.676] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:18:18.676] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.676] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.677] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.677] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:18.677] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:18:19.130] INFO: enter 'restricted' command line mode
[15:18:19.130] INFO: enter test to run
[15:18:32.705] INFO: test: PixelAlive no parameter change
[15:18:32.706] INFO: running: pixelalive
[15:18:32.850] INFO: ----------------------------------------------------------------------
[15:18:32.850] 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:18:32.850] INFO: ----------------------------------------------------------------------
[15:18:33.167] INFO: Expecting 41600 events.
[15:18:37.516] INFO: 41600 events read in total (3630ms).
[15:18:37.685] INFO: Test took 4831ms.
[15:18:37.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:38.270] INFO: PixTestAlive::aliveTest() done
[15:18:38.270] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:18:38.431] INFO: enter test to run
[15:18:46.081] INFO: test: timing no parameter change
[15:18:46.081] INFO: running: timing
[15:18:46.085] INFO: ######################################################################
[15:18:46.085] INFO: PixTestTiming::doTest()
[15:18:46.085] INFO: ######################################################################
[15:18:46.085] INFO: ----------------------------------------------------------------------
[15:18:46.085] INFO: PixTestTiming::TBMPhaseScan()
[15:18:46.085] INFO: ----------------------------------------------------------------------
[15:24:21.440] INFO: TBM Phase Settings: 240
[15:24:21.440] INFO: 400MHz Phase: 4
[15:24:21.440] INFO: 160MHz Phase: 7
[15:24:21.440] INFO: Functional Phase Area: 5
[15:24:21.457] INFO: Test took 335372 ms.
[15:24:21.457] INFO: PixTestTiming::TBMPhaseScan() done.
[15:24:21.457] INFO: ----------------------------------------------------------------------
[15:24:21.457] INFO: PixTestTiming::ROCDelayScan()
[15:24:21.457] INFO: ----------------------------------------------------------------------
[15:26:26.228] INFO: ROC Delay Settings: 228
[15:26:26.228] INFO: ROC Header-Trailer/Token Delay: 11
[15:26:26.229] INFO: ROC Port 0 Delay: 4
[15:26:26.229] INFO: ROC Port 1 Delay: 4
[15:26:26.229] INFO: Functional ROC Area: 4
[15:26:26.232] INFO: Test took 124775 ms.
[15:26:26.232] INFO: PixTestTiming::ROCDelayScan() done.
[15:26:26.232] INFO: ----------------------------------------------------------------------
[15:26:26.232] INFO: PixTestTiming::TimingTest()
[15:26:26.232] INFO: ----------------------------------------------------------------------
[15:26:42.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:57.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:12.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:27.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:43.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:58.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:13.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:28.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:43.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:58.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:59.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: Read back bit status: 1
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: Timings are good!
[15:28:59.049] INFO: ----------------------------------------------------------------------
[15:28:59.049] INFO: Test took 152817 ms.
[15:28:59.049] INFO: PixTestTiming::TimingTest() done.
[15:28:59.059] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:28:59.059] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:28:59.059] INFO: PixTestTiming::doTest took 612977 ms.
[15:28:59.059] INFO: PixTestTiming::doTest() done
[15:28:59.060] INFO: Write out TBMPhaseScan_0_V0
[15:28:59.060] INFO: Write out TBMPhaseScan_1_V0
[15:28:59.060] INFO: Write out CombinedTBMPhaseScan_V0
[15:28:59.086] INFO: Write out ROCDelayScan3_V0
[15:28:59.086] INFO: enter test to run
[15:29:28.845] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:29:28.845] INFO: running: highrate
[15:29:28.903] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:29:30.685] INFO: ----------------------------------------------------------------------
[15:29:30.685] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:29:30.685] INFO: ----------------------------------------------------------------------
[15:29:30.685] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:29:30.685] INFO: edge/corner pixel THR is adjusted
[15:29:30.685] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:29:31.705] INFO: Collecting data for 5 seconds...
[15:29:36.723] INFO: Done with hot pixel readout
[15:29:48.367] INFO: PixTest:: pg_setup set to default.
[15:29:48.368] INFO: 1 hot pixels found in step 0
[15:29:49.359] INFO: Collecting data for 5 seconds...
[15:29:54.376] INFO: Done with hot pixel readout
[15:30:05.768] INFO: PixTest:: pg_setup set to default.
[15:30:05.769] INFO: 0 hot pixels found in step 1
[15:30:05.805] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:30:05.808] INFO: PixTest::trimHotPixels() done
[15:30:05.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C0.dat
[15:30:05.814] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C1.dat
[15:30:05.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C2.dat
[15:30:05.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C3.dat
[15:30:05.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C4.dat
[15:30:05.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C5.dat
[15:30:05.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C6.dat
[15:30:05.847] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C7.dat
[15:30:05.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C8.dat
[15:30:05.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C9.dat
[15:30:05.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C10.dat
[15:30:05.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C11.dat
[15:30:05.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C12.dat
[15:30:05.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C13.dat
[15:30:05.884] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C14.dat
[15:30:05.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//trimParameters35_C15.dat
[15:30:05.895] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-42_FPIXTest-17C-FNAL-161010-1202-150V_2016-10-10_12h10m_1476119430/000_FPIXTest_p17//defaultMaskFile.dat
[15:30:05.904] INFO: enter test to run
[15:30:35.229] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:30:35.229] INFO: running: xray
[15:30:35.230] INFO: ----------------------------------------------------------------------
[15:30:35.230] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:30:35.230] INFO: ----------------------------------------------------------------------
[15:30:36.213] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:30:47.974] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:31:17.498] INFO: Resuming triggers.
[15:31:29.257] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:31:58.788] INFO: Resuming triggers.
[15:32:10.544] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:32:39.904] INFO: Resuming triggers.
[15:32:51.660] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:33:21.162] INFO: Resuming triggers.
[15:33:32.918] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:34:02.344] INFO: Resuming triggers.
[15:34:14.100] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:34:43.572] INFO: Resuming triggers.
[15:34:55.327] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:35:24.765] INFO: Resuming triggers.
[15:35:36.521] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:36:05.978] INFO: Resuming triggers.
[15:36:12.241] INFO: data taking finished, elapsed time: 100 seconds.
[15:36:28.267] INFO: PixTest:: pg_setup set to default.
[15:36:28.270] INFO: PixTestXray::doPhRun() done
[15:36:28.457] INFO: enter test to run
[15:37:26.282] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:37:26.282] INFO: running: xray
[15:37:26.283] INFO: ----------------------------------------------------------------------
[15:37:26.283] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:37:26.283] INFO: ----------------------------------------------------------------------
[15:37:27.246] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:37:33.981] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:38:05.204] INFO: Resuming triggers.
[15:38:11.946] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:38:42.556] INFO: Resuming triggers.
[15:38:49.294] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:39:20.333] INFO: Resuming triggers.
[15:39:27.077] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:39:58.152] INFO: Resuming triggers.
[15:40:04.893] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:40:35.972] INFO: Resuming triggers.
[15:40:42.716] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[15:41:13.814] INFO: Resuming triggers.
[15:41:20.558] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:41:52.137] INFO: Resuming triggers.
[15:41:58.881] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:42:30.317] INFO: Resuming triggers.
[15:42:37.058] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[15:43:08.453] INFO: Resuming triggers.
[15:43:15.195] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:43:46.509] INFO: Resuming triggers.
[15:43:53.245] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:44:24.414] INFO: Resuming triggers.
[15:44:31.151] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:45:02.270] INFO: Resuming triggers.
[15:45:08.005] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[15:45:39.307] INFO: Resuming triggers.
[15:45:46.039] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:46:16.267] INFO: Resuming triggers.
[15:46:22.263] INFO: data taking finished, elapsed time: 100 seconds.
[15:46:49.292] INFO: PixTest:: pg_setup set to default.
[15:46:49.295] INFO: PixTestXray::doPhRun() done
[15:46:49.443] INFO: enter test to run
[15:47:06.246] INFO: test: HighRate no parameter change
[15:47:06.246] INFO: running: highrate
[15:47:06.271] INFO: ----------------------------------------------------------------------
[15:47:06.271] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:47:06.271] INFO: ----------------------------------------------------------------------
[15:47:06.428] INFO: Expecting 768 events.
[15:47:07.567] INFO: 768 events read in total (423ms).
[15:47:07.567] INFO: Test took 1280ms.
[15:47:08.371] INFO: Expecting 41600 events.
[15:47:11.542] INFO: 41600 events read in total (2644ms).
[15:47:11.543] INFO: Test took 3924ms.
[15:47:11.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:12.298] INFO: Expecting 41600 events.
[15:47:15.543] INFO: 41600 events read in total (2718ms).
[15:47:15.544] INFO: Test took 3948ms.
[15:47:15.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:16.300] INFO: Expecting 41600 events.
[15:47:19.564] INFO: 41600 events read in total (2737ms).
[15:47:19.565] INFO: Test took 3967ms.
[15:47:19.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:20.322] INFO: Expecting 41600 events.
[15:47:23.581] INFO: 41600 events read in total (2732ms).
[15:47:23.582] INFO: Test took 3962ms.
[15:47:23.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:24.337] INFO: Expecting 41600 events.
[15:47:27.580] INFO: 41600 events read in total (2716ms).
[15:47:27.581] INFO: Test took 3943ms.
[15:47:27.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:28.339] INFO: Expecting 41600 events.
[15:47:31.537] INFO: 41600 events read in total (2671ms).
[15:47:31.538] INFO: Test took 3903ms.
[15:47:31.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:32.293] INFO: Expecting 41600 events.
[15:47:35.548] INFO: 41600 events read in total (2728ms).
[15:47:35.549] INFO: Test took 3956ms.
[15:47:35.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:36.306] INFO: Expecting 41600 events.
[15:47:39.554] INFO: 41600 events read in total (2721ms).
[15:47:39.555] INFO: Test took 3950ms.
[15:47:39.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:40.312] INFO: Expecting 41600 events.
[15:47:43.563] INFO: 41600 events read in total (2725ms).
[15:47:43.564] INFO: Test took 3954ms.
[15:47:43.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:44.322] INFO: Expecting 41600 events.
[15:47:47.560] INFO: 41600 events read in total (2711ms).
[15:47:47.561] INFO: Test took 3943ms.
[15:47:47.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:48.319] INFO: Expecting 41600 events.
[15:47:51.567] INFO: 41600 events read in total (2721ms).
[15:47:51.568] INFO: Test took 3952ms.
[15:47:51.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:52.324] INFO: Expecting 41600 events.
[15:47:55.572] INFO: 41600 events read in total (2722ms).
[15:47:55.573] INFO: Test took 3949ms.
[15:47:55.609] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:56.327] INFO: Expecting 41600 events.
[15:47:59.559] INFO: 41600 events read in total (2705ms).
[15:47:59.560] INFO: Test took 3933ms.
[15:47:59.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:00.317] INFO: Expecting 41600 events.
[15:48:03.579] INFO: 41600 events read in total (2736ms).
[15:48:03.580] INFO: Test took 3965ms.
[15:48:03.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:04.337] INFO: Expecting 41600 events.
[15:48:07.610] INFO: 41600 events read in total (2746ms).
[15:48:07.611] INFO: Test took 3976ms.
[15:48:07.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:08.364] INFO: Expecting 41600 events.
[15:48:11.628] INFO: 41600 events read in total (2737ms).
[15:48:11.630] INFO: Test took 3963ms.
[15:48:11.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:12.382] INFO: Expecting 41600 events.
[15:48:15.628] INFO: 41600 events read in total (2719ms).
[15:48:15.629] INFO: Test took 3937ms.
[15:48:15.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:16.388] INFO: Expecting 41600 events.
[15:48:19.587] INFO: 41600 events read in total (2672ms).
[15:48:19.588] INFO: Test took 3894ms.
[15:48:19.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:20.346] INFO: Expecting 41600 events.
[15:48:23.534] INFO: 41600 events read in total (2661ms).
[15:48:23.534] INFO: Test took 3891ms.
[15:48:23.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:24.294] INFO: Expecting 41600 events.
[15:48:27.273] INFO: 41600 events read in total (2452ms).
[15:48:27.274] INFO: Test took 3684ms.
[15:48:27.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:27.674] INFO: enter test to run
[15:48:50.021] INFO: test: HighRate no parameter change
[15:48:50.021] INFO: running: highrate
[15:48:50.022] INFO: ----------------------------------------------------------------------
[15:48:50.022] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:48:50.022] INFO: ----------------------------------------------------------------------
[15:48:50.638] INFO: Expecting 208000 events.
[15:49:02.567] INFO: 208000 events read in total (11402ms).
[15:49:02.570] INFO: Test took 12539ms.
[15:49:02.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:02.978] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:49:02.978] INFO: number of red-efficiency pixels: 64 57 107 144 174 172 118 120 134 145 126 87 120 80 24 28
[15:49:02.978] INFO: number of X-ray hits detected: 70770 48175 73825 111200 122465 125687 118588 89886 87947 105844 104343 86273 90974 55900 23669 28327
[15:49:02.978] 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:49:02.978] INFO: number of Vcal hits detected: 207935 207893 207891 207850 207821 207822 207878 207877 207862 207851 207873 207913 207877 207920 207976 207972
[15:49:02.978] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:49:02.978] INFO: Vcal hit overall efficiency (%): 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:49:02.979] INFO: X-ray hit rate [MHz/cm2]: 20.7 14.1 21.6 32.6 35.9 36.8 34.8 26.3 25.8 31.0 30.6 25.3 26.7 16.4 6.9 8.3
[15:49:02.979] INFO: PixTestHighRate::doXPixelAlive() done
[15:49:03.031] INFO: PixTest:: pg_setup set to default.
[15:49:03.043] INFO: enter test to run
[15:50:39.220] INFO: test: HighRate no parameter change
[15:50:39.221] INFO: running: highrate
[15:50:39.222] INFO: ----------------------------------------------------------------------
[15:50:39.222] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:50:39.222] INFO: ----------------------------------------------------------------------
[15:50:39.840] INFO: Expecting 208000 events.
[15:50:53.602] INFO: 208000 events read in total (13235ms).
[15:50:53.608] INFO: Test took 14376ms.
[15:50:53.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:54.217] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:50:54.217] INFO: number of red-efficiency pixels: 295 153 349 523 627 552 458 403 354 443 454 286 345 225 62 62
[15:50:54.217] INFO: number of X-ray hits detected: 141759 97880 147618 223144 244102 252515 236969 180828 176414 212523 209505 173529 182634 112481 47085 57691
[15:50:54.217] 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:50:54.217] INFO: number of Vcal hits detected: 207682 207790 207612 207434 207301 207385 207486 207567 207623 207525 207511 207694 207637 207763 207937 207938
[15:50:54.217] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:50:54.217] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:50:54.217] INFO: X-ray hit rate [MHz/cm2]: 41.6 28.7 43.3 65.4 71.5 74.0 69.5 53.0 51.7 62.3 61.4 50.9 53.5 33.0 13.8 16.9
[15:50:54.217] INFO: PixTestHighRate::doXPixelAlive() done
[15:50:54.266] INFO: PixTest:: pg_setup set to default.
[15:50:54.281] INFO: enter test to run
[15:51:38.380] INFO: test: HighRate no parameter change
[15:51:38.380] INFO: running: highrate
[15:51:38.381] INFO: ----------------------------------------------------------------------
[15:51:38.381] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:51:38.381] INFO: ----------------------------------------------------------------------
[15:51:39.028] INFO: Expecting 208000 events.
[15:51:54.661] INFO: 208000 events read in total (15107ms).
[15:51:54.669] INFO: Test took 16279ms.
[15:51:55.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:55.488] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:51:55.489] INFO: number of red-efficiency pixels: 571 298 694 1142 1271 1170 1000 806 685 1074 989 625 758 465 95 106
[15:51:55.489] INFO: number of X-ray hits detected: 206990 142311 215084 322644 355519 366761 345266 263684 257360 308625 304353 252922 266281 163723 69438 84049
[15:51:55.489] 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:51:55.489] INFO: number of Vcal hits detected: 207301 207615 207051 206579 206348 206462 206744 206999 207222 206663 206774 207292 207118 207425 207902 207891
[15:51:55.489] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.4 99.3 99.3 99.5 99.6 99.7 99.4 99.5 99.7 99.6 99.8 100.0 99.9
[15:51:55.489] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.2 99.3 99.4 99.5 99.6 99.4 99.4 99.7 99.6 99.7 100.0 99.9
[15:51:55.489] INFO: X-ray hit rate [MHz/cm2]: 60.7 41.7 63.0 94.6 104.2 107.5 101.2 77.3 75.4 90.5 89.2 74.1 78.0 48.0 20.4 24.6
[15:51:55.489] INFO: PixTestHighRate::doXPixelAlive() done
[15:51:55.537] INFO: PixTest:: pg_setup set to default.
[15:51:55.554] INFO: enter test to run
[15:52:12.492] INFO: test: exit no parameter change
[15:52:13.759] QUIET: Connection to board 33 closed.
[15:52:14.014] INFO: pXar: this is the end, my friend