[11:17:30.371] INFO: *** Welcome to pxar ***
[11:17:30.371] INFO: *** Today: 2016/09/21
[11:17:31.749] INFO: *** Version: v1.9.0-818-g96727
[11:17:31.749] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//dacParameters35_C15.dat
[11:17:31.842] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:17:31.842] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[11:17:31.842] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[11:17:31.968] INFO: clk: 4
[11:17:31.968] INFO: ctr: 4
[11:17:31.968] INFO: sda: 19
[11:17:31.968] INFO: tin: 9
[11:17:31.968] INFO: level: 15
[11:17:31.968] INFO: triggerdelay: 0
[11:17:31.968] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:17:31.968] INFO: Log level: INFO
[11:17:31.984] QUIET: Connection to board DTB_WREKRL opened.
[11:17:31.987] 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:17:31.990] INFO: RPC call hashes of host and DTB match: 398089610
[11:17:33.538] INFO: DUT info:
[11:17:33.539] INFO: The DUT currently contains the following objects:
[11:17:33.539] INFO: 2 TBM Cores tbm08c (2 ON)
[11:17:33.544] INFO: TBM Core alpha (0): 7 registers set
[11:17:33.544] INFO: TBM Core beta (1): 7 registers set
[11:17:33.544] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:17:33.544] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.544] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.545] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:17:33.005] INFO: enter 'restricted' command line mode
[11:17:33.005] INFO: enter test to run
[11:17:39.048] INFO: test: PixelAlive no parameter change
[11:17:39.048] INFO: running: pixelalive
[11:17:39.108] INFO: ----------------------------------------------------------------------
[11:17:39.108] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:17:39.108] INFO: ----------------------------------------------------------------------
[11:17:39.431] INFO: Expecting 41600 events.
[11:17:43.774] INFO: 41600 events read in total (3624ms).
[11:17:43.935] INFO: Test took 4825ms.
[11:17:43.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:44.495] INFO: PixTestAlive::aliveTest() done
[11:17:44.495] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[11:17:44.673] INFO: enter test to run
[11:17:53.400] INFO: test: timing no parameter change
[11:17:53.400] INFO: running: timing
[11:17:53.403] INFO: ######################################################################
[11:17:53.403] INFO: PixTestTiming::doTest()
[11:17:53.403] INFO: ######################################################################
[11:17:53.404] INFO: ----------------------------------------------------------------------
[11:17:53.404] INFO: PixTestTiming::TBMPhaseScan()
[11:17:53.404] INFO: ----------------------------------------------------------------------
[11:24:12.326] INFO: TBM Phase Settings: 16
[11:24:12.326] INFO: 400MHz Phase: 4
[11:24:12.326] INFO: 160MHz Phase: 0
[11:24:12.326] INFO: Functional Phase Area: 3
[11:24:12.346] INFO: Test took 378943 ms.
[11:24:12.346] INFO: PixTestTiming::TBMPhaseScan() done.
[11:24:12.346] INFO: ----------------------------------------------------------------------
[11:24:12.346] INFO: PixTestTiming::ROCDelayScan()
[11:24:12.346] INFO: ----------------------------------------------------------------------
[11:26:11.456] INFO: ROC Delay Settings: 219
[11:26:11.456] INFO: ROC Header-Trailer/Token Delay: 11
[11:26:11.456] INFO: ROC Port 0 Delay: 3
[11:26:11.456] INFO: ROC Port 1 Delay: 3
[11:26:11.456] INFO: Functional ROC Area: 4
[11:26:11.460] INFO: Test took 119114 ms.
[11:26:11.460] INFO: PixTestTiming::ROCDelayScan() done.
[11:26:11.460] INFO: ----------------------------------------------------------------------
[11:26:11.460] INFO: PixTestTiming::TimingTest()
[11:26:11.460] INFO: ----------------------------------------------------------------------
[11:26:27.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:42.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:57.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:12.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:27.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:42.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:57.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:12.356] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:27.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:42.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:42.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: Read back bit status: 1
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: Timings are good!
[11:28:42.667] INFO: ----------------------------------------------------------------------
[11:28:42.667] INFO: Test took 151207 ms.
[11:28:42.667] INFO: PixTestTiming::TimingTest() done.
[11:28:42.667] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:28:42.667] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:28:42.668] INFO: PixTestTiming::doTest took 649268 ms.
[11:28:42.668] INFO: PixTestTiming::doTest() done
[11:28:42.668] INFO: Write out TBMPhaseScan_0_V0
[11:28:42.668] INFO: Write out TBMPhaseScan_1_V0
[11:28:42.668] INFO: Write out CombinedTBMPhaseScan_V0
[11:28:42.670] INFO: Write out ROCDelayScan3_V0
[11:28:42.671] INFO: enter test to run
[11:29:34.323] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:29:34.323] INFO: running: highrate
[11:29:34.335] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:29:34.586] INFO: ----------------------------------------------------------------------
[11:29:34.586] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:29:34.586] INFO: ----------------------------------------------------------------------
[11:29:34.586] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:29:34.586] INFO: edge/corner pixel THR is adjusted
[11:29:34.586] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:29:35.544] INFO: Collecting data for 5 seconds...
[11:29:40.559] INFO: Done with hot pixel readout
[11:29:52.067] INFO: PixTest:: pg_setup set to default.
[11:29:52.068] INFO: 1 hot pixels found in step 0
[11:29:53.058] INFO: Collecting data for 5 seconds...
[11:29:58.074] INFO: Done with hot pixel readout
[11:30:09.755] INFO: PixTest:: pg_setup set to default.
[11:30:09.756] INFO: 1 hot pixels found in step 1
[11:30:10.748] INFO: Collecting data for 5 seconds...
[11:30:15.766] INFO: Done with hot pixel readout
[11:30:27.323] INFO: PixTest:: pg_setup set to default.
[11:30:27.324] INFO: 1 hot pixels found in step 2
[11:30:28.314] INFO: Collecting data for 5 seconds...
[11:30:33.332] INFO: Done with hot pixel readout
[11:30:44.739] INFO: PixTest:: pg_setup set to default.
[11:30:44.740] INFO: 0 hot pixels found in step 3
[11:30:44.775] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:30:44.779] INFO: PixTest::trimHotPixels() done
[11:30:44.779] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat
[11:30:44.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C1.dat
[11:30:44.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C2.dat
[11:30:44.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C3.dat
[11:30:44.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C4.dat
[11:30:44.806] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C5.dat
[11:30:44.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C6.dat
[11:30:44.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C7.dat
[11:30:44.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C8.dat
[11:30:44.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C9.dat
[11:30:44.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C10.dat
[11:30:44.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C11.dat
[11:30:44.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C12.dat
[11:30:44.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C13.dat
[11:30:44.856] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C14.dat
[11:30:44.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[11:30:44.867] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[11:30:44.876] INFO: enter test to run
[11:31:27.147] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:31:27.147] INFO: running: highrate
[11:31:27.151] INFO: ----------------------------------------------------------------------
[11:31:27.151] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:31:27.151] INFO: ----------------------------------------------------------------------
[11:31:27.151] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:31:27.151] INFO: edge/corner pixel THR is adjusted
[11:31:27.151] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:31:28.108] INFO: Collecting data for 1 seconds...
[11:31:29.112] INFO: Done with hot pixel readout
[11:31:33.019] INFO: PixTest:: pg_setup set to default.
[11:31:33.020] INFO: 0 hot pixels found in step 0
[11:31:33.026] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:31:33.119] INFO: PixTest::trimHotPixels() done
[11:31:33.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C0.dat
[11:31:33.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C1.dat
[11:31:33.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C2.dat
[11:31:33.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C3.dat
[11:31:33.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C4.dat
[11:31:33.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C5.dat
[11:31:33.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C6.dat
[11:31:33.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C7.dat
[11:31:33.169] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C8.dat
[11:31:33.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C9.dat
[11:31:33.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C10.dat
[11:31:33.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C11.dat
[11:31:33.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C12.dat
[11:31:33.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C13.dat
[11:31:33.203] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C14.dat
[11:31:33.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//trimParameters35_C15.dat
[11:31:33.214] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-26_FPIXTest-17C-FNAL-160915-0919-150V_2016-09-15_09h19m_1473949154/000_FPIXTest_p17//defaultMaskFile.dat
[11:31:33.227] INFO: enter test to run
[11:31:55.162] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:31:55.162] INFO: running: xray
[11:31:55.164] INFO: ----------------------------------------------------------------------
[11:31:55.164] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:31:55.164] INFO: ----------------------------------------------------------------------
[11:31:56.143] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:32:08.029] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:32:37.661] INFO: Resuming triggers.
[11:32:49.549] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:33:18.878] INFO: Resuming triggers.
[11:33:30.770] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:34:00.957] INFO: Resuming triggers.
[11:34:12.846] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:34:43.581] INFO: Resuming triggers.
[11:34:55.471] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:35:24.918] INFO: Resuming triggers.
[11:35:36.807] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:36:06.053] INFO: Resuming triggers.
[11:36:17.938] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[11:36:47.129] INFO: Resuming triggers.
[11:36:59.020] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:37:28.311] INFO: Resuming triggers.
[11:37:33.558] INFO: data taking finished, elapsed time: 100 seconds.
[11:37:46.855] INFO: PixTest:: pg_setup set to default.
[11:37:46.858] INFO: PixTestXray::doPhRun() done
[11:37:47.056] INFO: enter test to run
[11:38:21.144] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:38:21.144] INFO: running: xray
[11:38:21.145] INFO: ----------------------------------------------------------------------
[11:38:21.145] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:38:21.145] INFO: ----------------------------------------------------------------------
[11:38:22.110] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:38:29.295] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[11:38:59.554] INFO: Resuming triggers.
[11:39:06.739] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[11:39:36.985] INFO: Resuming triggers.
[11:39:44.172] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:40:14.320] INFO: Resuming triggers.
[11:40:21.506] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[11:40:51.693] INFO: Resuming triggers.
[11:40:58.883] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:41:29.169] INFO: Resuming triggers.
[11:41:36.357] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[11:42:06.624] INFO: Resuming triggers.
[11:42:13.813] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[11:42:44.079] INFO: Resuming triggers.
[11:42:51.269] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:43:22.498] INFO: Resuming triggers.
[11:43:29.686] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[11:44:00.055] INFO: Resuming triggers.
[11:44:07.247] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:44:38.224] INFO: Resuming triggers.
[11:44:45.409] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[11:45:16.125] INFO: Resuming triggers.
[11:45:23.312] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[11:45:54.151] INFO: Resuming triggers.
[11:46:01.340] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:46:32.764] INFO: Resuming triggers.
[11:46:39.667] INFO: data taking finished, elapsed time: 100 seconds.
[11:47:10.223] INFO: PixTest:: pg_setup set to default.
[11:47:10.226] INFO: PixTestXray::doPhRun() done
[11:47:10.379] INFO: enter test to run
[11:47:56.636] INFO: test: HighRate no parameter change
[11:47:56.636] INFO: running: highrate
[11:47:56.669] INFO: ----------------------------------------------------------------------
[11:47:56.669] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:47:56.669] INFO: ----------------------------------------------------------------------
[11:47:56.835] INFO: Expecting 768 events.
[11:47:57.988] INFO: 768 events read in total (438ms).
[11:47:57.988] INFO: Test took 1299ms.
[11:47:58.791] INFO: Expecting 41600 events.
[11:48:01.892] INFO: 41600 events read in total (2574ms).
[11:48:01.892] INFO: Test took 3898ms.
[11:48:01.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:02.657] INFO: Expecting 41600 events.
[11:48:05.934] INFO: 41600 events read in total (2750ms).
[11:48:05.935] INFO: Test took 3996ms.
[11:48:05.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:06.692] INFO: Expecting 41600 events.
[11:48:09.972] INFO: 41600 events read in total (2753ms).
[11:48:09.972] INFO: Test took 3987ms.
[11:48:09.005] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:10.724] INFO: Expecting 41600 events.
[11:48:13.940] INFO: 41600 events read in total (2689ms).
[11:48:13.941] INFO: Test took 3920ms.
[11:48:13.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:14.698] INFO: Expecting 41600 events.
[11:48:17.977] INFO: 41600 events read in total (2752ms).
[11:48:17.978] INFO: Test took 3988ms.
[11:48:18.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:18.735] INFO: Expecting 41600 events.
[11:48:21.971] INFO: 41600 events read in total (2709ms).
[11:48:21.972] INFO: Test took 3943ms.
[11:48:21.005] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:22.722] INFO: Expecting 41600 events.
[11:48:25.945] INFO: 41600 events read in total (2696ms).
[11:48:25.946] INFO: Test took 3922ms.
[11:48:25.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:26.703] INFO: Expecting 41600 events.
[11:48:29.939] INFO: 41600 events read in total (2709ms).
[11:48:29.940] INFO: Test took 3946ms.
[11:48:29.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:30.701] INFO: Expecting 41600 events.
[11:48:33.970] INFO: 41600 events read in total (2743ms).
[11:48:33.971] INFO: Test took 3983ms.
[11:48:33.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:34.731] INFO: Expecting 41600 events.
[11:48:37.988] INFO: 41600 events read in total (2730ms).
[11:48:37.989] INFO: Test took 3969ms.
[11:48:38.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:38.745] INFO: Expecting 41600 events.
[11:48:41.988] INFO: 41600 events read in total (2716ms).
[11:48:41.989] INFO: Test took 3952ms.
[11:48:42.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:42.745] INFO: Expecting 41600 events.
[11:48:46.094] INFO: 41600 events read in total (2822ms).
[11:48:46.095] INFO: Test took 4058ms.
[11:48:46.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:46.850] INFO: Expecting 41600 events.
[11:48:50.099] INFO: 41600 events read in total (2722ms).
[11:48:50.100] INFO: Test took 3940ms.
[11:48:50.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:50.859] INFO: Expecting 41600 events.
[11:48:54.128] INFO: 41600 events read in total (2742ms).
[11:48:54.129] INFO: Test took 3982ms.
[11:48:54.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:54.884] INFO: Expecting 41600 events.
[11:48:58.139] INFO: 41600 events read in total (2728ms).
[11:48:58.140] INFO: Test took 3963ms.
[11:48:58.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:58.900] INFO: Expecting 41600 events.
[11:49:02.109] INFO: 41600 events read in total (2682ms).
[11:49:02.110] INFO: Test took 3922ms.
[11:49:02.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:02.871] INFO: Expecting 41600 events.
[11:49:06.080] INFO: 41600 events read in total (2682ms).
[11:49:06.081] INFO: Test took 3924ms.
[11:49:06.111] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:06.841] INFO: Expecting 41600 events.
[11:49:10.039] INFO: 41600 events read in total (2672ms).
[11:49:10.040] INFO: Test took 3912ms.
[11:49:10.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:10.798] INFO: Expecting 41600 events.
[11:49:13.975] INFO: 41600 events read in total (2650ms).
[11:49:13.976] INFO: Test took 3888ms.
[11:49:14.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:14.733] INFO: Expecting 41600 events.
[11:49:17.768] INFO: 41600 events read in total (2508ms).
[11:49:17.769] INFO: Test took 3746ms.
[11:49:17.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:18.177] INFO: enter test to run
[11:49:23.059] INFO: test: HighRate no parameter change
[11:49:23.059] INFO: running: highrate
[11:49:23.060] INFO: ----------------------------------------------------------------------
[11:49:23.060] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:49:23.060] INFO: ----------------------------------------------------------------------
[11:49:23.674] INFO: Expecting 208000 events.
[11:49:35.323] INFO: 208000 events read in total (11122ms).
[11:49:35.326] INFO: Test took 12258ms.
[11:49:35.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:35.702] INFO: number of dead pixels (per ROC): 0 0 0 0 1 70 0 0 0 0 0 1 0 0 0 0
[11:49:35.702] INFO: number of red-efficiency pixels: 55 44 63 132 114 280 129 74 78 116 97 88 86 65 14 17
[11:49:35.702] INFO: number of X-ray hits detected: 57107 37854 58646 93411 103090 103491 105298 68126 65704 86697 87196 72170 75693 44419 17434 21363
[11:49:35.702] 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:49:35.702] INFO: number of Vcal hits detected: 207944 207954 207936 207865 207833 200015 207864 207924 207920 207877 207899 207862 207912 207935 207986 207983
[11:49:35.702] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 98.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[11:49:35.703] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 96.2 99.9 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0
[11:49:35.703] INFO: X-ray hit rate [MHz/cm2]: 16.7 11.1 17.2 27.4 30.2 30.3 30.9 20.0 19.3 25.4 25.6 21.2 22.2 13.0 5.1 6.3
[11:49:35.703] INFO: PixTestHighRate::doXPixelAlive() done
[11:49:35.758] INFO: PixTest:: pg_setup set to default.
[11:49:35.775] INFO: enter test to run
[11:50:13.683] INFO: test: HighRate no parameter change
[11:50:13.683] INFO: running: highrate
[11:50:13.684] INFO: ----------------------------------------------------------------------
[11:50:13.684] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:50:13.684] INFO: ----------------------------------------------------------------------
[11:50:14.300] INFO: Expecting 208000 events.
[11:50:27.502] INFO: 208000 events read in total (12675ms).
[11:50:27.507] INFO: Test took 13814ms.
[11:50:27.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:28.067] INFO: number of dead pixels (per ROC): 0 0 0 0 1 57 0 0 0 0 0 1 0 0 0 0
[11:50:28.067] INFO: number of red-efficiency pixels: 165 103 180 377 391 576 508 264 261 301 282 254 276 156 37 57
[11:50:28.068] INFO: number of X-ray hits detected: 118619 78731 120862 193219 212665 215113 218344 140557 136734 179511 180898 148947 156173 91989 36215 44617
[11:50:28.068] 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:50:28.068] INFO: number of Vcal hits detected: 207821 207894 207810 207593 207538 199734 207429 207722 207726 207662 207707 207685 207714 207835 207963 207941
[11:50:28.068] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 98.5 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[11:50:28.068] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 96.0 99.7 99.9 99.9 99.8 99.9 99.8 99.9 99.9 100.0 100.0
[11:50:28.068] INFO: X-ray hit rate [MHz/cm2]: 34.8 23.1 35.4 56.6 62.3 63.1 64.0 41.2 40.1 52.6 53.0 43.7 45.8 27.0 10.6 13.1
[11:50:28.068] INFO: PixTestHighRate::doXPixelAlive() done
[11:50:28.118] INFO: PixTest:: pg_setup set to default.
[11:50:28.133] INFO: enter test to run
[11:50:47.035] INFO: test: HighRate no parameter change
[11:50:47.035] INFO: running: highrate
[11:50:47.036] INFO: ----------------------------------------------------------------------
[11:50:47.036] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:50:47.036] INFO: ----------------------------------------------------------------------
[11:50:47.650] INFO: Expecting 208000 events.
[11:51:02.513] INFO: 208000 events read in total (14336ms).
[11:51:02.520] INFO: Test took 15475ms.
[11:51:02.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:03.261] INFO: number of dead pixels (per ROC): 0 0 0 0 1 72 0 0 0 0 0 1 0 0 0 0
[11:51:03.261] INFO: number of red-efficiency pixels: 333 215 412 945 838 1199 1218 638 461 657 615 587 624 356 70 62
[11:51:03.261] INFO: number of X-ray hits detected: 181661 121673 184893 295377 325141 319742 333874 214966 210141 275973 278801 229360 240764 140788 55313 67685
[11:51:03.261] 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:51:03.261] INFO: number of Vcal hits detected: 207611 207767 207522 206857 206988 198865 206426 207237 207478 207219 207307 207271 207308 207584 207928 207937
[11:51:03.261] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.5 99.6 98.3 99.3 99.7 99.8 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[11:51:03.261] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.5 95.6 99.2 99.6 99.7 99.6 99.7 99.6 99.7 99.8 100.0 100.0
[11:51:03.261] INFO: X-ray hit rate [MHz/cm2]: 53.2 35.7 54.2 86.6 95.3 93.7 97.9 63.0 61.6 80.9 81.7 67.2 70.6 41.3 16.2 19.8
[11:51:03.261] INFO: PixTestHighRate::doXPixelAlive() done
[11:51:03.314] INFO: PixTest:: pg_setup set to default.
[11:51:03.330] INFO: enter test to run
[11:51:32.954] INFO: test: exit no parameter change
[11:51:33.424] QUIET: Connection to board 33 closed.
[11:51:33.439] INFO: pXar: this is the end, my friend