[10:36:43.774] INFO: *** Welcome to pxar ***
[10:36:43.774] INFO: *** Today: 2016/09/23
[10:36:45.029] INFO: *** Version: v1.9.0-818-g96727
[10:36:45.029] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//dacParameters35_C15.dat
[10:36:45.318] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:36:45.318] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[10:36:45.331] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[10:36:46.590] INFO: clk: 4
[10:36:46.590] INFO: ctr: 4
[10:36:46.590] INFO: sda: 19
[10:36:46.590] INFO: tin: 9
[10:36:46.590] INFO: level: 15
[10:36:46.590] INFO: triggerdelay: 0
[10:36:46.590] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:36:46.590] INFO: Log level: INFO
[10:36:46.607] QUIET: Connection to board DTB_WREKRL opened.
[10:36:46.610] 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:
------------------------------------------------------
[10:36:46.613] INFO: RPC call hashes of host and DTB match: 398089610
[10:36:48.144] INFO: DUT info:
[10:36:48.144] INFO: The DUT currently contains the following objects:
[10:36:48.144] INFO: 2 TBM Cores tbm08c (2 ON)
[10:36:48.144] INFO: TBM Core alpha (0): 7 registers set
[10:36:48.144] INFO: TBM Core beta (1): 7 registers set
[10:36:48.144] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:36:48.144] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.144] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:36:48.554] INFO: enter 'restricted' command line mode
[10:36:48.554] INFO: enter test to run
[10:36:55.328] INFO: test: PixelAlive no parameter change
[10:36:55.328] INFO: running: pixelalive
[10:36:55.337] INFO: ----------------------------------------------------------------------
[10:36:55.337] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:36:55.337] INFO: ----------------------------------------------------------------------
[10:36:55.656] INFO: Expecting 41600 events.
[10:37:00.028] INFO: 41600 events read in total (3653ms).
[10:37:00.197] INFO: Test took 4857ms.
[10:37:00.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:00.473] INFO: PixTestAlive::aliveTest() done
[10:37:00.473] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[10:37:00.505] INFO: enter test to run
[10:37:04.655] INFO: test: timing no parameter change
[10:37:04.655] INFO: running: timing
[10:37:04.659] INFO: ######################################################################
[10:37:04.659] INFO: PixTestTiming::doTest()
[10:37:04.659] INFO: ######################################################################
[10:37:04.659] INFO: ----------------------------------------------------------------------
[10:37:04.659] INFO: PixTestTiming::TBMPhaseScan()
[10:37:04.659] INFO: ----------------------------------------------------------------------
[10:43:28.560] INFO: TBM Phase Settings: 224
[10:43:28.560] INFO: 400MHz Phase: 0
[10:43:28.560] INFO: 160MHz Phase: 7
[10:43:28.561] INFO: Functional Phase Area: 4
[10:43:28.564] INFO: Test took 383905 ms.
[10:43:28.564] INFO: PixTestTiming::TBMPhaseScan() done.
[10:43:28.564] INFO: ----------------------------------------------------------------------
[10:43:28.564] INFO: PixTestTiming::ROCDelayScan()
[10:43:28.564] INFO: ----------------------------------------------------------------------
[10:45:31.574] INFO: ROC Delay Settings: 228
[10:45:31.574] INFO: ROC Header-Trailer/Token Delay: 11
[10:45:31.574] INFO: ROC Port 0 Delay: 4
[10:45:31.574] INFO: ROC Port 1 Delay: 4
[10:45:31.574] INFO: Functional ROC Area: 5
[10:45:31.577] INFO: Test took 123013 ms.
[10:45:31.577] INFO: PixTestTiming::ROCDelayScan() done.
[10:45:31.577] INFO: ----------------------------------------------------------------------
[10:45:31.577] INFO: PixTestTiming::TimingTest()
[10:45:31.577] INFO: ----------------------------------------------------------------------
[10:45:47.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:02.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:17.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:32.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:47.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:02.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:17.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:32.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:47.434] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:02.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:02.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: Read back bit status: 1
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: Timings are good!
[10:48:02.797] INFO: ----------------------------------------------------------------------
[10:48:02.797] INFO: Test took 151220 ms.
[10:48:02.797] INFO: PixTestTiming::TimingTest() done.
[10:48:02.815] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:48:02.815] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:48:02.815] INFO: PixTestTiming::doTest took 658159 ms.
[10:48:02.815] INFO: PixTestTiming::doTest() done
[10:48:02.816] INFO: Write out TBMPhaseScan_0_V0
[10:48:02.816] INFO: Write out TBMPhaseScan_1_V0
[10:48:02.816] INFO: Write out CombinedTBMPhaseScan_V0
[10:48:02.831] INFO: Write out ROCDelayScan3_V0
[10:48:02.832] INFO: enter test to run
[10:49:04.699] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:49:04.699] INFO: running: highrate
[10:49:04.724] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:49:05.015] INFO: ----------------------------------------------------------------------
[10:49:05.015] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:49:05.015] INFO: ----------------------------------------------------------------------
[10:49:05.015] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:49:05.015] INFO: edge/corner pixel THR is adjusted
[10:49:05.015] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:49:05.974] INFO: Collecting data for 5 seconds...
[10:49:10.990] INFO: Done with hot pixel readout
[10:49:22.647] INFO: PixTest:: pg_setup set to default.
[10:49:22.648] INFO: 1 hot pixels found in step 0
[10:49:23.641] INFO: Collecting data for 5 seconds...
[10:49:28.658] INFO: Done with hot pixel readout
[10:49:40.276] INFO: PixTest:: pg_setup set to default.
[10:49:40.277] INFO: 1 hot pixels found in step 1
[10:49:41.269] INFO: Collecting data for 5 seconds...
[10:49:46.286] INFO: Done with hot pixel readout
[10:49:57.622] INFO: PixTest:: pg_setup set to default.
[10:49:57.623] INFO: 1 hot pixels found in step 2
[10:49:58.615] INFO: Collecting data for 5 seconds...
[10:50:03.632] INFO: Done with hot pixel readout
[10:50:15.207] INFO: PixTest:: pg_setup set to default.
[10:50:15.208] INFO: 0 hot pixels found in step 3
[10:50:15.243] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:50:15.247] INFO: PixTest::trimHotPixels() done
[10:50:15.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat
[10:50:15.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C1.dat
[10:50:15.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C2.dat
[10:50:15.264] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C3.dat
[10:50:15.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C4.dat
[10:50:15.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C5.dat
[10:50:15.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C6.dat
[10:50:15.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C7.dat
[10:50:15.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C8.dat
[10:50:15.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C9.dat
[10:50:15.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C10.dat
[10:50:15.306] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C11.dat
[10:50:15.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C12.dat
[10:50:15.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C13.dat
[10:50:15.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C14.dat
[10:50:15.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[10:50:15.332] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[10:50:15.342] INFO: enter test to run
[10:50:37.050] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:50:37.050] INFO: running: highrate
[10:50:37.055] INFO: ----------------------------------------------------------------------
[10:50:37.055] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:50:37.055] INFO: ----------------------------------------------------------------------
[10:50:37.055] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:50:37.055] INFO: edge/corner pixel THR is adjusted
[10:50:37.055] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:50:38.013] INFO: Collecting data for 1 seconds...
[10:50:39.017] INFO: Done with hot pixel readout
[10:50:43.168] INFO: PixTest:: pg_setup set to default.
[10:50:43.169] INFO: 0 hot pixels found in step 0
[10:50:43.174] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:50:43.260] INFO: PixTest::trimHotPixels() done
[10:50:43.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat
[10:50:43.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C1.dat
[10:50:43.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C2.dat
[10:50:43.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C3.dat
[10:50:43.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C4.dat
[10:50:43.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C5.dat
[10:50:43.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C6.dat
[10:50:43.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C7.dat
[10:50:43.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C8.dat
[10:50:43.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C9.dat
[10:50:43.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C10.dat
[10:50:43.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C11.dat
[10:50:43.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C12.dat
[10:50:43.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C13.dat
[10:50:43.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C14.dat
[10:50:43.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[10:50:43.351] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-43_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[10:50:43.368] INFO: enter test to run
[10:51:17.458] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:51:17.458] INFO: running: xray
[10:51:17.459] INFO: ----------------------------------------------------------------------
[10:51:17.459] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:51:17.459] INFO: ----------------------------------------------------------------------
[10:51:18.421] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:51:29.986] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:51:59.855] INFO: Resuming triggers.
[10:52:11.421] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:52:41.416] INFO: Resuming triggers.
[10:52:52.979] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:53:22.552] INFO: Resuming triggers.
[10:53:34.114] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:54:03.340] INFO: Resuming triggers.
[10:54:14.905] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:54:44.556] INFO: Resuming triggers.
[10:54:56.120] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:55:26.470] INFO: Resuming triggers.
[10:55:38.033] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:56:08.447] INFO: Resuming triggers.
[10:56:20.014] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:56:49.543] INFO: Resuming triggers.
[10:56:57.389] INFO: data taking finished, elapsed time: 100 seconds.
[10:57:17.592] INFO: PixTest:: pg_setup set to default.
[10:57:17.596] INFO: PixTestXray::doPhRun() done
[10:57:17.769] INFO: enter test to run
[10:58:23.151] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:58:23.151] INFO: running: xray
[10:58:23.152] INFO: ----------------------------------------------------------------------
[10:58:23.152] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:58:23.152] INFO: ----------------------------------------------------------------------
[10:58:24.116] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:58:30.666] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:59:00.996] INFO: Resuming triggers.
[10:59:07.547] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:59:37.698] INFO: Resuming triggers.
[10:59:44.247] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:00:14.416] INFO: Resuming triggers.
[11:00:20.966] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:00:51.162] INFO: Resuming triggers.
[11:00:57.716] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:01:28.030] INFO: Resuming triggers.
[11:01:34.579] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:02:04.833] INFO: Resuming triggers.
[11:02:11.383] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:02:41.544] INFO: Resuming triggers.
[11:02:48.094] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:03:18.296] INFO: Resuming triggers.
[11:03:24.841] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[11:03:54.002] INFO: Resuming triggers.
[11:04:01.548] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:04:32.205] INFO: Resuming triggers.
[11:04:38.754] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:05:09.006] INFO: Resuming triggers.
[11:05:15.554] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[11:05:46.807] INFO: Resuming triggers.
[11:05:53.353] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[11:06:23.888] INFO: Resuming triggers.
[11:06:30.435] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:07:01.593] INFO: Resuming triggers.
[11:07:08.138] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[11:07:40.097] INFO: Resuming triggers.
[11:07:42.204] INFO: data taking finished, elapsed time: 100 seconds.
[11:07:52.654] INFO: PixTest:: pg_setup set to default.
[11:07:52.657] INFO: PixTestXray::doPhRun() done
[11:07:52.809] INFO: enter test to run
[11:08:25.563] INFO: test: HighRate no parameter change
[11:08:25.563] INFO: running: highrate
[11:08:25.582] INFO: ----------------------------------------------------------------------
[11:08:25.582] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:08:25.582] INFO: ----------------------------------------------------------------------
[11:08:25.765] INFO: Expecting 768 events.
[11:08:26.951] INFO: 768 events read in total (470ms).
[11:08:26.951] INFO: Test took 1340ms.
[11:08:27.754] INFO: Expecting 41600 events.
[11:08:30.885] INFO: 41600 events read in total (2604ms).
[11:08:30.886] INFO: Test took 3929ms.
[11:08:30.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:31.645] INFO: Expecting 41600 events.
[11:08:34.911] INFO: 41600 events read in total (2739ms).
[11:08:34.912] INFO: Test took 3974ms.
[11:08:34.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:35.671] INFO: Expecting 41600 events.
[11:08:38.954] INFO: 41600 events read in total (2756ms).
[11:08:38.955] INFO: Test took 3989ms.
[11:08:38.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:39.711] INFO: Expecting 41600 events.
[11:08:43.169] INFO: 41600 events read in total (2931ms).
[11:08:43.170] INFO: Test took 4161ms.
[11:08:43.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:43.927] INFO: Expecting 41600 events.
[11:08:47.245] INFO: 41600 events read in total (2791ms).
[11:08:47.245] INFO: Test took 4020ms.
[11:08:47.282] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:47.999] INFO: Expecting 41600 events.
[11:08:51.385] INFO: 41600 events read in total (2859ms).
[11:08:51.386] INFO: Test took 4086ms.
[11:08:51.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:52.140] INFO: Expecting 41600 events.
[11:08:55.455] INFO: 41600 events read in total (2788ms).
[11:08:55.456] INFO: Test took 4016ms.
[11:08:55.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:56.212] INFO: Expecting 41600 events.
[11:08:59.610] INFO: 41600 events read in total (2871ms).
[11:08:59.611] INFO: Test took 4100ms.
[11:08:59.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:00.368] INFO: Expecting 41600 events.
[11:09:03.707] INFO: 41600 events read in total (2812ms).
[11:09:03.708] INFO: Test took 4043ms.
[11:09:03.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:04.460] INFO: Expecting 41600 events.
[11:09:07.770] INFO: 41600 events read in total (2783ms).
[11:09:07.770] INFO: Test took 4007ms.
[11:09:07.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:08.525] INFO: Expecting 41600 events.
[11:09:11.861] INFO: 41600 events read in total (2810ms).
[11:09:11.861] INFO: Test took 4036ms.
[11:09:11.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:12.618] INFO: Expecting 41600 events.
[11:09:15.877] INFO: 41600 events read in total (2732ms).
[11:09:15.878] INFO: Test took 3963ms.
[11:09:15.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:16.634] INFO: Expecting 41600 events.
[11:09:19.898] INFO: 41600 events read in total (2737ms).
[11:09:19.899] INFO: Test took 3965ms.
[11:09:19.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:20.657] INFO: Expecting 41600 events.
[11:09:23.915] INFO: 41600 events read in total (2731ms).
[11:09:23.916] INFO: Test took 3964ms.
[11:09:23.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:24.670] INFO: Expecting 41600 events.
[11:09:27.935] INFO: 41600 events read in total (2738ms).
[11:09:27.936] INFO: Test took 3965ms.
[11:09:27.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:28.690] INFO: Expecting 41600 events.
[11:09:31.823] INFO: 41600 events read in total (2606ms).
[11:09:31.824] INFO: Test took 3834ms.
[11:09:31.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:32.578] INFO: Expecting 41600 events.
[11:09:35.857] INFO: 41600 events read in total (2752ms).
[11:09:35.857] INFO: Test took 3979ms.
[11:09:35.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:36.612] INFO: Expecting 41600 events.
[11:09:39.878] INFO: 41600 events read in total (2739ms).
[11:09:39.879] INFO: Test took 3967ms.
[11:09:39.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:40.634] INFO: Expecting 41600 events.
[11:09:43.848] INFO: 41600 events read in total (2687ms).
[11:09:43.849] INFO: Test took 3915ms.
[11:09:43.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:44.603] INFO: Expecting 41600 events.
[11:09:47.762] INFO: 41600 events read in total (2632ms).
[11:09:47.763] INFO: Test took 3860ms.
[11:09:47.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:48.166] INFO: enter test to run
[11:10:05.722] INFO: test: HighRate no parameter change
[11:10:05.722] INFO: running: highrate
[11:10:05.724] INFO: ----------------------------------------------------------------------
[11:10:05.724] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:10:05.724] INFO: ----------------------------------------------------------------------
[11:10:06.334] INFO: Expecting 208000 events.
[11:10:18.258] INFO: 208000 events read in total (11397ms).
[11:10:18.262] INFO: Test took 12529ms.
[11:10:18.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:10:18.666] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:10:18.666] INFO: number of red-efficiency pixels: 82 52 88 139 119 182 112 92 113 161 140 123 115 76 25 26
[11:10:18.666] INFO: number of X-ray hits detected: 68739 44864 65849 102194 106114 117404 112519 81894 89655 112106 111228 94915 96812 59265 23493 25631
[11:10:18.666] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:10:18.666] INFO: number of Vcal hits detected: 207916 207948 207911 207859 207880 207810 207883 207908 207883 207835 207854 207874 207882 207923 207975 207973
[11:10:18.666] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[11:10:18.666] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[11:10:18.666] INFO: X-ray hit rate [MHz/cm2]: 20.1 13.1 19.3 30.0 31.1 34.4 33.0 24.0 26.3 32.9 32.6 27.8 28.4 17.4 6.9 7.5
[11:10:18.666] INFO: PixTestHighRate::doXPixelAlive() done
[11:10:18.715] INFO: PixTest:: pg_setup set to default.
[11:10:18.732] INFO: enter test to run
[11:11:01.162] INFO: test: HighRate no parameter change
[11:11:01.162] INFO: running: highrate
[11:11:01.163] INFO: ----------------------------------------------------------------------
[11:11:01.163] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:11:01.163] INFO: ----------------------------------------------------------------------
[11:11:01.777] INFO: Expecting 208000 events.
[11:11:15.362] INFO: 208000 events read in total (13058ms).
[11:11:15.369] INFO: Test took 14195ms.
[11:11:15.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:15.972] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:11:15.972] INFO: number of red-efficiency pixels: 206 123 228 425 409 570 390 337 382 506 494 380 301 194 53 62
[11:11:15.972] INFO: number of X-ray hits detected: 136839 88928 131467 202606 212792 234474 226216 164652 178319 225355 221581 189655 194062 119224 47999 51764
[11:11:15.972] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:11:15.972] INFO: number of Vcal hits detected: 207781 207873 207760 207532 207566 207375 207578 207639 207596 207451 207464 207585 207678 207790 207946 207937
[11:11:15.972] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[11:11:15.972] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[11:11:15.972] INFO: X-ray hit rate [MHz/cm2]: 40.1 26.1 38.5 59.4 62.4 68.7 66.3 48.3 52.3 66.1 64.9 55.6 56.9 34.9 14.1 15.2
[11:11:15.972] INFO: PixTestHighRate::doXPixelAlive() done
[11:11:16.020] INFO: PixTest:: pg_setup set to default.
[11:11:16.036] INFO: enter test to run
[11:11:28.994] INFO: test: HighRate no parameter change
[11:11:28.994] INFO: running: highrate
[11:11:28.995] INFO: ----------------------------------------------------------------------
[11:11:28.995] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:11:28.995] INFO: ----------------------------------------------------------------------
[11:11:29.612] INFO: Expecting 208000 events.
[11:11:45.289] INFO: 208000 events read in total (15150ms).
[11:11:45.297] INFO: Test took 16291ms.
[11:11:45.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:46.118] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:11:46.118] INFO: number of red-efficiency pixels: 414 258 467 1119 951 1379 946 742 752 1251 1093 904 705 428 111 97
[11:11:46.118] INFO: number of X-ray hits detected: 208710 136408 199825 309834 321680 357180 344059 249964 271446 341799 337158 287951 295414 181383 72294 78559
[11:11:46.118] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:11:46.118] INFO: number of Vcal hits detected: 207522 207722 207440 206624 206852 206168 206852 207104 207100 206404 206567 206854 207184 207514 207885 207903
[11:11:46.118] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.4 99.5 99.2 99.5 99.6 99.6 99.3 99.4 99.5 99.6 99.8 99.9 100.0
[11:11:46.118] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.3 99.4 99.1 99.4 99.6 99.6 99.2 99.3 99.4 99.6 99.8 99.9 100.0
[11:11:46.118] INFO: X-ray hit rate [MHz/cm2]: 61.2 40.0 58.6 90.8 94.3 104.7 100.8 73.3 79.6 100.2 98.8 84.4 86.6 53.2 21.2 23.0
[11:11:46.118] INFO: PixTestHighRate::doXPixelAlive() done
[11:11:46.168] INFO: PixTest:: pg_setup set to default.
[11:11:46.190] INFO: enter test to run
[11:11:56.473] INFO: test: exit no parameter change
[11:11:56.922] QUIET: Connection to board 33 closed.
[11:11:56.980] INFO: pXar: this is the end, my friend