[11:48:13.222] INFO: *** Welcome to pxar ***
[11:48:13.222] INFO: *** Today: 2016/09/09
[11:48:13.257] INFO: *** Version: v1.9.0-818-g96727
[11:48:13.257] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C15.dat
[11:48:13.281] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:48:13.281] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:48:13.286] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:48:13.372] INFO: clk: 4
[11:48:13.372] INFO: ctr: 4
[11:48:13.372] INFO: sda: 19
[11:48:13.372] INFO: tin: 9
[11:48:13.372] INFO: level: 15
[11:48:13.372] INFO: triggerdelay: 0
[11:48:13.372] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:48:13.372] INFO: Log level: INFO
[11:48:13.390] QUIET: Connection to board DTB_WREKRL opened.
[11:48:13.393] 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:48:13.396] INFO: RPC call hashes of host and DTB match: 398089610
[11:48:14.929] INFO: DUT info:
[11:48:14.929] INFO: The DUT currently contains the following objects:
[11:48:14.929] INFO: 2 TBM Cores tbm08c (2 ON)
[11:48:14.929] INFO: TBM Core alpha (0): 7 registers set
[11:48:14.929] INFO: TBM Core beta (1): 7 registers set
[11:48:14.929] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:48:14.929] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.929] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:14.930] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:48:15.333] INFO: enter 'restricted' command line mode
[11:48:15.333] INFO: enter test to run
[11:48:24.039] INFO: test: PixelAlive no parameter change
[11:48:24.039] INFO: running: pixelalive
[11:48:24.048] INFO: ----------------------------------------------------------------------
[11:48:24.048] 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:48:24.048] INFO: ----------------------------------------------------------------------
[11:48:24.366] INFO: Expecting 41600 events.
[11:48:28.698] INFO: 41600 events read in total (3613ms).
[11:48:28.867] INFO: Test took 4816ms.
[11:48:28.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:29.151] INFO: PixTestAlive::aliveTest() done
[11:48:29.151] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 1 0 0
[11:48:29.182] INFO: enter test to run
[11:49:07.063] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:49:07.063] INFO: running: highrate
[11:49:07.076] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:49:07.330] INFO: ----------------------------------------------------------------------
[11:49:07.330] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:49:07.330] INFO: ----------------------------------------------------------------------
[11:49:07.330] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:49:07.330] INFO: edge/corner pixel THR is adjusted
[11:49:07.330] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:49:08.289] INFO: Collecting data for 5 seconds...
[11:49:13.306] INFO: Done with hot pixel readout
[11:49:25.276] INFO: PixTest:: pg_setup set to default.
[11:49:25.277] INFO: 9 hot pixels found in step 0
[11:49:26.269] INFO: Collecting data for 5 seconds...
[11:49:31.287] INFO: Done with hot pixel readout
[11:49:43.112] INFO: PixTest:: pg_setup set to default.
[11:49:43.113] INFO: 14 hot pixels found in step 1
[11:49:44.110] INFO: Collecting data for 5 seconds...
[11:49:49.129] INFO: Done with hot pixel readout
[11:50:00.815] INFO: PixTest:: pg_setup set to default.
[11:50:00.815] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:00.815] INFO: 9 hot pixels found in step 2
[11:50:01.812] INFO: Collecting data for 5 seconds...
[11:50:06.829] INFO: Done with hot pixel readout
[11:50:18.531] INFO: PixTest:: pg_setup set to default.
[11:50:18.532] INFO: 7 hot pixels found in step 3
[11:50:19.528] INFO: Collecting data for 5 seconds...
[11:50:24.547] INFO: Done with hot pixel readout
[11:50:35.961] INFO: PixTest:: pg_setup set to default.
[11:50:35.962] INFO: 5 hot pixels found in step 4
[11:50:36.958] INFO: Collecting data for 5 seconds...
[11:50:41.976] INFO: Done with hot pixel readout
[11:50:53.393] INFO: PixTest:: pg_setup set to default.
[11:50:53.394] INFO: 9 hot pixels found in step 5
[11:50:54.390] INFO: Collecting data for 5 seconds...
[11:50:59.407] INFO: Done with hot pixel readout
[11:51:09.832] INFO: PixTest:: pg_setup set to default.
[11:51:09.833] INFO: 4 hot pixels found in step 6
[11:51:10.830] INFO: Collecting data for 5 seconds...
[11:51:15.849] INFO: Done with hot pixel readout
[11:51:27.064] INFO: PixTest:: pg_setup set to default.
[11:51:27.065] INFO: 5 hot pixels found in step 7
[11:51:28.060] INFO: Collecting data for 5 seconds...
[11:51:33.079] INFO: Done with hot pixel readout
[11:51:44.643] INFO: PixTest:: pg_setup set to default.
[11:51:44.644] INFO: 4 hot pixels found in step 8
[11:51:45.639] INFO: Collecting data for 5 seconds...
[11:51:50.657] INFO: Done with hot pixel readout
[11:52:02.557] INFO: PixTest:: pg_setup set to default.
[11:52:02.557] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:02.558] INFO: 4 hot pixels found in step 9
[11:52:03.556] INFO: Collecting data for 5 seconds...
[11:52:08.574] INFO: Done with hot pixel readout
[11:52:20.322] INFO: PixTest:: pg_setup set to default.
[11:52:20.323] INFO: 9 hot pixels found in step 10
[11:52:21.327] INFO: Collecting data for 5 seconds...
[11:52:26.347] INFO: Done with hot pixel readout
[11:52:37.697] INFO: PixTest:: pg_setup set to default.
[11:52:37.698] INFO: 5 hot pixels found in step 11
[11:52:38.694] INFO: Collecting data for 5 seconds...
[11:52:43.713] INFO: Done with hot pixel readout
[11:52:54.644] INFO: PixTest:: pg_setup set to default.
[11:52:54.645] INFO: 6 hot pixels found in step 12
[11:52:55.644] INFO: Collecting data for 5 seconds...
[11:53:00.662] INFO: Done with hot pixel readout
[11:53:11.633] INFO: PixTest:: pg_setup set to default.
[11:53:11.634] INFO: 1 hot pixels found in step 13
[11:53:12.631] INFO: Collecting data for 5 seconds...
[11:53:17.649] INFO: Done with hot pixel readout
[11:53:28.841] INFO: PixTest:: pg_setup set to default.
[11:53:29.117] INFO: 1 hot pixels found in step 14
[11:53:29.162] INFO: 1 hot pixels could not be trimmed and have been masked.
[11:53:29.246] INFO: PixTest::trimHotPixels() done
[11:53:29.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[11:53:29.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[11:53:29.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[11:53:29.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[11:53:29.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[11:53:29.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[11:53:29.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[11:53:29.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[11:53:29.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[11:53:29.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[11:53:29.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[11:53:29.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[11:53:29.348] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[11:53:29.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[11:53:29.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[11:53:29.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:53:29.370] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:53:29.402] INFO: enter test to run
[11:54:02.133] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:54:02.133] INFO: running: highrate
[11:54:02.138] INFO: ----------------------------------------------------------------------
[11:54:02.138] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:54:02.138] INFO: ----------------------------------------------------------------------
[11:54:02.138] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:54:02.138] INFO: edge/corner pixel THR is adjusted
[11:54:02.138] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:54:03.095] INFO: Collecting data for 1 seconds...
[11:54:04.098] INFO: Done with hot pixel readout
[11:54:08.249] INFO: PixTest:: pg_setup set to default.
[11:54:08.250] INFO: 0 hot pixels found in step 0
[11:54:08.256] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:54:08.346] INFO: PixTest::trimHotPixels() done
[11:54:08.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[11:54:08.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[11:54:08.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[11:54:08.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[11:54:08.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[11:54:08.376] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[11:54:08.381] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[11:54:08.387] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[11:54:08.392] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[11:54:08.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[11:54:08.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[11:54:08.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[11:54:08.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[11:54:08.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[11:54:08.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[11:54:08.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[11:54:08.435] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-43_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[11:54:08.445] INFO: enter test to run
[11:55:12.068] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:55:12.068] INFO: running: xray
[11:55:12.079] INFO: ----------------------------------------------------------------------
[11:55:12.080] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:55:12.080] INFO: ----------------------------------------------------------------------
[11:55:13.091] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:55:24.545] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:55:54.994] INFO: Resuming triggers.
[11:56:06.445] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:56:36.254] INFO: Resuming triggers.
[11:56:47.712] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:57:16.956] INFO: Resuming triggers.
[11:57:28.412] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:57:57.732] INFO: Resuming triggers.
[11:58:09.188] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:58:38.613] INFO: Resuming triggers.
[11:58:50.068] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:59:19.481] INFO: Resuming triggers.
[11:59:30.935] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:00:00.524] INFO: Resuming triggers.
[12:00:11.979] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:00:41.478] INFO: Resuming triggers.
[12:00:50.170] INFO: data taking finished, elapsed time: 100 seconds.
[12:01:12.527] INFO: PixTest:: pg_setup set to default.
[12:01:12.530] INFO: PixTestXray::doPhRun() done
[12:01:12.768] INFO: enter test to run
[12:02:13.313] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:02:13.313] INFO: running: xray
[12:02:13.315] INFO: ----------------------------------------------------------------------
[12:02:13.315] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:02:13.315] INFO: ----------------------------------------------------------------------
[12:02:14.279] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:02:20.000] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:02:51.623] INFO: Resuming triggers.
[12:02:58.340] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:03:28.954] INFO: Resuming triggers.
[12:03:35.676] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:04:06.480] INFO: Resuming triggers.
[12:04:13.196] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:04:43.153] INFO: Resuming triggers.
[12:04:49.871] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:05:20.383] INFO: Resuming triggers.
[12:05:27.102] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:05:58.090] INFO: Resuming triggers.
[12:06:04.802] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:06:36.018] INFO: Resuming triggers.
[12:06:42.736] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:07:13.667] INFO: Resuming triggers.
[12:07:20.384] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:07:51.526] INFO: Resuming triggers.
[12:07:58.236] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:08:29.443] INFO: Resuming triggers.
[12:08:36.155] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:09:06.699] INFO: Resuming triggers.
[12:09:13.410] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:09:43.467] INFO: Resuming triggers.
[12:09:50.180] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:10:20.212] INFO: Resuming triggers.
[12:10:26.925] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:10:56.948] INFO: Resuming triggers.
[12:11:03.273] INFO: data taking finished, elapsed time: 100 seconds.
[12:11:31.840] INFO: PixTest:: pg_setup set to default.
[12:11:31.843] INFO: PixTestXray::doPhRun() done
[12:11:31.994] INFO: enter test to run
[12:12:07.517] INFO: test: HighRate no parameter change
[12:12:07.517] INFO: running: highrate
[12:12:07.530] INFO: ----------------------------------------------------------------------
[12:12:07.530] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:12:07.530] INFO: ----------------------------------------------------------------------
[12:12:07.691] INFO: Expecting 768 events.
[12:12:08.825] INFO: 768 events read in total (419ms).
[12:12:08.825] INFO: Test took 1269ms.
[12:12:09.628] INFO: Expecting 41600 events.
[12:12:12.667] INFO: 41600 events read in total (2512ms).
[12:12:12.668] INFO: Test took 3782ms.
[12:12:12.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:13.430] INFO: Expecting 41600 events.
[12:12:16.609] INFO: 41600 events read in total (2652ms).
[12:12:16.610] INFO: Test took 3892ms.
[12:12:16.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:17.370] INFO: Expecting 41600 events.
[12:12:20.592] INFO: 41600 events read in total (2695ms).
[12:12:20.593] INFO: Test took 3931ms.
[12:12:20.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:21.351] INFO: Expecting 41600 events.
[12:12:24.586] INFO: 41600 events read in total (2708ms).
[12:12:24.587] INFO: Test took 3942ms.
[12:12:24.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:25.342] INFO: Expecting 41600 events.
[12:12:28.562] INFO: 41600 events read in total (2694ms).
[12:12:28.563] INFO: Test took 3924ms.
[12:12:28.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:29.323] INFO: Expecting 41600 events.
[12:12:32.556] INFO: 41600 events read in total (2706ms).
[12:12:32.557] INFO: Test took 3941ms.
[12:12:32.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:33.315] INFO: Expecting 41600 events.
[12:12:36.539] INFO: 41600 events read in total (2697ms).
[12:12:36.540] INFO: Test took 3931ms.
[12:12:36.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:37.295] INFO: Expecting 41600 events.
[12:12:40.525] INFO: 41600 events read in total (2703ms).
[12:12:40.546] INFO: Test took 3954ms.
[12:12:40.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:41.284] INFO: Expecting 41600 events.
[12:12:44.532] INFO: 41600 events read in total (2721ms).
[12:12:44.533] INFO: Test took 3934ms.
[12:12:44.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:45.291] INFO: Expecting 41600 events.
[12:12:48.528] INFO: 41600 events read in total (2711ms).
[12:12:48.529] INFO: Test took 3945ms.
[12:12:48.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:49.287] INFO: Expecting 41600 events.
[12:12:52.526] INFO: 41600 events read in total (2712ms).
[12:12:52.527] INFO: Test took 3944ms.
[12:12:52.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:53.287] INFO: Expecting 41600 events.
[12:12:56.532] INFO: 41600 events read in total (2719ms).
[12:12:56.533] INFO: Test took 3954ms.
[12:12:56.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:57.289] INFO: Expecting 41600 events.
[12:13:00.539] INFO: 41600 events read in total (2723ms).
[12:13:00.540] INFO: Test took 3955ms.
[12:13:00.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:01.295] INFO: Expecting 41600 events.
[12:13:04.526] INFO: 41600 events read in total (2704ms).
[12:13:04.527] INFO: Test took 3935ms.
[12:13:04.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:05.287] INFO: Expecting 41600 events.
[12:13:08.522] INFO: 41600 events read in total (2708ms).
[12:13:08.523] INFO: Test took 3943ms.
[12:13:08.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:09.282] INFO: Expecting 41600 events.
[12:13:12.527] INFO: 41600 events read in total (2718ms).
[12:13:12.528] INFO: Test took 3952ms.
[12:13:12.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:13.284] INFO: Expecting 41600 events.
[12:13:16.526] INFO: 41600 events read in total (2715ms).
[12:13:16.527] INFO: Test took 3947ms.
[12:13:16.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:17.285] INFO: Expecting 41600 events.
[12:13:20.520] INFO: 41600 events read in total (2708ms).
[12:13:20.521] INFO: Test took 3942ms.
[12:13:20.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:21.279] INFO: Expecting 41600 events.
[12:13:24.299] INFO: 41600 events read in total (2494ms).
[12:13:24.300] INFO: Test took 3727ms.
[12:13:24.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:25.061] INFO: Expecting 41600 events.
[12:13:28.207] INFO: 41600 events read in total (2619ms).
[12:13:28.208] INFO: Test took 3855ms.
[12:13:28.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:28.596] INFO: enter test to run
[12:13:39.773] INFO: test: HighRate no parameter change
[12:13:39.773] INFO: running: highrate
[12:13:39.774] INFO: ----------------------------------------------------------------------
[12:13:39.774] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:13:39.774] INFO: ----------------------------------------------------------------------
[12:13:40.410] INFO: Expecting 208000 events.
[12:13:52.249] INFO: 208000 events read in total (11312ms).
[12:13:52.252] INFO: Test took 12449ms.
[12:13:52.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:52.652] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[12:13:52.652] INFO: number of red-efficiency pixels: 81 68 96 123 145 135 170 92 79 121 128 115 88 90 27 30
[12:13:52.652] INFO: number of X-ray hits detected: 70927 40587 64591 96874 105726 111728 118627 79935 73665 101357 99659 87399 90882 58650 22437 26031
[12:13:52.652] 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:13:52.652] INFO: number of Vcal hits detected: 207915 207931 207902 207776 207852 207863 207822 207905 207920 207878 207870 207882 207911 207904 207973 207969
[12:13:52.652] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[12:13:52.652] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[12:13:52.652] INFO: X-ray hit rate [MHz/cm2]: 20.8 11.9 18.9 28.4 31.0 32.7 34.8 23.4 21.6 29.7 29.2 25.6 26.6 17.2 6.6 7.6
[12:13:52.652] INFO: PixTestHighRate::doXPixelAlive() done
[12:13:52.702] INFO: PixTest:: pg_setup set to default.
[12:13:52.719] INFO: enter test to run
[12:14:33.524] INFO: test: HighRate no parameter change
[12:14:33.524] INFO: running: highrate
[12:14:33.525] INFO: ----------------------------------------------------------------------
[12:14:33.525] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:14:33.525] INFO: ----------------------------------------------------------------------
[12:14:34.145] INFO: Expecting 208000 events.
[12:14:47.743] INFO: 208000 events read in total (13071ms).
[12:14:47.748] INFO: Test took 14214ms.
[12:14:48.038] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:48.336] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[12:14:48.336] INFO: number of red-efficiency pixels: 281 172 287 449 487 421 589 289 250 370 459 385 311 275 44 68
[12:14:48.336] INFO: number of X-ray hits detected: 145910 83767 132519 198740 218628 228892 244483 165210 151314 208421 205569 181148 188681 121330 47192 53982
[12:14:48.336] 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:14:48.336] INFO: number of Vcal hits detected: 207700 207814 207682 207426 207470 207549 207324 207691 207730 207603 207500 207590 207664 207700 207955 207931
[12:14:48.337] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[12:14:48.337] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:14:48.337] INFO: X-ray hit rate [MHz/cm2]: 42.8 24.6 38.8 58.3 64.1 67.1 71.7 48.4 44.4 61.1 60.3 53.1 55.3 35.6 13.8 15.8
[12:14:48.337] INFO: PixTestHighRate::doXPixelAlive() done
[12:14:48.384] INFO: PixTest:: pg_setup set to default.
[12:14:48.399] INFO: enter test to run
[12:15:15.724] INFO: test: HighRate no parameter change
[12:15:15.724] INFO: running: highrate
[12:15:15.725] INFO: ----------------------------------------------------------------------
[12:15:15.725] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:15:15.725] INFO: ----------------------------------------------------------------------
[12:15:16.340] INFO: Expecting 208000 events.
[12:15:31.752] INFO: 208000 events read in total (14886ms).
[12:15:31.760] INFO: Test took 16024ms.
[12:15:32.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:32.527] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[12:15:32.527] INFO: number of red-efficiency pixels: 619 325 649 928 1064 974 1485 597 481 760 1029 824 686 543 106 89
[12:15:32.527] INFO: number of X-ray hits detected: 219430 125695 199441 299380 329350 343735 366536 248739 228195 313460 309450 273872 282100 181260 70653 82386
[12:15:32.528] 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:15:32.528] INFO: number of Vcal hits detected: 207197 207649 207184 206775 206637 206780 205925 207267 207470 207129 206662 206998 207210 207274 207889 207907
[12:15:32.528] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.5 99.4 99.5 99.1 99.7 99.8 99.6 99.4 99.6 99.7 99.7 100.0 100.0
[12:15:32.528] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.6 99.4 99.3 99.4 99.0 99.6 99.7 99.6 99.4 99.5 99.6 99.7 99.9 100.0
[12:15:32.528] INFO: X-ray hit rate [MHz/cm2]: 64.3 36.8 58.5 87.8 96.5 100.8 107.4 72.9 66.9 91.9 90.7 80.3 82.7 53.1 20.7 24.1
[12:15:32.528] INFO: PixTestHighRate::doXPixelAlive() done
[12:15:32.579] INFO: PixTest:: pg_setup set to default.
[12:15:32.597] INFO: enter test to run
[12:16:08.155] INFO: test: exit no parameter change
[12:16:08.694] QUIET: Connection to board 33 closed.
[12:16:08.825] INFO: pXar: this is the end, my friend