[16:11:45.491] INFO: *** Welcome to pxar ***
[16:11:45.491] INFO: *** Today: 2016/07/01
[16:11:45.506] INFO: *** Version: v1.9.0-814-g7497
[16:11:45.506] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C15.dat
[16:11:45.542] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:11:45.542] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[16:11:45.550] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[16:11:45.647] INFO: clk: 4
[16:11:45.647] INFO: ctr: 4
[16:11:45.647] INFO: sda: 19
[16:11:45.647] INFO: tin: 9
[16:11:45.647] INFO: level: 15
[16:11:45.647] INFO: triggerdelay: 0
[16:11:45.647] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:11:45.647] INFO: Log level: INFO
[16:11:45.663] QUIET: Connection to board DTB_WREKRL opened.
[16:11:45.667] 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:
------------------------------------------------------
[16:11:45.669] INFO: RPC call hashes of host and DTB match: 398089610
[16:11:47.205] INFO: DUT info:
[16:11:47.205] INFO: The DUT currently contains the following objects:
[16:11:47.205] INFO: 2 TBM Cores tbm08c (2 ON)
[16:11:47.206] INFO: TBM Core alpha (0): 7 registers set
[16:11:47.206] INFO: TBM Core beta (1): 7 registers set
[16:11:47.206] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:11:47.206] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.206] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.207] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:47.610] INFO: enter 'restricted' command line mode
[16:11:47.610] INFO: enter test to run
[16:11:49.917] INFO: test: PixelAlive no parameter change
[16:11:49.917] INFO: running: pixelalive
[16:11:49.927] INFO: ----------------------------------------------------------------------
[16:11:49.927] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:11:49.927] INFO: ----------------------------------------------------------------------
[16:11:50.253] INFO: Expecting 41600 events.
[16:11:54.609] INFO: 41600 events read in total (3637ms).
[16:11:54.775] INFO: Test took 4845ms.
[16:11:54.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:55.047] INFO: PixTestAlive::aliveTest() done
[16:11:55.047] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 1 0 0 0 0 0 0
[16:11:55.087] INFO: enter test to run
[16:13:37.677] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:13:37.677] INFO: running: highrate
[16:13:37.677] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:13:37.893] INFO: ----------------------------------------------------------------------
[16:13:37.893] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:13:37.893] INFO: ----------------------------------------------------------------------
[16:13:37.893] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:13:37.893] INFO: edge/corner pixel THR is adjusted
[16:13:37.893] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:13:38.852] INFO: Collecting data for 5 seconds...
[16:13:43.868] INFO: Done with hot pixel readout
[16:13:55.378] INFO: PixTest:: pg_setup set to default.
[16:13:55.379] INFO: 8 hot pixels found in step 0
[16:13:56.390] INFO: Collecting data for 5 seconds...
[16:14:01.408] INFO: Done with hot pixel readout
[16:14:12.895] INFO: PixTest:: pg_setup set to default.
[16:14:12.896] INFO: 10 hot pixels found in step 1
[16:14:13.887] INFO: Collecting data for 5 seconds...
[16:14:18.904] INFO: Done with hot pixel readout
[16:14:30.408] INFO: PixTest:: pg_setup set to default.
[16:14:30.408] INFO: 11 hot pixels found in step 2
[16:14:31.398] INFO: Collecting data for 5 seconds...
[16:14:36.415] INFO: Done with hot pixel readout
[16:14:47.936] INFO: PixTest:: pg_setup set to default.
[16:14:47.937] INFO: 6 hot pixels found in step 3
[16:14:48.927] INFO: Collecting data for 5 seconds...
[16:14:53.943] INFO: Done with hot pixel readout
[16:15:05.437] INFO: PixTest:: pg_setup set to default.
[16:15:05.437] INFO: 3 hot pixels found in step 4
[16:15:06.427] INFO: Collecting data for 5 seconds...
[16:15:11.443] INFO: Done with hot pixel readout
[16:15:22.968] INFO: PixTest:: pg_setup set to default.
[16:15:22.969] INFO: 6 hot pixels found in step 5
[16:15:23.959] INFO: Collecting data for 5 seconds...
[16:15:28.977] INFO: Done with hot pixel readout
[16:15:40.510] INFO: PixTest:: pg_setup set to default.
[16:15:40.511] INFO: 5 hot pixels found in step 6
[16:15:41.501] INFO: Collecting data for 5 seconds...
[16:15:46.518] INFO: Done with hot pixel readout
[16:15:57.981] INFO: PixTest:: pg_setup set to default.
[16:15:57.982] INFO: 6 hot pixels found in step 7
[16:15:58.971] INFO: Collecting data for 5 seconds...
[16:16:03.988] INFO: Done with hot pixel readout
[16:16:15.491] INFO: PixTest:: pg_setup set to default.
[16:16:15.491] INFO: 3 hot pixels found in step 8
[16:16:16.482] INFO: Collecting data for 5 seconds...
[16:16:21.499] INFO: Done with hot pixel readout
[16:16:32.973] INFO: PixTest:: pg_setup set to default.
[16:16:32.974] INFO: 2 hot pixels found in step 9
[16:16:33.963] INFO: Collecting data for 5 seconds...
[16:16:38.980] INFO: Done with hot pixel readout
[16:16:50.472] INFO: PixTest:: pg_setup set to default.
[16:16:50.473] INFO: 4 hot pixels found in step 10
[16:16:51.461] INFO: Collecting data for 5 seconds...
[16:16:56.478] INFO: Done with hot pixel readout
[16:17:08.037] INFO: PixTest:: pg_setup set to default.
[16:17:08.038] INFO: 7 hot pixels found in step 11
[16:17:09.028] INFO: Collecting data for 5 seconds...
[16:17:14.045] INFO: Done with hot pixel readout
[16:17:25.562] INFO: PixTest:: pg_setup set to default.
[16:17:25.563] INFO: 5 hot pixels found in step 12
[16:17:26.554] INFO: Collecting data for 5 seconds...
[16:17:31.571] INFO: Done with hot pixel readout
[16:17:43.063] INFO: PixTest:: pg_setup set to default.
[16:17:43.064] INFO: 3 hot pixels found in step 13
[16:17:44.054] INFO: Collecting data for 5 seconds...
[16:17:49.071] INFO: Done with hot pixel readout
[16:18:00.562] INFO: PixTest:: pg_setup set to default.
[16:18:00.563] INFO: 3 hot pixels found in step 14
[16:18:00.597] INFO: 3 hot pixels could not be trimmed and have been masked.
[16:18:00.600] INFO: PixTest::trimHotPixels() done
[16:18:00.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[16:18:00.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[16:18:00.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[16:18:00.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[16:18:00.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[16:18:00.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[16:18:00.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[16:18:00.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[16:18:00.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[16:18:00.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[16:18:00.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[16:18:00.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[16:18:00.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[16:18:00.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[16:18:00.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[16:18:00.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[16:18:00.686] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[16:18:00.700] INFO: enter test to run
[16:20:49.170] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:20:49.170] INFO: running: highrate
[16:20:49.174] INFO: ----------------------------------------------------------------------
[16:20:49.174] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:20:49.174] INFO: ----------------------------------------------------------------------
[16:20:49.174] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:20:49.174] INFO: edge/corner pixel THR is adjusted
[16:20:49.174] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:20:50.132] INFO: Collecting data for 1 seconds...
[16:20:51.136] INFO: Done with hot pixel readout
[16:20:54.992] INFO: PixTest:: pg_setup set to default.
[16:20:54.993] INFO: 0 hot pixels found in step 0
[16:20:54.998] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:20:55.094] INFO: PixTest::trimHotPixels() done
[16:20:55.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[16:20:55.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[16:20:55.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[16:20:55.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[16:20:55.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[16:20:55.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[16:20:55.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[16:20:55.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[16:20:55.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[16:20:55.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[16:20:55.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[16:20:55.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[16:20:55.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[16:20:55.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[16:20:55.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[16:20:55.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[16:20:55.183] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-49_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[16:20:55.193] INFO: enter test to run
[16:22:46.513] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:22:46.513] INFO: running: xray
[16:22:46.515] INFO: ----------------------------------------------------------------------
[16:22:46.515] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:22:46.515] INFO: ----------------------------------------------------------------------
[16:22:47.478] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:22:59.264] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:23:29.363] INFO: Resuming triggers.
[16:23:41.149] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:24:11.463] INFO: Resuming triggers.
[16:24:23.245] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:24:53.285] INFO: Resuming triggers.
[16:25:05.068] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:25:34.334] INFO: Resuming triggers.
[16:25:46.121] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[16:26:15.494] INFO: Resuming triggers.
[16:26:27.279] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:26:56.683] INFO: Resuming triggers.
[16:27:08.467] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:27:37.860] INFO: Resuming triggers.
[16:27:49.651] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:28:18.958] INFO: Resuming triggers.
[16:28:25.032] INFO: data taking finished, elapsed time: 100 seconds.
[16:28:40.443] INFO: PixTest:: pg_setup set to default.
[16:28:40.446] INFO: PixTestXray::doPhRun() done
[16:28:40.582] INFO: enter test to run
[16:31:39.693] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:31:39.693] INFO: running: xray
[16:31:39.694] INFO: ----------------------------------------------------------------------
[16:31:39.695] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:31:39.695] INFO: ----------------------------------------------------------------------
[16:31:40.658] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:31:47.742] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[16:32:18.046] INFO: Resuming triggers.
[16:32:25.129] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[16:32:55.346] INFO: Resuming triggers.
[16:33:02.427] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[16:33:33.406] INFO: Resuming triggers.
[16:33:40.488] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[16:34:11.035] INFO: Resuming triggers.
[16:34:18.118] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:34:49.344] INFO: Resuming triggers.
[16:34:56.426] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[16:35:27.873] INFO: Resuming triggers.
[16:35:34.954] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[16:36:06.769] INFO: Resuming triggers.
[16:36:13.849] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:36:44.502] INFO: Resuming triggers.
[16:36:51.590] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:37:21.777] INFO: Resuming triggers.
[16:37:28.859] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:37:59.155] INFO: Resuming triggers.
[16:38:06.237] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[16:38:36.431] INFO: Resuming triggers.
[16:38:43.511] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:39:13.719] INFO: Resuming triggers.
[16:39:20.802] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:39:51.124] INFO: Resuming triggers.
[16:39:58.204] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[16:40:28.426] INFO: Resuming triggers.
[16:40:29.631] INFO: data taking finished, elapsed time: 100 seconds.
[16:40:35.083] INFO: PixTest:: pg_setup set to default.
[16:40:35.087] INFO: PixTestXray::doPhRun() done
[16:40:35.243] INFO: enter test to run
[16:41:10.297] INFO: test: HighRate no parameter change
[16:41:10.298] INFO: running: highrate
[16:41:10.299] INFO: ----------------------------------------------------------------------
[16:41:10.299] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:41:10.299] INFO: ----------------------------------------------------------------------
[16:41:10.441] INFO: Expecting 768 events.
[16:41:11.575] INFO: 768 events read in total (419ms).
[16:41:11.575] INFO: Test took 1269ms.
[16:41:12.378] INFO: Expecting 41600 events.
[16:41:15.426] INFO: 41600 events read in total (2521ms).
[16:41:15.427] INFO: Test took 3844ms.
[16:41:15.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:16.192] INFO: Expecting 41600 events.
[16:41:19.340] INFO: 41600 events read in total (2621ms).
[16:41:19.341] INFO: Test took 3865ms.
[16:41:19.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:20.101] INFO: Expecting 41600 events.
[16:41:23.312] INFO: 41600 events read in total (2684ms).
[16:41:23.313] INFO: Test took 3925ms.
[16:41:23.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:24.073] INFO: Expecting 41600 events.
[16:41:27.296] INFO: 41600 events read in total (2696ms).
[16:41:27.297] INFO: Test took 3935ms.
[16:41:27.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:28.054] INFO: Expecting 41600 events.
[16:41:31.267] INFO: 41600 events read in total (2687ms).
[16:41:31.268] INFO: Test took 3922ms.
[16:41:31.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:32.025] INFO: Expecting 41600 events.
[16:41:35.229] INFO: 41600 events read in total (2677ms).
[16:41:35.230] INFO: Test took 3913ms.
[16:41:35.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:35.988] INFO: Expecting 41600 events.
[16:41:39.199] INFO: 41600 events read in total (2685ms).
[16:41:39.200] INFO: Test took 3920ms.
[16:41:39.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:39.958] INFO: Expecting 41600 events.
[16:41:43.185] INFO: 41600 events read in total (2701ms).
[16:41:43.186] INFO: Test took 3936ms.
[16:41:43.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:43.946] INFO: Expecting 41600 events.
[16:41:47.169] INFO: 41600 events read in total (2696ms).
[16:41:47.170] INFO: Test took 3934ms.
[16:41:47.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:47.929] INFO: Expecting 41600 events.
[16:41:51.140] INFO: 41600 events read in total (2684ms).
[16:41:51.141] INFO: Test took 3922ms.
[16:41:51.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:51.900] INFO: Expecting 41600 events.
[16:41:55.115] INFO: 41600 events read in total (2688ms).
[16:41:55.117] INFO: Test took 3926ms.
[16:41:55.156] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:55.877] INFO: Expecting 41600 events.
[16:41:59.088] INFO: 41600 events read in total (2684ms).
[16:41:59.089] INFO: Test took 3916ms.
[16:41:59.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:59.853] INFO: Expecting 41600 events.
[16:42:03.061] INFO: 41600 events read in total (2682ms).
[16:42:03.062] INFO: Test took 3924ms.
[16:42:03.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:03.824] INFO: Expecting 41600 events.
[16:42:07.041] INFO: 41600 events read in total (2690ms).
[16:42:07.042] INFO: Test took 3930ms.
[16:42:07.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:07.802] INFO: Expecting 41600 events.
[16:42:11.013] INFO: 41600 events read in total (2684ms).
[16:42:11.013] INFO: Test took 3922ms.
[16:42:11.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:11.772] INFO: Expecting 41600 events.
[16:42:14.984] INFO: 41600 events read in total (2685ms).
[16:42:14.985] INFO: Test took 3922ms.
[16:42:15.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:15.742] INFO: Expecting 41600 events.
[16:42:18.959] INFO: 41600 events read in total (2690ms).
[16:42:18.960] INFO: Test took 3926ms.
[16:42:18.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:19.722] INFO: Expecting 41600 events.
[16:42:22.940] INFO: 41600 events read in total (2691ms).
[16:42:22.941] INFO: Test took 3931ms.
[16:42:22.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:23.698] INFO: Expecting 41600 events.
[16:42:26.912] INFO: 41600 events read in total (2687ms).
[16:42:26.913] INFO: Test took 3921ms.
[16:42:26.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:27.672] INFO: Expecting 41600 events.
[16:42:30.739] INFO: 41600 events read in total (2540ms).
[16:42:30.740] INFO: Test took 3777ms.
[16:42:30.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:31.140] INFO: enter test to run
[16:43:19.457] INFO: test: HighRate no parameter change
[16:43:19.457] INFO: running: highrate
[16:43:19.458] INFO: ----------------------------------------------------------------------
[16:43:19.458] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:43:19.458] INFO: ----------------------------------------------------------------------
[16:43:20.072] INFO: Expecting 208000 events.
[16:43:31.832] INFO: 208000 events read in total (11233ms).
[16:43:31.835] INFO: Test took 12368ms.
[16:43:31.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:32.214] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 1 0 0 0 0 0 0
[16:43:32.214] INFO: number of red-efficiency pixels: 70 30 75 109 122 121 118 81 93 107 83 102 92 45 22 23
[16:43:32.214] INFO: number of X-ray hits detected: 57331 36430 62507 98919 109751 108181 105981 81717 75408 91323 83342 71979 73794 46099 18590 23200
[16:43:32.214] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:43:32.214] INFO: number of Vcal hits detected: 207928 207970 207876 207839 207873 207877 207879 207916 207904 207843 207917 207895 207907 207955 207978 207977
[16:43:32.214] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:43:32.214] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0
[16:43:32.214] INFO: X-ray hit rate [MHz/cm2]: 16.8 10.7 18.3 29.0 32.2 31.7 31.1 24.0 22.1 26.8 24.4 21.1 21.6 13.5 5.4 6.8
[16:43:32.214] INFO: PixTestHighRate::doXPixelAlive() done
[16:43:32.266] INFO: PixTest:: pg_setup set to default.
[16:43:32.283] INFO: enter test to run
[16:43:51.976] INFO: test: HighRate no parameter change
[16:43:51.976] INFO: running: highrate
[16:43:51.978] INFO: ----------------------------------------------------------------------
[16:43:51.978] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:43:51.978] INFO: ----------------------------------------------------------------------
[16:43:52.596] INFO: Expecting 208000 events.
[16:44:05.898] INFO: 208000 events read in total (12775ms).
[16:44:05.906] INFO: Test took 13919ms.
[16:44:06.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:06.482] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 1 0 0 0 0 0 0
[16:44:06.482] INFO: number of red-efficiency pixels: 189 94 262 381 389 458 376 284 250 337 284 262 229 133 40 58
[16:44:06.482] INFO: number of X-ray hits detected: 118703 74724 128228 203395 226748 221113 216648 168928 155236 187264 172204 148406 152136 95061 38851 47706
[16:44:06.482] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:44:06.482] INFO: number of Vcal hits detected: 207793 207903 207665 207531 207575 207498 207591 207704 207731 207599 207695 207724 207759 207863 207960 207942
[16:44:06.482] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:44:06.482] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:44:06.482] INFO: X-ray hit rate [MHz/cm2]: 34.8 21.9 37.6 59.6 66.5 64.8 63.5 49.5 45.5 54.9 50.5 43.5 44.6 27.9 11.4 14.0
[16:44:06.482] INFO: PixTestHighRate::doXPixelAlive() done
[16:44:06.535] INFO: PixTest:: pg_setup set to default.
[16:44:06.554] INFO: enter test to run
[16:44:37.704] INFO: test: HighRate no parameter change
[16:44:37.704] INFO: running: highrate
[16:44:37.705] INFO: ----------------------------------------------------------------------
[16:44:37.705] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:44:37.705] INFO: ----------------------------------------------------------------------
[16:44:38.325] INFO: Expecting 208000 events.
[16:44:53.504] INFO: 208000 events read in total (14652ms).
[16:44:53.511] INFO: Test took 15795ms.
[16:44:53.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:54.268] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 1 0 0 0 0 0 0
[16:44:54.268] INFO: number of red-efficiency pixels: 394 184 556 840 929 1055 870 557 592 857 655 589 551 264 77 77
[16:44:54.268] INFO: number of X-ray hits detected: 180646 113734 195000 307166 342889 334610 328575 256144 237015 282915 260615 225338 230183 144418 59351 72922
[16:44:54.268] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:44:54.268] INFO: number of Vcal hits detected: 207552 207808 207243 206965 206883 206676 206940 207348 207328 206955 207263 207346 207387 207710 207922 207920
[16:44:54.268] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.5 99.4 99.5 99.7 99.7 99.6 99.7 99.7 99.7 99.9 100.0 100.0
[16:44:54.268] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.5 99.5 99.4 99.5 99.7 99.7 99.5 99.6 99.7 99.7 99.9 100.0 100.0
[16:44:54.268] INFO: X-ray hit rate [MHz/cm2]: 52.9 33.3 57.2 90.0 100.5 98.1 96.3 75.1 69.5 82.9 76.4 66.0 67.5 42.3 17.4 21.4
[16:44:54.268] INFO: PixTestHighRate::doXPixelAlive() done
[16:44:54.313] INFO: PixTest:: pg_setup set to default.
[16:44:54.327] INFO: enter test to run
[16:45:51.872] INFO: test: exit no parameter change
[16:45:52.157] QUIET: Connection to board 33 closed.
[16:45:52.168] INFO: pXar: this is the end, my friend