[14:15:07.766] INFO: *** Welcome to pxar ***
[14:15:07.766] INFO: *** Today: 2016/06/07
[14:15:08.525] INFO: *** Version: v1.9.0-814-g7497
[14:15:08.525] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//dacParameters35_C15.dat
[14:15:08.589] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:15:08.589] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//defaultMaskFile.dat
[14:15:08.598] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C15.dat
[14:15:08.725] INFO: clk: 4
[14:15:08.725] INFO: ctr: 4
[14:15:08.725] INFO: sda: 19
[14:15:08.725] INFO: tin: 9
[14:15:08.725] INFO: level: 15
[14:15:08.725] INFO: triggerdelay: 0
[14:15:08.725] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:15:08.725] INFO: Log level: INFO
[14:15:08.743] QUIET: Connection to board DTB_WREK4U opened.
[14:15:08.747] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[14:15:08.749] INFO: RPC call hashes of host and DTB match: 398089610
[14:15:10.285] INFO: DUT info:
[14:15:10.285] INFO: The DUT currently contains the following objects:
[14:15:10.285] INFO: 2 TBM Cores tbm08c (2 ON)
[14:15:10.285] INFO: TBM Core alpha (0): 7 registers set
[14:15:10.285] INFO: TBM Core beta (1): 7 registers set
[14:15:10.285] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:15:10.285] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.285] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.285] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.285] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.285] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.285] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.286] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:10.700] INFO: enter 'restricted' command line mode
[14:15:10.700] INFO: enter test to run
[14:15:21.579] INFO: test: PixelAlive no parameter change
[14:15:21.579] INFO: running: pixelalive
[14:15:21.588] INFO: ----------------------------------------------------------------------
[14:15:21.588] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:15:21.589] INFO: ----------------------------------------------------------------------
[14:15:21.961] INFO: Expecting 41600 events.
[14:15:26.182] INFO: 41600 events read in total (3503ms).
[14:15:26.347] INFO: Test took 4756ms.
[14:15:26.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:26.630] INFO: PixTestAlive::aliveTest() done
[14:15:26.630] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[14:15:26.666] INFO: enter test to run
[14:16:25.683] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:16:25.683] INFO: running: highrate
[14:16:25.683] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:16:25.965] INFO: ----------------------------------------------------------------------
[14:16:25.965] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:16:25.965] INFO: ----------------------------------------------------------------------
[14:16:25.965] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:16:25.965] INFO: edge/corner pixel THR is adjusted
[14:16:25.965] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:16:26.923] INFO: Collecting data for 5 seconds...
[14:16:31.940] INFO: Done with hot pixel readout
[14:16:43.243] INFO: PixTest:: pg_setup set to default.
[14:16:43.244] INFO: 5 hot pixels found in step 0
[14:16:44.263] INFO: Collecting data for 5 seconds...
[14:16:49.281] INFO: Done with hot pixel readout
[14:17:01.149] INFO: PixTest:: pg_setup set to default.
[14:17:01.150] INFO: 8 hot pixels found in step 1
[14:17:02.142] INFO: Collecting data for 5 seconds...
[14:17:07.159] INFO: Done with hot pixel readout
[14:17:18.967] INFO: PixTest:: pg_setup set to default.
[14:17:18.968] INFO: 5 hot pixels found in step 2
[14:17:19.966] INFO: Collecting data for 5 seconds...
[14:17:24.983] INFO: Done with hot pixel readout
[14:17:37.276] INFO: PixTest:: pg_setup set to default.
[14:17:37.277] INFO: 3 hot pixels found in step 3
[14:17:38.273] INFO: Collecting data for 5 seconds...
[14:17:43.291] INFO: Done with hot pixel readout
[14:17:55.527] INFO: PixTest:: pg_setup set to default.
[14:17:55.528] INFO: 5 hot pixels found in step 4
[14:17:56.524] INFO: Collecting data for 5 seconds...
[14:18:01.544] INFO: Done with hot pixel readout
[14:18:13.971] INFO: PixTest:: pg_setup set to default.
[14:18:13.971] INFO: 8 hot pixels found in step 5
[14:18:14.968] INFO: Collecting data for 5 seconds...
[14:18:19.989] INFO: Done with hot pixel readout
[14:18:32.497] INFO: PixTest:: pg_setup set to default.
[14:18:32.498] INFO: 5 hot pixels found in step 6
[14:18:33.494] INFO: Collecting data for 5 seconds...
[14:18:38.515] INFO: Done with hot pixel readout
[14:18:50.801] INFO: PixTest:: pg_setup set to default.
[14:18:50.802] INFO: 7 hot pixels found in step 7
[14:18:51.798] INFO: Collecting data for 5 seconds...
[14:18:56.817] INFO: Done with hot pixel readout
[14:19:08.946] INFO: PixTest:: pg_setup set to default.
[14:19:08.947] INFO: 13 hot pixels found in step 8
[14:19:09.943] INFO: Collecting data for 5 seconds...
[14:19:14.959] INFO: Done with hot pixel readout
[14:19:27.056] INFO: PixTest:: pg_setup set to default.

[14:19:27.056] INFO: 8 hot pixels found in step 9
[14:19:28.052] INFO: Collecting data for 5 seconds...
[14:19:33.069] INFO: Done with hot pixel readout
[14:19:45.200] INFO: PixTest:: pg_setup set to default.
[14:19:45.201] INFO: 5 hot pixels found in step 10
[14:19:46.197] INFO: Collecting data for 5 seconds...
[14:19:51.213] INFO: Done with hot pixel readout
[14:20:03.320] INFO: PixTest:: pg_setup set to default.
[14:20:03.321] INFO: 5 hot pixels found in step 11
[14:20:04.317] INFO: Collecting data for 5 seconds...
[14:20:09.333] INFO: Done with hot pixel readout
[14:20:21.358] INFO: PixTest:: pg_setup set to default.
[14:20:21.359] INFO: 5 hot pixels found in step 12
[14:20:22.354] INFO: Collecting data for 5 seconds...
[14:20:27.370] INFO: Done with hot pixel readout
[14:20:39.406] INFO: PixTest:: pg_setup set to default.

[14:20:39.407] INFO: 7 hot pixels found in step 13
[14:20:40.403] INFO: Collecting data for 5 seconds...
[14:20:45.420] INFO: Done with hot pixel readout
[14:20:57.457] INFO: PixTest:: pg_setup set to default.
[14:20:57.458] INFO: 5 hot pixels found in step 14
[14:20:57.497] INFO: 5 hot pixels could not be trimmed and have been masked.
[14:20:57.501] INFO: PixTest::trimHotPixels() done
[14:20:57.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C0.dat
[14:20:57.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C1.dat
[14:20:57.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C2.dat
[14:20:57.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C3.dat
[14:20:57.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C4.dat
[14:20:57.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C5.dat
[14:20:57.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C6.dat
[14:20:57.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C7.dat
[14:20:57.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C8.dat
[14:20:57.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C9.dat
[14:20:57.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C10.dat
[14:20:57.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C11.dat
[14:20:57.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C12.dat
[14:20:57.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C13.dat
[14:20:57.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C14.dat
[14:20:57.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C15.dat
[14:20:57.590] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//defaultMaskFile.dat
[14:20:57.601] INFO: enter test to run
[14:21:33.217] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:21:33.217] INFO: running: highrate
[14:21:33.221] INFO: ----------------------------------------------------------------------
[14:21:33.221] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:21:33.221] INFO: ----------------------------------------------------------------------
[14:21:33.221] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:21:33.222] INFO: edge/corner pixel THR is adjusted
[14:21:33.222] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:21:34.179] INFO: Collecting data for 1 seconds...
[14:21:35.183] INFO: Done with hot pixel readout
[14:21:39.486] INFO: PixTest:: pg_setup set to default.
[14:21:39.487] INFO: 0 hot pixels found in step 0
[14:21:39.492] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:21:39.571] INFO: PixTest::trimHotPixels() done
[14:21:39.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C0.dat
[14:21:39.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C1.dat
[14:21:39.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C2.dat
[14:21:39.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C3.dat
[14:21:39.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C4.dat
[14:21:39.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C5.dat
[14:21:39.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C6.dat
[14:21:39.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C7.dat
[14:21:39.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C8.dat
[14:21:39.626] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C9.dat
[14:21:39.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C10.dat
[14:21:39.636] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C11.dat
[14:21:39.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C12.dat
[14:21:39.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C13.dat
[14:21:39.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C14.dat
[14:21:39.657] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//trimParameters35_C15.dat
[14:21:39.663] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-10_FPIXTest-17C-FNAL-160601-1533_2016-06-01_15h33m_1464813187/000_FPIXTest_p17//defaultMaskFile.dat
[14:21:39.673] INFO: enter test to run
[14:22:05.488] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:22:05.488] INFO: running: xray
[14:22:05.490] INFO: ----------------------------------------------------------------------
[14:22:05.490] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:22:05.490] INFO: ----------------------------------------------------------------------
[14:22:06.453] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:22:17.398] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:22:46.961] INFO: Resuming triggers.
[14:22:57.910] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:23:27.567] INFO: Resuming triggers.
[14:23:38.516] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:24:08.074] INFO: Resuming triggers.
[14:24:19.024] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:24:48.603] INFO: Resuming triggers.
[14:24:59.549] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:25:29.180] INFO: Resuming triggers.
[14:25:40.130] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:26:09.727] INFO: Resuming triggers.
[14:26:20.673] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:26:50.258] INFO: Resuming triggers.
[14:27:01.206] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:27:31.392] INFO: Resuming triggers.
[14:27:42.340] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:28:11.983] INFO: Resuming triggers.
[14:28:13.781] INFO: data taking finished, elapsed time: 100 seconds.
[14:28:18.838] INFO: PixTest:: pg_setup set to default.
[14:28:18.841] INFO: PixTestXray::doPhRun() done
[14:28:18.980] INFO: enter test to run
[14:28:57.389] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:28:57.389] INFO: running: xray
[14:28:57.390] INFO: ----------------------------------------------------------------------
[14:28:57.390] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:28:57.391] INFO: ----------------------------------------------------------------------
[14:28:58.372] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:29:04.542] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:29:36.322] INFO: Resuming triggers.
[14:29:42.493] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:30:13.429] INFO: Resuming triggers.
[14:30:19.599] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:30:49.606] INFO: Resuming triggers.
[14:30:55.779] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:31:25.881] INFO: Resuming triggers.
[14:31:32.052] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:32:02.235] INFO: Resuming triggers.
[14:32:08.406] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:32:38.566] INFO: Resuming triggers.
[14:32:44.738] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:33:14.836] INFO: Resuming triggers.
[14:33:21.008] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:33:51.183] INFO: Resuming triggers.
[14:33:57.357] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:34:27.495] INFO: Resuming triggers.
[14:34:33.671] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:35:03.735] INFO: Resuming triggers.
[14:35:09.910] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:35:39.000] INFO: Resuming triggers.
[14:35:46.174] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:36:16.331] INFO: Resuming triggers.
[14:36:22.504] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:36:52.603] INFO: Resuming triggers.
[14:36:58.773] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:37:28.873] INFO: Resuming triggers.
[14:37:35.046] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:38:05.194] INFO: Resuming triggers.
[14:38:11.366] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:38:42.487] INFO: Resuming triggers.
[14:38:44.062] INFO: data taking finished, elapsed time: 100 seconds.
[14:38:52.213] INFO: PixTest:: pg_setup set to default.
[14:38:52.216] INFO: PixTestXray::doPhRun() done
[14:38:52.370] INFO: enter test to run
[14:39:34.993] INFO: test: HighRate no parameter change
[14:39:34.993] INFO: running: highrate
[14:39:35.007] INFO: ----------------------------------------------------------------------
[14:39:35.007] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:39:35.007] INFO: ----------------------------------------------------------------------
[14:39:35.163] INFO: Expecting 768 events.
[14:39:36.310] INFO: 768 events read in total (424ms).
[14:39:36.311] INFO: Test took 1283ms.
[14:39:37.113] INFO: Expecting 41600 events.
[14:39:40.188] INFO: 41600 events read in total (2548ms).
[14:39:40.189] INFO: Test took 3871ms.
[14:39:40.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:40.937] INFO: Expecting 41600 events.
[14:39:44.291] INFO: 41600 events read in total (2827ms).
[14:39:44.291] INFO: Test took 4047ms.
[14:39:44.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:45.045] INFO: Expecting 41600 events.
[14:39:48.418] INFO: 41600 events read in total (2846ms).
[14:39:48.419] INFO: Test took 4070ms.
[14:39:48.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:49.171] INFO: Expecting 41600 events.
[14:39:52.474] INFO: 41600 events read in total (2776ms).
[14:39:52.475] INFO: Test took 3998ms.
[14:39:52.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:53.228] INFO: Expecting 41600 events.
[14:39:56.529] INFO: 41600 events read in total (2774ms).
[14:39:56.530] INFO: Test took 3998ms.
[14:39:56.568] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:57.280] INFO: Expecting 41600 events.
[14:40:00.701] INFO: 41600 events read in total (2894ms).
[14:40:00.702] INFO: Test took 4115ms.
[14:40:00.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:01.445] INFO: Expecting 41600 events.
[14:40:04.710] INFO: 41600 events read in total (2738ms).
[14:40:04.711] INFO: Test took 3951ms.
[14:40:04.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:05.458] INFO: Expecting 41600 events.
[14:40:08.770] INFO: 41600 events read in total (2785ms).
[14:40:08.771] INFO: Test took 4003ms.
[14:40:08.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:09.520] INFO: Expecting 41600 events.
[14:40:12.866] INFO: 41600 events read in total (2819ms).
[14:40:12.867] INFO: Test took 4039ms.
[14:40:12.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:13.621] INFO: Expecting 41600 events.
[14:40:16.929] INFO: 41600 events read in total (2781ms).
[14:40:16.930] INFO: Test took 4006ms.
[14:40:16.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:17.681] INFO: Expecting 41600 events.
[14:40:21.009] INFO: 41600 events read in total (2801ms).
[14:40:21.010] INFO: Test took 4023ms.
[14:40:21.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:21.761] INFO: Expecting 41600 events.
[14:40:25.074] INFO: 41600 events read in total (2787ms).
[14:40:25.075] INFO: Test took 4008ms.
[14:40:25.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:25.809] INFO: Expecting 41600 events.
[14:40:29.112] INFO: 41600 events read in total (2776ms).
[14:40:29.113] INFO: Test took 3977ms.
[14:40:29.152] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:29.868] INFO: Expecting 41600 events.
[14:40:33.188] INFO: 41600 events read in total (2793ms).
[14:40:33.189] INFO: Test took 4018ms.
[14:40:33.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:33.940] INFO: Expecting 41600 events.
[14:40:37.333] INFO: 41600 events read in total (2866ms).
[14:40:37.334] INFO: Test took 4087ms.
[14:40:37.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:38.082] INFO: Expecting 41600 events.
[14:40:41.503] INFO: 41600 events read in total (2894ms).
[14:40:41.504] INFO: Test took 4112ms.
[14:40:41.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:42.251] INFO: Expecting 41600 events.
[14:40:45.573] INFO: 41600 events read in total (2795ms).
[14:40:45.574] INFO: Test took 4013ms.
[14:40:45.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:46.324] INFO: Expecting 41600 events.
[14:40:49.633] INFO: 41600 events read in total (2782ms).
[14:40:49.634] INFO: Test took 4003ms.
[14:40:49.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:50.388] INFO: Expecting 41600 events.
[14:40:53.701] INFO: 41600 events read in total (2786ms).
[14:40:53.702] INFO: Test took 4010ms.
[14:40:53.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:54.441] INFO: Expecting 41600 events.
[14:40:57.586] INFO: 41600 events read in total (2619ms).
[14:40:57.587] INFO: Test took 3826ms.
[14:40:57.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:57.979] INFO: enter test to run
[14:41:09.632] INFO: test: HighRate no parameter change
[14:41:09.632] INFO: running: highrate
[14:41:09.633] INFO: ----------------------------------------------------------------------
[14:41:09.633] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:41:09.633] INFO: ----------------------------------------------------------------------
[14:41:10.255] INFO: Expecting 208000 events.
[14:41:22.551] INFO: 208000 events read in total (11769ms).
[14:41:22.554] INFO: Test took 12912ms.
[14:41:22.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:22.978] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[14:41:22.978] INFO: number of red-efficiency pixels: 95 64 91 153 155 178 148 145 86 130 139 107 119 81 16 33
[14:41:22.978] INFO: number of X-ray hits detected: 75811 49552 77786 124315 127900 127906 129836 94249 87893 108918 104538 94297 98169 58571 24118 25600
[14:41:22.978] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:41:22.978] INFO: number of Vcal hits detected: 207900 207935 207907 207841 207840 207816 207802 207850 207914 207864 207860 207879 207880 207917 207984 207967
[14:41:22.978] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:41:22.978] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:41:22.978] INFO: X-ray hit rate [MHz/cm2]: 22.2 14.5 22.8 36.4 37.5 37.5 38.1 27.6 25.8 31.9 30.6 27.6 28.8 17.2 7.1 7.5
[14:41:22.978] INFO: PixTestHighRate::doXPixelAlive() done
[14:41:23.026] INFO: PixTest:: pg_setup set to default.
[14:41:23.040] INFO: enter test to run
[14:41:59.599] INFO: test: HighRate no parameter change
[14:41:59.599] INFO: running: highrate
[14:41:59.600] INFO: ----------------------------------------------------------------------
[14:41:59.600] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:41:59.600] INFO: ----------------------------------------------------------------------
[14:42:00.215] INFO: Expecting 208000 events.
[14:42:13.657] INFO: 208000 events read in total (12915ms).
[14:42:13.665] INFO: Test took 14057ms.
[14:42:14.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:14.356] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[14:42:14.356] INFO: number of red-efficiency pixels: 240 160 296 663 643 660 550 491 282 415 450 340 378 276 52 43
[14:42:14.356] INFO: number of X-ray hits detected: 158831 103256 164322 260518 267778 268080 272631 198612 184215 228154 219276 199320 204851 122782 50078 53971
[14:42:14.356] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:42:14.356] INFO: number of Vcal hits detected: 207742 207832 207680 207257 207274 207243 207351 207418 207696 207557 207509 207623 207598 207699 207945 207956
[14:42:14.356] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.7 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:42:14.356] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.6 99.7 99.6 99.7 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:42:14.356] INFO: X-ray hit rate [MHz/cm2]: 46.6 30.3 48.2 76.4 78.5 78.6 79.9 58.2 54.0 66.9 64.3 58.4 60.0 36.0 14.7 15.8
[14:42:14.356] INFO: PixTestHighRate::doXPixelAlive() done
[14:42:14.400] INFO: PixTest:: pg_setup set to default.
[14:42:14.410] INFO: enter test to run
[14:42:44.415] INFO: test: HighRate no parameter change
[14:42:44.415] INFO: running: highrate
[14:42:44.416] INFO: ----------------------------------------------------------------------
[14:42:44.416] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:42:44.417] INFO: ----------------------------------------------------------------------
[14:42:45.037] INFO: Expecting 208000 events.
[14:43:01.458] INFO: 208000 events read in total (15894ms).
[14:43:01.466] INFO: Test took 17039ms.
[14:43:01.996] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:02.373] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[14:43:02.373] INFO: number of red-efficiency pixels: 530 368 688 1559 1410 1615 1323 1060 691 961 1103 729 870 626 85 95
[14:43:02.373] INFO: number of X-ray hits detected: 239924 156766 248699 396162 406849 404920 412405 300859 280807 345791 330912 300502 309992 186773 76411 82134
[14:43:02.373] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:43:02.373] INFO: number of Vcal hits detected: 207348 207574 207076 205747 206082 205687 206182 206501 207221 206863 206608 207096 206951 207194 207914 207905
[14:43:02.373] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.0 99.2 99.0 99.2 99.4 99.6 99.5 99.4 99.6 99.5 99.7 100.0 100.0
[14:43:02.373] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 98.9 99.1 98.9 99.1 99.3 99.6 99.5 99.3 99.6 99.5 99.6 100.0 100.0
[14:43:02.373] INFO: X-ray hit rate [MHz/cm2]: 70.3 45.9 72.9 116.1 119.3 118.7 120.9 88.2 82.3 101.4 97.0 88.1 90.9 54.7 22.4 24.1
[14:43:02.373] INFO: PixTestHighRate::doXPixelAlive() done
[14:43:02.434] INFO: PixTest:: pg_setup set to default.
[14:43:02.450] INFO: enter test to run
[14:43:07.975] INFO: test: exit no parameter change
[14:43:08.321] QUIET: Connection to board 32 closed.
[14:43:08.322] INFO: pXar: this is the end, my friend