[15:56:56.975] INFO: *** Welcome to pxar ***
[15:56:56.975] INFO: *** Today: 2016/09/22
[15:56:58.568] INFO: *** Version: v1.9.0-818-g96727
[15:56:58.568] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//dacParameters35_C15.dat
[15:56:58.622] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:56:58.622] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[15:56:58.626] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[15:56:58.749] INFO: clk: 4
[15:56:58.749] INFO: ctr: 4
[15:56:58.749] INFO: sda: 19
[15:56:58.749] INFO: tin: 9
[15:56:58.749] INFO: level: 15
[15:56:58.749] INFO: triggerdelay: 0
[15:56:58.749] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:56:58.749] INFO: Log level: INFO
[15:56:58.768] QUIET: Connection to board DTB_WREKRL opened.
[15:56:58.771] 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:
------------------------------------------------------
[15:56:58.774] INFO: RPC call hashes of host and DTB match: 398089610
[15:57:00.335] INFO: DUT info:
[15:57:00.335] INFO: The DUT currently contains the following objects:
[15:57:00.336] INFO: 2 TBM Cores tbm08c (2 ON)
[15:57:00.336] INFO: TBM Core alpha (0): 7 registers set
[15:57:00.336] INFO: TBM Core beta (1): 7 registers set
[15:57:00.336] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:57:00.336] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.336] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:00.818] INFO: enter 'restricted' command line mode
[15:57:00.818] INFO: enter test to run
[15:57:04.731] INFO: test: PixelAlive no parameter change
[15:57:04.731] INFO: running: pixelalive
[15:57:04.799] INFO: ----------------------------------------------------------------------
[15:57:04.799] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:57:04.799] INFO: ----------------------------------------------------------------------
[15:57:05.123] INFO: Expecting 41600 events.
[15:57:09.550] INFO: 41600 events read in total (3708ms).
[15:57:09.715] INFO: Test took 4913ms.
[15:57:09.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:10.028] INFO: PixTestAlive::aliveTest() done
[15:57:10.028] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 2 0 0 0 0 0 0 0 0 0
[15:57:10.067] INFO: enter test to run
[15:58:18.515] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:58:18.515] INFO: running: highrate
[15:58:18.525] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:58:18.778] INFO: ----------------------------------------------------------------------
[15:58:18.778] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:58:18.778] INFO: ----------------------------------------------------------------------
[15:58:18.778] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:58:18.778] INFO: edge/corner pixel THR is adjusted
[15:58:18.778] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:58:19.764] INFO: Collecting data for 5 seconds...
[15:58:24.780] INFO: Done with hot pixel readout
[15:58:36.546] INFO: PixTest:: pg_setup set to default.
[15:58:36.547] INFO: 12 hot pixels found in step 0
[15:58:37.536] INFO: Collecting data for 5 seconds...
[15:58:42.552] INFO: Done with hot pixel readout
[15:58:54.230] INFO: PixTest:: pg_setup set to default.
[15:58:54.231] INFO: 13 hot pixels found in step 1
[15:58:55.224] INFO: Collecting data for 5 seconds...
[15:59:00.240] INFO: Done with hot pixel readout
[15:59:11.942] INFO: PixTest:: pg_setup set to default.
[15:59:11.943] INFO: 11 hot pixels found in step 2
[15:59:12.935] INFO: Collecting data for 5 seconds...
[15:59:17.951] INFO: Done with hot pixel readout
[15:59:29.666] INFO: PixTest:: pg_setup set to default.
[15:59:29.667] INFO: 14 hot pixels found in step 3
[15:59:30.660] INFO: Collecting data for 5 seconds...
[15:59:35.677] INFO: Done with hot pixel readout
[15:59:47.378] INFO: PixTest:: pg_setup set to default.
[15:59:47.379] INFO: 12 hot pixels found in step 4
[15:59:48.371] INFO: Collecting data for 5 seconds...
[15:59:53.387] INFO: Done with hot pixel readout
[16:00:05.053] INFO: PixTest:: pg_setup set to default.

[16:00:05.054] INFO: 8 hot pixels found in step 5
[16:00:06.047] INFO: Collecting data for 5 seconds...
[16:00:11.063] INFO: Done with hot pixel readout
[16:00:22.778] INFO: PixTest:: pg_setup set to default.

[16:00:22.779] INFO: 7 hot pixels found in step 6
[16:00:23.771] INFO: Collecting data for 5 seconds...
[16:00:28.787] INFO: Done with hot pixel readout
[16:00:40.491] INFO: PixTest:: pg_setup set to default.


[16:00:40.492] INFO: 7 hot pixels found in step 7
[16:00:41.485] INFO: Collecting data for 5 seconds...
[16:00:46.501] INFO: Done with hot pixel readout
[16:00:58.218] INFO: PixTest:: pg_setup set to default.


[16:00:58.219] INFO: 9 hot pixels found in step 8
[16:00:59.210] INFO: Collecting data for 5 seconds...
[16:01:04.227] INFO: Done with hot pixel readout
[16:01:15.949] INFO: PixTest:: pg_setup set to default.

[16:01:15.950] INFO: 7 hot pixels found in step 9
[16:01:16.942] INFO: Collecting data for 5 seconds...
[16:01:21.958] INFO: Done with hot pixel readout
[16:01:33.687] INFO: PixTest:: pg_setup set to default.

[16:01:33.688] INFO: 3 hot pixels found in step 10
[16:01:34.679] INFO: Collecting data for 5 seconds...
[16:01:39.696] INFO: Done with hot pixel readout
[16:01:51.399] INFO: PixTest:: pg_setup set to default.

[16:01:51.400] INFO: 6 hot pixels found in step 11
[16:01:52.393] INFO: Collecting data for 5 seconds...
[16:01:57.408] INFO: Done with hot pixel readout
[16:02:09.125] INFO: PixTest:: pg_setup set to default.

[16:02:09.126] INFO: 5 hot pixels found in step 12
[16:02:10.118] INFO: Collecting data for 5 seconds...
[16:02:15.136] INFO: Done with hot pixel readout
[16:02:26.678] INFO: PixTest:: pg_setup set to default.
[16:02:26.679] INFO: 0 hot pixels found in step 13
[16:02:26.715] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:02:26.719] INFO: PixTest::trimHotPixels() done
[16:02:26.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat
[16:02:26.724] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C1.dat
[16:02:26.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C2.dat
[16:02:26.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C3.dat
[16:02:26.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C4.dat
[16:02:26.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C5.dat
[16:02:26.753] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C6.dat
[16:02:26.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C7.dat
[16:02:26.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C8.dat
[16:02:26.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C9.dat
[16:02:26.775] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C10.dat
[16:02:26.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C11.dat
[16:02:26.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C12.dat
[16:02:26.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C13.dat
[16:02:26.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C14.dat
[16:02:26.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[16:02:26.808] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[16:02:26.818] INFO: enter test to run
[16:03:06.401] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:03:06.401] INFO: running: highrate
[16:03:06.405] INFO: ----------------------------------------------------------------------
[16:03:06.406] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:03:06.406] INFO: ----------------------------------------------------------------------
[16:03:06.406] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:03:06.406] INFO: edge/corner pixel THR is adjusted
[16:03:06.406] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:03:07.363] INFO: Collecting data for 1 seconds...
[16:03:08.367] INFO: Done with hot pixel readout
[16:03:12.329] INFO: PixTest:: pg_setup set to default.
[16:03:12.330] INFO: 0 hot pixels found in step 0
[16:03:12.335] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:03:12.427] INFO: PixTest::trimHotPixels() done
[16:03:12.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C0.dat
[16:03:12.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C1.dat
[16:03:12.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C2.dat
[16:03:12.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C3.dat
[16:03:12.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C4.dat
[16:03:12.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C5.dat
[16:03:12.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C6.dat
[16:03:12.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C7.dat
[16:03:12.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C8.dat
[16:03:12.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C9.dat
[16:03:12.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C10.dat
[16:03:12.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C11.dat
[16:03:12.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C12.dat
[16:03:12.505] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C13.dat
[16:03:12.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C14.dat
[16:03:12.516] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//trimParameters35_C15.dat
[16:03:12.521] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-39_FPIXTest-17C-FNAL-160916-1208-150V_2016-09-16_12h08m_1474045711/000_FPIXTest_p17//defaultMaskFile.dat
[16:03:12.531] INFO: enter test to run
[16:03:41.073] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:03:41.073] INFO: running: xray
[16:03:41.074] INFO: ----------------------------------------------------------------------
[16:03:41.074] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:03:41.074] INFO: ----------------------------------------------------------------------
[16:03:42.037] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:03:53.511] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:04:23.507] INFO: Resuming triggers.
[16:04:34.984] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:05:04.878] INFO: Resuming triggers.
[16:05:16.359] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:05:46.373] INFO: Resuming triggers.
[16:05:57.852] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:06:28.451] INFO: Resuming triggers.
[16:06:39.927] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:07:09.948] INFO: Resuming triggers.
[16:07:21.431] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[16:07:51.027] INFO: Resuming triggers.
[16:08:02.504] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:08:32.742] INFO: Resuming triggers.
[16:08:44.220] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:09:14.143] INFO: Resuming triggers.
[16:09:22.679] INFO: data taking finished, elapsed time: 100 seconds.
[16:09:44.862] INFO: PixTest:: pg_setup set to default.
[16:09:44.866] INFO: PixTestXray::doPhRun() done
[16:09:44.003] INFO: enter test to run
[16:10:24.862] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:10:24.862] INFO: running: xray
[16:10:24.863] INFO: ----------------------------------------------------------------------
[16:10:24.863] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:10:24.863] INFO: ----------------------------------------------------------------------
[16:10:25.838] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:10:32.594] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:11:02.847] INFO: Resuming triggers.
[16:11:09.608] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:11:39.825] INFO: Resuming triggers.
[16:11:46.580] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:12:16.754] INFO: Resuming triggers.
[16:12:23.511] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:12:53.750] INFO: Resuming triggers.
[16:13:00.510] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:13:30.696] INFO: Resuming triggers.
[16:13:37.453] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:14:07.731] INFO: Resuming triggers.
[16:14:14.486] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:14:44.703] INFO: Resuming triggers.
[16:14:51.463] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:15:21.685] INFO: Resuming triggers.
[16:15:28.443] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:15:58.464] INFO: Resuming triggers.
[16:16:05.226] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:16:35.295] INFO: Resuming triggers.
[16:16:42.054] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:17:13.338] INFO: Resuming triggers.
[16:17:20.098] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:17:51.095] INFO: Resuming triggers.
[16:17:57.853] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:18:28.985] INFO: Resuming triggers.
[16:18:35.744] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:19:07.403] INFO: Resuming triggers.
[16:19:13.130] INFO: data taking finished, elapsed time: 100 seconds.
[16:19:40.376] INFO: PixTest:: pg_setup set to default.
[16:19:40.379] INFO: PixTestXray::doPhRun() done
[16:19:40.537] INFO: enter test to run
[16:20:12.690] INFO: test: HighRate no parameter change
[16:20:12.690] INFO: running: highrate
[16:20:12.691] INFO: ----------------------------------------------------------------------
[16:20:12.691] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:20:12.691] INFO: ----------------------------------------------------------------------
[16:20:12.868] INFO: Expecting 768 events.
[16:20:13.003] INFO: 768 events read in total (419ms).
[16:20:13.003] INFO: Test took 1269ms.
[16:20:14.806] INFO: Expecting 41600 events.
[16:20:18.036] INFO: 41600 events read in total (2703ms).
[16:20:18.037] INFO: Test took 4026ms.
[16:20:18.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:18.793] INFO: Expecting 41600 events.
[16:20:22.095] INFO: 41600 events read in total (2775ms).
[16:20:22.096] INFO: Test took 4007ms.
[16:20:22.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:22.854] INFO: Expecting 41600 events.
[16:20:26.097] INFO: 41600 events read in total (2716ms).
[16:20:26.098] INFO: Test took 3950ms.
[16:20:26.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:26.854] INFO: Expecting 41600 events.
[16:20:30.094] INFO: 41600 events read in total (2713ms).
[16:20:30.095] INFO: Test took 3946ms.
[16:20:30.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:30.848] INFO: Expecting 41600 events.
[16:20:34.094] INFO: 41600 events read in total (2719ms).
[16:20:34.095] INFO: Test took 3947ms.
[16:20:34.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:34.854] INFO: Expecting 41600 events.
[16:20:38.089] INFO: 41600 events read in total (2708ms).
[16:20:38.090] INFO: Test took 3942ms.
[16:20:38.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:38.850] INFO: Expecting 41600 events.
[16:20:42.085] INFO: 41600 events read in total (2708ms).
[16:20:42.086] INFO: Test took 3944ms.
[16:20:42.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:42.845] INFO: Expecting 41600 events.
[16:20:46.082] INFO: 41600 events read in total (2710ms).
[16:20:46.083] INFO: Test took 3946ms.
[16:20:46.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:46.843] INFO: Expecting 41600 events.
[16:20:50.075] INFO: 41600 events read in total (2705ms).
[16:20:50.076] INFO: Test took 3942ms.
[16:20:50.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:50.834] INFO: Expecting 41600 events.
[16:20:54.075] INFO: 41600 events read in total (2714ms).
[16:20:54.076] INFO: Test took 3948ms.
[16:20:54.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:54.837] INFO: Expecting 41600 events.
[16:20:58.091] INFO: 41600 events read in total (2728ms).
[16:20:58.092] INFO: Test took 3965ms.
[16:20:58.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:58.850] INFO: Expecting 41600 events.
[16:21:02.085] INFO: 41600 events read in total (2708ms).
[16:21:02.086] INFO: Test took 3942ms.
[16:21:02.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:02.841] INFO: Expecting 41600 events.
[16:21:06.075] INFO: 41600 events read in total (2707ms).
[16:21:06.076] INFO: Test took 3937ms.
[16:21:06.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:06.836] INFO: Expecting 41600 events.
[16:21:10.080] INFO: 41600 events read in total (2717ms).
[16:21:10.081] INFO: Test took 3953ms.
[16:21:10.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:10.839] INFO: Expecting 41600 events.
[16:21:14.078] INFO: 41600 events read in total (2712ms).
[16:21:14.079] INFO: Test took 3947ms.
[16:21:14.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:14.838] INFO: Expecting 41600 events.
[16:21:18.081] INFO: 41600 events read in total (2716ms).
[16:21:18.082] INFO: Test took 3951ms.
[16:21:18.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:18.837] INFO: Expecting 41600 events.
[16:21:22.079] INFO: 41600 events read in total (2715ms).
[16:21:22.080] INFO: Test took 3946ms.
[16:21:22.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:22.839] INFO: Expecting 41600 events.
[16:21:26.087] INFO: 41600 events read in total (2721ms).
[16:21:26.088] INFO: Test took 3954ms.
[16:21:26.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:26.845] INFO: Expecting 41600 events.
[16:21:30.071] INFO: 41600 events read in total (2699ms).
[16:21:30.072] INFO: Test took 3932ms.
[16:21:30.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:30.830] INFO: Expecting 41600 events.
[16:21:33.896] INFO: 41600 events read in total (2539ms).
[16:21:33.897] INFO: Test took 3773ms.
[16:21:33.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:34.296] INFO: enter test to run
[16:22:01.945] INFO: test: HighRate no parameter change
[16:22:01.945] INFO: running: highrate
[16:22:01.946] INFO: ----------------------------------------------------------------------
[16:22:01.946] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:22:01.946] INFO: ----------------------------------------------------------------------
[16:22:02.563] INFO: Expecting 208000 events.
[16:22:14.406] INFO: 208000 events read in total (11316ms).
[16:22:14.409] INFO: Test took 12454ms.
[16:22:14.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:14.802] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 2 0 0 0 0 0 0 0 0 0
[16:22:14.802] INFO: number of red-efficiency pixels: 67 41 78 134 141 177 139 96 93 123 107 77 104 62 33 35
[16:22:14.802] INFO: number of X-ray hits detected: 62511 40478 68272 104861 110312 117150 112152 77879 70654 97456 94494 80132 84107 51603 23661 27566
[16:22:14.802] 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:22:14.802] INFO: number of Vcal hits detected: 207931 207957 207920 207860 207857 207769 207756 207901 207906 207874 207889 207921 207893 207937 207965 207965
[16:22:14.802] 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 100.0 100.0 100.0 100.0 100.0
[16:22:14.802] 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 100.0 99.9 100.0 100.0 100.0
[16:22:14.802] INFO: X-ray hit rate [MHz/cm2]: 18.3 11.9 20.0 30.7 32.3 34.3 32.9 22.8 20.7 28.6 27.7 23.5 24.7 15.1 6.9 8.1
[16:22:14.802] INFO: PixTestHighRate::doXPixelAlive() done
[16:22:14.849] INFO: PixTest:: pg_setup set to default.
[16:22:14.861] INFO: enter test to run
[16:22:36.401] INFO: test: HighRate no parameter change
[16:22:36.401] INFO: running: highrate
[16:22:36.402] INFO: ----------------------------------------------------------------------
[16:22:36.402] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:22:36.402] INFO: ----------------------------------------------------------------------
[16:22:37.019] INFO: Expecting 208000 events.
[16:22:50.595] INFO: 208000 events read in total (13049ms).
[16:22:50.600] INFO: Test took 14189ms.
[16:22:50.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:51.194] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 2 0 0 0 0 0 0 0 0 0
[16:22:51.194] INFO: number of red-efficiency pixels: 234 131 308 517 473 619 547 330 222 432 332 302 264 201 58 74
[16:22:51.194] INFO: number of X-ray hits detected: 128784 84253 141415 218115 229975 243158 233473 162913 146158 202426 196297 166940 177365 109264 49141 57437
[16:22:51.194] 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:22:51.194] INFO: number of Vcal hits detected: 207748 207861 207645 207441 207484 207251 207301 207639 207770 207536 207644 207687 207722 207785 207939 207924
[16:22:51.194] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:22:51.195] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[16:22:51.195] INFO: X-ray hit rate [MHz/cm2]: 37.7 24.7 41.4 63.9 67.4 71.3 68.4 47.8 42.8 59.3 57.5 48.9 52.0 32.0 14.4 16.8
[16:22:51.195] INFO: PixTestHighRate::doXPixelAlive() done
[16:22:51.245] INFO: PixTest:: pg_setup set to default.
[16:22:51.259] INFO: enter test to run
[16:23:15.153] INFO: test: HighRate no parameter change
[16:23:15.153] INFO: running: highrate
[16:23:15.154] INFO: ----------------------------------------------------------------------
[16:23:15.154] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:23:15.154] INFO: ----------------------------------------------------------------------
[16:23:15.772] INFO: Expecting 208000 events.
[16:23:31.195] INFO: 208000 events read in total (14896ms).
[16:23:31.202] INFO: Test took 16039ms.
[16:23:31.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:31.973] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 2 0 0 0 0 0 0 0 0 0
[16:23:31.973] INFO: number of red-efficiency pixels: 464 261 688 1167 1023 1449 1380 793 443 950 704 708 601 419 77 123
[16:23:31.973] INFO: number of X-ray hits detected: 194658 126720 213745 328434 343847 365187 350517 246092 221696 304579 295302 251717 265726 164248 75021 87265
[16:23:31.973] 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:23:31.973] INFO: number of Vcal hits detected: 207448 207712 207097 206478 206714 205929 206063 207003 207513 206869 207221 207163 207332 207513 207922 207874
[16:23:31.973] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.3 99.5 99.1 99.2 99.6 99.8 99.5 99.7 99.7 99.7 99.8 100.0 99.9
[16:23:31.973] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.3 99.4 99.0 99.1 99.5 99.8 99.5 99.6 99.6 99.7 99.8 100.0 99.9
[16:23:31.973] INFO: X-ray hit rate [MHz/cm2]: 57.1 37.1 62.7 96.3 100.8 107.0 102.7 72.1 65.0 89.3 86.6 73.8 77.9 48.1 22.0 25.6
[16:23:31.973] INFO: PixTestHighRate::doXPixelAlive() done
[16:23:32.019] INFO: PixTest:: pg_setup set to default.
[16:23:32.040] INFO: enter test to run
[16:24:18.624] INFO: test: exit no parameter change
[16:24:18.951] QUIET: Connection to board 33 closed.
[16:24:18.967] INFO: pXar: this is the end, my friend