[11:58:36.835] INFO: *** Welcome to pxar ***
[11:58:36.835] INFO: *** Today: 2016/04/15
[11:58:36.853] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:58:36.853] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//dacParameters35_C15.dat
[11:58:36.854] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:58:36.854] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[11:58:36.855] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[11:58:36.922] INFO: clk: 4
[11:58:36.922] INFO: ctr: 4
[11:58:36.922] INFO: sda: 19
[11:58:36.922] INFO: tin: 9
[11:58:36.922] INFO: level: 15
[11:58:36.922] INFO: triggerdelay: 0
[11:58:36.922] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:58:36.923] INFO: Log level: INFO
[11:58:36.941] QUIET: Connection to board DTB_WREKRL opened.
[11:58:36.944] 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:
------------------------------------------------------
[11:58:36.947] INFO: RPC call hashes of host and DTB match: 398089610
[11:58:38.478] INFO: DUT info:
[11:58:38.478] INFO: The DUT currently contains the following objects:
[11:58:38.478] INFO: 2 TBM Cores tbm08c (2 ON)
[11:58:38.478] INFO: TBM Core alpha (0): 7 registers set
[11:58:38.478] INFO: TBM Core beta (1): 7 registers set
[11:58:38.478] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:58:38.478] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.478] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.479] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:58:38.882] INFO: enter 'restricted' command line mode
[11:58:38.882] INFO: enter test to run
[11:58:40.314] INFO: test: timing no parameter change
[11:58:40.314] INFO: running: timing
[11:58:40.343] INFO: ######################################################################
[11:58:40.343] INFO: PixTestTiming::doTest()
[11:58:40.346] INFO: ######################################################################
[11:58:40.347] INFO: ----------------------------------------------------------------------
[11:58:40.347] INFO: PixTestTiming::TBMPhaseScan()
[11:58:40.347] INFO: ----------------------------------------------------------------------
[12:04:19.781] INFO: TBM Phase Settings: 16
[12:04:19.781] INFO: 400MHz Phase: 4
[12:04:19.781] INFO: 160MHz Phase: 0
[12:04:19.781] INFO: Functional Phase Area: 2
[12:04:19.791] INFO: Test took 339444 ms.
[12:04:19.791] INFO: PixTestTiming::TBMPhaseScan() done.
[12:04:19.791] INFO: ----------------------------------------------------------------------
[12:04:19.791] INFO: PixTestTiming::ROCDelayScan()
[12:04:19.791] INFO: ----------------------------------------------------------------------
[12:06:29.509] INFO: ROC Delay Settings: 227
[12:06:29.509] INFO: ROC Header-Trailer/Token Delay: 11
[12:06:29.509] INFO: ROC Port 0 Delay: 3
[12:06:29.509] INFO: ROC Port 1 Delay: 4
[12:06:29.509] INFO: Functional ROC Area: 5
[12:06:29.513] INFO: Test took 129722 ms.
[12:06:29.513] INFO: PixTestTiming::ROCDelayScan() done.
[12:06:29.513] INFO: ----------------------------------------------------------------------
[12:06:29.513] INFO: PixTestTiming::TimingTest()
[12:06:29.513] INFO: ----------------------------------------------------------------------
[12:06:45.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:00.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:15.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:30.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:45.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:00.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:15.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:30.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:45.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:00.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:00.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: Read back bit status: 1
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: Timings are good!
[12:09:00.561] INFO: ----------------------------------------------------------------------
[12:09:00.561] INFO: Test took 151048 ms.
[12:09:00.561] INFO: PixTestTiming::TimingTest() done.
[12:09:00.573] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:09:00.573] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:09:00.573] INFO: PixTestTiming::doTest took 620235 ms.
[12:09:00.573] INFO: PixTestTiming::doTest() done
[12:09:00.574] INFO: Write out TBMPhaseScan_0_V0
[12:09:00.610] INFO: Write out TBMPhaseScan_1_V0
[12:09:00.610] INFO: Write out CombinedTBMPhaseScan_V0
[12:09:00.627] INFO: Write out ROCDelayScan3_V0
[12:09:00.628] INFO: enter test to run
[12:09:08.478] INFO: test: PixelAlive no parameter change
[12:09:08.478] INFO: running: pixelalive
[12:09:08.482] INFO: ----------------------------------------------------------------------
[12:09:08.482] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:09:08.482] INFO: ----------------------------------------------------------------------
[12:09:08.799] INFO: Expecting 41600 events.
[12:09:13.112] INFO: 41600 events read in total (3598ms).
[12:09:13.113] INFO: Test took 4628ms.
[12:09:13.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:13.518] INFO: PixTestAlive::aliveTest() done
[12:09:13.518] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 1 0 0 0 0 4 1 0
[12:09:13.521] INFO: enter test to run
[12:09:32.718] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:09:32.718] INFO: running: highrate
[12:09:32.718] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:09:32.870] INFO: ----------------------------------------------------------------------
[12:09:32.870] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:09:32.870] INFO: ----------------------------------------------------------------------
[12:09:32.870] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:09:32.870] INFO: edge/corner pixel THR is adjusted
[12:09:32.870] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:09:33.828] INFO: Collecting data for 5 seconds...
[12:09:38.845] INFO: Done with hot pixel readout
[12:09:50.808] INFO: PixTest:: pg_setup set to default.
[12:09:50.809] INFO: 9 hot pixels found in step 0
[12:09:51.803] INFO: Collecting data for 5 seconds...
[12:09:56.820] INFO: Done with hot pixel readout
[12:10:08.819] INFO: PixTest:: pg_setup set to default.
[12:10:08.820] INFO: 2 hot pixels found in step 1
[12:10:09.815] INFO: Collecting data for 5 seconds...
[12:10:14.832] INFO: Done with hot pixel readout
[12:10:26.820] INFO: PixTest:: pg_setup set to default.
[12:10:26.821] INFO: 3 hot pixels found in step 2
[12:10:27.815] INFO: Collecting data for 5 seconds...
[12:10:32.832] INFO: Done with hot pixel readout
[12:10:44.846] INFO: PixTest:: pg_setup set to default.
[12:10:44.846] INFO: 3 hot pixels found in step 3
[12:10:45.841] INFO: Collecting data for 5 seconds...
[12:10:50.858] INFO: Done with hot pixel readout
[12:11:02.839] INFO: PixTest:: pg_setup set to default.
[12:11:02.840] INFO: 2 hot pixels found in step 4
[12:11:03.835] INFO: Collecting data for 5 seconds...
[12:11:08.850] INFO: Done with hot pixel readout
[12:11:20.845] INFO: PixTest:: pg_setup set to default.
[12:11:20.846] INFO: 0 hot pixels found in step 5
[12:11:20.884] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:11:20.888] INFO: PixTest::trimHotPixels() done
[12:11:20.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat
[12:11:20.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C1.dat
[12:11:20.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C2.dat
[12:11:20.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C3.dat
[12:11:20.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C4.dat
[12:11:20.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C5.dat
[12:11:20.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C6.dat
[12:11:20.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C7.dat
[12:11:20.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C8.dat
[12:11:20.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C9.dat
[12:11:20.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C10.dat
[12:11:20.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C11.dat
[12:11:20.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C12.dat
[12:11:20.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C13.dat
[12:11:20.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C14.dat
[12:11:20.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[12:11:20.973] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[12:11:20.983] INFO: enter test to run
[12:11:39.069] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:11:39.069] INFO: running: highrate
[12:11:39.073] INFO: ----------------------------------------------------------------------
[12:11:39.073] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:11:39.073] INFO: ----------------------------------------------------------------------
[12:11:39.073] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:11:39.073] INFO: edge/corner pixel THR is adjusted
[12:11:39.073] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:11:40.031] INFO: Collecting data for 1 seconds...
[12:11:41.034] INFO: Done with hot pixel readout
[12:11:45.183] INFO: PixTest:: pg_setup set to default.
[12:11:45.184] INFO: 0 hot pixels found in step 0
[12:11:45.189] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:11:45.269] INFO: PixTest::trimHotPixels() done
[12:11:45.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat
[12:11:45.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C1.dat
[12:11:45.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C2.dat
[12:11:45.292] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C3.dat
[12:11:45.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C4.dat
[12:11:45.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C5.dat
[12:11:45.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C6.dat
[12:11:45.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C7.dat
[12:11:45.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C8.dat
[12:11:45.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C9.dat
[12:11:45.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C10.dat
[12:11:45.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C11.dat
[12:11:45.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C12.dat
[12:11:45.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C13.dat
[12:11:45.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C14.dat
[12:11:45.355] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[12:11:45.360] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-34_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[12:11:45.370] INFO: enter test to run
[12:12:03.277] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:12:03.277] INFO: running: xray
[12:12:03.278] INFO: ----------------------------------------------------------------------
[12:12:03.278] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:12:03.278] INFO: ----------------------------------------------------------------------
[12:12:04.240] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:12:15.273] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:12:44.778] INFO: Resuming triggers.
[12:12:55.808] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:13:25.300] INFO: Resuming triggers.
[12:13:36.330] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:14:05.721] INFO: Resuming triggers.
[12:14:16.752] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:14:46.300] INFO: Resuming triggers.
[12:14:57.335] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:15:26.778] INFO: Resuming triggers.
[12:15:37.807] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:16:07.276] INFO: Resuming triggers.
[12:16:18.311] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:16:46.361] INFO: Resuming triggers.
[12:16:57.392] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:17:26.944] INFO: Resuming triggers.
[12:17:37.980] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:18:07.556] INFO: Resuming triggers.
[12:18:08.568] INFO: data taking finished, elapsed time: 100 seconds.
[12:18:11.668] INFO: PixTest:: pg_setup set to default.
[12:18:11.671] INFO: PixTestXray::doPhRun() done
[12:18:11.810] INFO: enter test to run
[12:18:26.170] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:18:26.170] INFO: running: xray
[12:18:26.171] INFO: ----------------------------------------------------------------------
[12:18:26.171] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:18:26.171] INFO: ----------------------------------------------------------------------
[12:18:27.146] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:18:33.568] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:19:03.695] INFO: Resuming triggers.
[12:19:10.118] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:19:40.137] INFO: Resuming triggers.
[12:19:46.561] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:20:16.563] INFO: Resuming triggers.
[12:20:22.988] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:20:53.123] INFO: Resuming triggers.
[12:20:59.545] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:21:29.618] INFO: Resuming triggers.
[12:21:36.041] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[12:22:06.114] INFO: Resuming triggers.
[12:22:12.537] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:22:42.630] INFO: Resuming triggers.
[12:22:49.052] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:23:19.075] INFO: Resuming triggers.
[12:23:25.495] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:23:55.558] INFO: Resuming triggers.
[12:24:01.977] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:24:31.992] INFO: Resuming triggers.
[12:24:38.409] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:25:08.442] INFO: Resuming triggers.
[12:25:14.860] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:25:44.920] INFO: Resuming triggers.
[12:25:51.341] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:26:21.040] INFO: Resuming triggers.
[12:26:27.458] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[12:26:57.153] INFO: Resuming triggers.
[12:27:03.576] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[12:27:33.639] INFO: Resuming triggers.
[12:27:37.632] INFO: data taking finished, elapsed time: 100 seconds.
[12:27:56.553] INFO: PixTest:: pg_setup set to default.
[12:27:56.556] INFO: PixTestXray::doPhRun() done
[12:27:56.705] INFO: enter test to run
[12:28:15.421] INFO: test: HighRate no parameter change
[12:28:15.421] INFO: running: highrate
[12:28:15.422] INFO: ----------------------------------------------------------------------
[12:28:15.422] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:28:15.422] INFO: ----------------------------------------------------------------------
[12:28:15.563] INFO: Expecting 768 events.
[12:28:16.697] INFO: 768 events read in total (418ms).
[12:28:16.697] INFO: Test took 1269ms.
[12:28:17.500] INFO: Expecting 41600 events.
[12:28:20.669] INFO: 41600 events read in total (2642ms).
[12:28:20.670] INFO: Test took 3967ms.
[12:28:20.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:21.432] INFO: Expecting 41600 events.
[12:28:24.690] INFO: 41600 events read in total (2731ms).
[12:28:24.691] INFO: Test took 3964ms.
[12:28:24.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:25.445] INFO: Expecting 41600 events.
[12:28:28.712] INFO: 41600 events read in total (2740ms).
[12:28:28.713] INFO: Test took 3968ms.
[12:28:28.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:29.470] INFO: Expecting 41600 events.
[12:28:32.744] INFO: 41600 events read in total (2747ms).
[12:28:32.745] INFO: Test took 3977ms.
[12:28:32.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:33.501] INFO: Expecting 41600 events.
[12:28:36.784] INFO: 41600 events read in total (2756ms).
[12:28:36.785] INFO: Test took 3985ms.
[12:28:36.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:37.538] INFO: Expecting 41600 events.
[12:28:40.805] INFO: 41600 events read in total (2740ms).
[12:28:40.806] INFO: Test took 3965ms.
[12:28:40.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:41.561] INFO: Expecting 41600 events.
[12:28:44.848] INFO: 41600 events read in total (2760ms).
[12:28:44.849] INFO: Test took 3988ms.
[12:28:44.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:45.602] INFO: Expecting 41600 events.
[12:28:48.893] INFO: 41600 events read in total (2765ms).
[12:28:48.894] INFO: Test took 3989ms.
[12:28:48.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:49.649] INFO: Expecting 41600 events.
[12:28:52.947] INFO: 41600 events read in total (2772ms).
[12:28:52.948] INFO: Test took 3998ms.
[12:28:52.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:53.701] INFO: Expecting 41600 events.
[12:28:56.985] INFO: 41600 events read in total (2757ms).
[12:28:56.986] INFO: Test took 3981ms.
[12:28:57.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:57.744] INFO: Expecting 41600 events.
[12:29:01.039] INFO: 41600 events read in total (2768ms).
[12:29:01.040] INFO: Test took 3998ms.
[12:29:01.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:01.797] INFO: Expecting 41600 events.
[12:29:05.105] INFO: 41600 events read in total (2781ms).
[12:29:05.106] INFO: Test took 4010ms.
[12:29:05.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:05.859] INFO: Expecting 41600 events.
[12:29:09.148] INFO: 41600 events read in total (2762ms).
[12:29:09.149] INFO: Test took 3989ms.
[12:29:09.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:09.902] INFO: Expecting 41600 events.
[12:29:13.197] INFO: 41600 events read in total (2768ms).
[12:29:13.198] INFO: Test took 3986ms.
[12:29:13.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:13.954] INFO: Expecting 41600 events.
[12:29:17.239] INFO: 41600 events read in total (2758ms).
[12:29:17.240] INFO: Test took 3987ms.
[12:29:17.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:17.997] INFO: Expecting 41600 events.
[12:29:21.282] INFO: 41600 events read in total (2758ms).
[12:29:21.283] INFO: Test took 3987ms.
[12:29:21.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:22.039] INFO: Expecting 41600 events.
[12:29:25.335] INFO: 41600 events read in total (2769ms).
[12:29:25.336] INFO: Test took 3997ms.
[12:29:25.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:26.089] INFO: Expecting 41600 events.
[12:29:29.380] INFO: 41600 events read in total (2764ms).
[12:29:29.381] INFO: Test took 3989ms.
[12:29:29.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:30.135] INFO: Expecting 41600 events.
[12:29:33.404] INFO: 41600 events read in total (2743ms).
[12:29:33.405] INFO: Test took 3970ms.
[12:29:33.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:34.163] INFO: Expecting 41600 events.
[12:29:37.286] INFO: 41600 events read in total (2596ms).
[12:29:37.287] INFO: Test took 3825ms.
[12:29:37.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:37.681] INFO: enter test to run
[12:29:53.813] INFO: test: HighRate no parameter change
[12:29:53.813] INFO: running: highrate
[12:29:53.814] INFO: ----------------------------------------------------------------------
[12:29:53.814] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:53.814] INFO: ----------------------------------------------------------------------
[12:29:54.431] INFO: Expecting 208000 events.
[12:30:06.437] INFO: 208000 events read in total (11479ms).
[12:30:06.441] INFO: Test took 12619ms.
[12:30:06.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:06.857] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 1 0 0 0 0 4 1 0
[12:30:06.857] INFO: number of red-efficiency pixels: 110 64 101 152 178 155 195 127 113 146 105 144 129 85 26 45
[12:30:06.857] INFO: number of X-ray hits detected: 67845 45660 74298 113394 120278 122158 121821 89492 89445 112406 109654 97655 96925 58728 24955 28715
[12:30:06.857] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:30:06.857] INFO: number of Vcal hits detected: 207890 207936 207799 207845 207813 207840 207796 207870 207837 207853 207895 207852 207867 207717 207923 207955
[12:30:06.857] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[12:30:06.857] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:30:06.857] INFO: X-ray hit rate [MHz/cm2]: 19.9 13.4 21.8 33.2 35.3 35.8 35.7 26.2 26.2 32.9 32.1 28.6 28.4 17.2 7.3 8.4
[12:30:06.857] INFO: PixTestHighRate::doXPixelAlive() done
[12:30:06.902] INFO: PixTest:: pg_setup set to default.
[12:30:06.918] INFO: enter test to run
[12:31:04.588] INFO: test: HighRate no parameter change
[12:31:04.588] INFO: running: highrate
[12:31:04.590] INFO: ----------------------------------------------------------------------
[12:31:04.590] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:31:04.590] INFO: ----------------------------------------------------------------------
[12:31:05.206] INFO: Expecting 208000 events.
[12:31:21.158] INFO: 208000 events read in total (15425ms).
[12:31:21.165] INFO: Test took 16565ms.
[12:31:21.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:22.013] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 1 0 0 0 0 4 1 0
[12:31:22.013] INFO: number of red-efficiency pixels: 537 308 766 948 1054 1190 1429 929 842 1094 935 968 976 527 115 103
[12:31:22.013] INFO: number of X-ray hits detected: 206111 138075 224928 345826 363352 372288 371555 274251 272938 343352 333742 297850 297144 178257 76058 88057
[12:31:22.013] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:31:22.013] INFO: number of Vcal hits detected: 207376 207664 206831 206853 206667 206433 206043 206769 206922 206636 206874 206803 206833 207155 207829 207895
[12:31:22.013] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.5 99.4 99.3 99.2 99.5 99.5 99.4 99.5 99.5 99.5 99.7 99.9 99.9
[12:31:22.013] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.4 99.4 99.2 99.1 99.4 99.5 99.3 99.5 99.4 99.4 99.6 99.9 99.9
[12:31:22.013] INFO: X-ray hit rate [MHz/cm2]: 60.4 40.5 65.9 101.4 106.5 109.1 108.9 80.4 80.0 100.6 97.8 87.3 87.1 52.2 22.3 25.8
[12:31:22.013] INFO: PixTestHighRate::doXPixelAlive() done
[12:31:22.058] INFO: PixTest:: pg_setup set to default.
[12:31:22.076] INFO: enter test to run
[12:31:34.204] INFO: test: HighRate no parameter change
[12:31:34.204] INFO: running: highrate
[12:31:34.205] INFO: ----------------------------------------------------------------------
[12:31:34.205] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:31:34.205] INFO: ----------------------------------------------------------------------
[12:31:34.821] INFO: Expecting 208000 events.
[12:31:48.566] INFO: 208000 events read in total (13218ms).
[12:31:48.572] INFO: Test took 14358ms.
[12:31:48.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:49.188] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 0 1 0 0 0 0 4 1 0
[12:31:49.188] INFO: number of red-efficiency pixels: 245 150 301 347 445 521 599 388 320 416 368 415 379 224 65 55
[12:31:49.188] INFO: number of X-ray hits detected: 132171 88646 143364 222162 232964 236988 238212 174839 174013 219644 214563 190058 189558 114275 48551 55873
[12:31:49.189] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:31:49.189] INFO: number of Vcal hits detected: 207745 207845 207564 207631 207523 207426 207331 207563 207609 207548 207610 207551 207592 207563 207885 207945
[12:31:49.189] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:31:49.189] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0
[12:31:49.189] INFO: X-ray hit rate [MHz/cm2]: 38.7 26.0 42.0 65.1 68.3 69.5 69.8 51.2 51.0 64.4 62.9 55.7 55.6 33.5 14.2 16.4
[12:31:49.189] INFO: PixTestHighRate::doXPixelAlive() done
[12:31:49.237] INFO: PixTest:: pg_setup set to default.
[12:31:49.248] INFO: enter test to run
[12:31:53.436] INFO: test: exit no parameter change
[12:31:53.829] QUIET: Connection to board 33 closed.
[12:31:53.830] INFO: pXar: this is the end, my friend