[10:25:51.989] INFO: *** Welcome to pxar ***
[10:25:51.989] INFO: *** Today: 2016/07/14
[10:25:52.085] INFO: *** Version: v1.9.0-814-g7497
[10:25:52.085] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//dacParameters35_C15.dat
[10:25:52.131] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:25:52.131] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[10:25:52.140] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[10:25:52.249] INFO: clk: 4
[10:25:52.249] INFO: ctr: 4
[10:25:52.249] INFO: sda: 19
[10:25:52.249] INFO: tin: 9
[10:25:52.249] INFO: level: 15
[10:25:52.249] INFO: triggerdelay: 0
[10:25:52.249] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:25:52.249] INFO: Log level: INFO
[10:25:52.266] QUIET: Connection to board DTB_WREKRL opened.
[10:25:52.270] 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:
------------------------------------------------------
[10:25:52.273] INFO: RPC call hashes of host and DTB match: 398089610
[10:25:53.801] INFO: DUT info:
[10:25:53.801] INFO: The DUT currently contains the following objects:
[10:25:53.801] INFO: 2 TBM Cores tbm08c (2 ON)
[10:25:53.801] INFO: TBM Core alpha (0): 7 registers set
[10:25:53.801] INFO: TBM Core beta (1): 7 registers set
[10:25:53.801] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:25:53.801] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.801] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:53.802] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:25:54.205] INFO: enter 'restricted' command line mode
[10:25:54.206] INFO: enter test to run
[10:26:18.496] INFO: test: PixelAlive no parameter change
[10:26:18.496] INFO: running: pixelalive
[10:26:18.629] INFO: ----------------------------------------------------------------------
[10:26:18.629] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:26:18.629] INFO: ----------------------------------------------------------------------
[10:26:18.951] INFO: Expecting 41600 events.
[10:26:23.353] INFO: 41600 events read in total (3683ms).
[10:26:23.518] INFO: Test took 4885ms.
[10:26:23.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:24.069] INFO: PixTestAlive::aliveTest() done
[10:26:24.069] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 1 0
[10:26:24.140] INFO: enter test to run
[10:27:18.248] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:27:18.248] INFO: running: highrate
[10:27:18.248] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:27:18.499] INFO: ----------------------------------------------------------------------
[10:27:18.500] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:27:18.500] INFO: ----------------------------------------------------------------------
[10:27:18.500] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:27:18.500] INFO: edge/corner pixel THR is adjusted
[10:27:18.500] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:27:19.458] INFO: Collecting data for 5 seconds...
[10:27:24.476] INFO: Done with hot pixel readout
[10:27:36.500] INFO: PixTest:: pg_setup set to default.



[10:27:36.526] INFO: 115 hot pixels found in step 0
[10:27:37.520] INFO: Collecting data for 5 seconds...
[10:27:42.538] INFO: Done with hot pixel readout
[10:27:53.918] INFO: PixTest:: pg_setup set to default.


[10:27:53.919] INFO: 107 hot pixels found in step 1
[10:27:54.917] INFO: Collecting data for 5 seconds...
[10:27:59.936] INFO: Done with hot pixel readout
[10:28:11.548] INFO: PixTest:: pg_setup set to default.





[10:28:11.549] INFO: 96 hot pixels found in step 2
[10:28:12.545] INFO: Collecting data for 5 seconds...
[10:28:17.564] INFO: Done with hot pixel readout
[10:28:29.884] INFO: PixTest:: pg_setup set to default.








[10:28:29.886] INFO: 103 hot pixels found in step 3
[10:28:30.882] INFO: Collecting data for 5 seconds...
[10:28:35.901] INFO: Done with hot pixel readout
[10:28:48.162] INFO: PixTest:: pg_setup set to default.









[10:28:48.163] INFO: 90 hot pixels found in step 4
[10:28:49.161] INFO: Collecting data for 5 seconds...
[10:28:54.180] INFO: Done with hot pixel readout
[10:29:06.563] INFO: PixTest:: pg_setup set to default.











[10:29:06.565] INFO: 84 hot pixels found in step 5
[10:29:07.562] INFO: Collecting data for 5 seconds...
[10:29:12.580] INFO: Done with hot pixel readout
[10:29:24.919] INFO: PixTest:: pg_setup set to default.









[10:29:24.920] INFO: 55 hot pixels found in step 6
[10:29:25.918] INFO: Collecting data for 5 seconds...
[10:29:30.936] INFO: Done with hot pixel readout
[10:29:43.207] INFO: PixTest:: pg_setup set to default.














[10:29:43.208] INFO: 59 hot pixels found in step 7
[10:29:44.205] INFO: Collecting data for 5 seconds...
[10:29:49.225] INFO: Done with hot pixel readout
[10:30:01.243] INFO: PixTest:: pg_setup set to default.















[10:30:01.244] INFO: 61 hot pixels found in step 8
[10:30:02.243] INFO: Collecting data for 5 seconds...
[10:30:07.261] INFO: Done with hot pixel readout
[10:30:19.642] INFO: PixTest:: pg_setup set to default.














[10:30:19.644] INFO: 59 hot pixels found in step 9
[10:30:20.641] INFO: Collecting data for 5 seconds...
[10:30:25.657] INFO: Done with hot pixel readout
[10:30:37.709] INFO: PixTest:: pg_setup set to default.














[10:30:37.710] INFO: 73 hot pixels found in step 10
[10:30:38.708] INFO: Collecting data for 5 seconds...
[10:30:43.724] INFO: Done with hot pixel readout
[10:30:55.763] INFO: PixTest:: pg_setup set to default.















[10:30:55.764] INFO: 63 hot pixels found in step 11
[10:30:56.760] INFO: Collecting data for 5 seconds...
[10:31:01.776] INFO: Done with hot pixel readout
[10:31:13.809] INFO: PixTest:: pg_setup set to default.


















[10:31:13.810] INFO: 55 hot pixels found in step 12
[10:31:14.807] INFO: Collecting data for 5 seconds...
[10:31:19.823] INFO: Done with hot pixel readout
[10:31:31.872] INFO: PixTest:: pg_setup set to default.


















[10:31:31.873] INFO: 59 hot pixels found in step 13
[10:31:32.871] INFO: Collecting data for 5 seconds...
[10:31:37.887] INFO: Done with hot pixel readout
[10:31:49.948] INFO: PixTest:: pg_setup set to default.















[10:31:49.949] INFO: 51 hot pixels found in step 14
[10:31:49.990] INFO: 51 hot pixels could not be trimmed and have been masked.
[10:31:49.993] INFO: PixTest::trimHotPixels() done
[10:31:49.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat
[10:31:49.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C1.dat
[10:31:50.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C2.dat
[10:31:50.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C3.dat
[10:31:50.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C4.dat
[10:31:50.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C5.dat
[10:31:50.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C6.dat
[10:31:50.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C7.dat
[10:31:50.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C8.dat
[10:31:50.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C9.dat
[10:31:50.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C10.dat
[10:31:50.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C11.dat
[10:31:50.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C12.dat
[10:31:50.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C13.dat
[10:31:50.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C14.dat
[10:31:50.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[10:31:50.079] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[10:31:50.089] INFO: enter test to run
[10:32:36.414] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:32:36.414] INFO: running: highrate
[10:32:36.418] INFO: ----------------------------------------------------------------------
[10:32:36.418] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:32:36.418] INFO: ----------------------------------------------------------------------
[10:32:36.418] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:32:36.418] INFO: edge/corner pixel THR is adjusted
[10:32:36.418] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:32:37.376] INFO: Collecting data for 1 seconds...
[10:32:38.380] INFO: Done with hot pixel readout
[10:32:42.548] INFO: PixTest:: pg_setup set to default.
[10:32:42.549] INFO: 0 hot pixels found in step 0
[10:32:42.554] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:32:42.634] INFO: PixTest::trimHotPixels() done
[10:32:42.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C0.dat
[10:32:42.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C1.dat
[10:32:42.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C2.dat
[10:32:42.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C3.dat
[10:32:42.657] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C4.dat
[10:32:42.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C5.dat
[10:32:42.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C6.dat
[10:32:42.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C7.dat
[10:32:42.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C8.dat
[10:32:42.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C9.dat
[10:32:42.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C10.dat
[10:32:42.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C11.dat
[10:32:42.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C12.dat
[10:32:42.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C13.dat
[10:32:42.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C14.dat
[10:32:42.714] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//trimParameters35_C15.dat
[10:32:42.719] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-34_FPIXTest-17C-FNAL-160707-1047_2016-07-07_10h47m_1467906454/000_FPIXTest_p17//defaultMaskFile.dat
[10:32:42.729] INFO: enter test to run
[10:33:21.229] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:33:21.229] INFO: running: xray
[10:33:21.231] INFO: ----------------------------------------------------------------------
[10:33:21.231] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:33:21.231] INFO: ----------------------------------------------------------------------
[10:33:22.205] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:33:33.293] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:34:03.013] INFO: Resuming triggers.
[10:34:14.103] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:34:43.723] INFO: Resuming triggers.
[10:34:54.810] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:35:24.332] INFO: Resuming triggers.
[10:35:35.418] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:36:04.997] INFO: Resuming triggers.
[10:36:16.082] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:36:45.747] INFO: Resuming triggers.
[10:36:56.835] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:37:26.343] INFO: Resuming triggers.
[10:37:37.432] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[10:38:06.960] INFO: Resuming triggers.
[10:38:18.050] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:38:48.415] INFO: Resuming triggers.
[10:38:59.506] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:39:29.713] INFO: Resuming triggers.
[10:39:30.255] INFO: data taking finished, elapsed time: 100 seconds.
[10:39:32.054] INFO: PixTest:: pg_setup set to default.
[10:39:32.058] INFO: PixTestXray::doPhRun() done
[10:39:32.199] INFO: enter test to run
[10:40:15.474] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:40:15.475] INFO: running: xray
[10:40:15.476] INFO: ----------------------------------------------------------------------
[10:40:15.476] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:40:15.476] INFO: ----------------------------------------------------------------------
[10:40:16.444] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:40:22.844] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:40:54.949] INFO: Resuming triggers.
[10:41:01.349] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:41:33.055] INFO: Resuming triggers.
[10:41:39.458] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:42:10.499] INFO: Resuming triggers.
[10:42:16.900] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:42:46.959] INFO: Resuming triggers.
[10:42:53.361] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:43:23.510] INFO: Resuming triggers.
[10:43:29.909] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[10:44:00.075] INFO: Resuming triggers.
[10:44:06.476] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:44:36.577] INFO: Resuming triggers.
[10:44:42.976] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[10:45:13.037] INFO: Resuming triggers.
[10:45:19.434] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:45:49.551] INFO: Resuming triggers.
[10:45:55.947] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:46:26.044] INFO: Resuming triggers.
[10:46:32.441] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:47:02.917] INFO: Resuming triggers.
[10:47:09.312] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:47:39.420] INFO: Resuming triggers.
[10:47:45.816] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:48:15.895] INFO: Resuming triggers.
[10:48:22.292] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[10:48:52.450] INFO: Resuming triggers.
[10:48:58.849] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[10:49:28.926] INFO: Resuming triggers.
[10:49:33.287] INFO: data taking finished, elapsed time: 100 seconds.
[10:49:54.011] INFO: PixTest:: pg_setup set to default.
[10:49:54.014] INFO: PixTestXray::doPhRun() done
[10:49:54.161] INFO: enter test to run
[10:50:38.735] INFO: test: HighRate no parameter change
[10:50:38.735] INFO: running: highrate
[10:50:38.761] INFO: ----------------------------------------------------------------------
[10:50:38.761] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:50:38.761] INFO: ----------------------------------------------------------------------
[10:50:38.916] INFO: Expecting 768 events.
[10:50:40.053] INFO: 768 events read in total (421ms).
[10:50:40.053] INFO: Test took 1271ms.
[10:50:40.856] INFO: Expecting 41600 events.
[10:50:44.018] INFO: 41600 events read in total (2635ms).
[10:50:44.020] INFO: Test took 3961ms.
[10:50:44.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:44.777] INFO: Expecting 41600 events.
[10:50:48.031] INFO: 41600 events read in total (2727ms).
[10:50:48.032] INFO: Test took 3956ms.
[10:50:48.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:48.782] INFO: Expecting 41600 events.
[10:50:52.022] INFO: 41600 events read in total (2713ms).
[10:50:52.023] INFO: Test took 3931ms.
[10:50:52.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:52.775] INFO: Expecting 41600 events.
[10:50:56.031] INFO: 41600 events read in total (2730ms).
[10:50:56.032] INFO: Test took 3951ms.
[10:50:56.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:56.786] INFO: Expecting 41600 events.
[10:51:00.059] INFO: 41600 events read in total (2746ms).
[10:51:00.060] INFO: Test took 3972ms.
[10:51:00.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:00.812] INFO: Expecting 41600 events.
[10:51:04.152] INFO: 41600 events read in total (2813ms).
[10:51:04.152] INFO: Test took 4035ms.
[10:51:04.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:04.903] INFO: Expecting 41600 events.
[10:51:08.187] INFO: 41600 events read in total (2757ms).
[10:51:08.188] INFO: Test took 3979ms.
[10:51:08.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:08.940] INFO: Expecting 41600 events.
[10:51:12.194] INFO: 41600 events read in total (2727ms).
[10:51:12.195] INFO: Test took 3949ms.
[10:51:12.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:12.950] INFO: Expecting 41600 events.
[10:51:16.202] INFO: 41600 events read in total (2725ms).
[10:51:16.203] INFO: Test took 3952ms.
[10:51:16.241] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:16.958] INFO: Expecting 41600 events.
[10:51:20.225] INFO: 41600 events read in total (2740ms).
[10:51:20.226] INFO: Test took 3967ms.
[10:51:20.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:20.981] INFO: Expecting 41600 events.
[10:51:24.268] INFO: 41600 events read in total (2760ms).
[10:51:24.269] INFO: Test took 3986ms.
[10:51:24.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:25.022] INFO: Expecting 41600 events.
[10:51:28.356] INFO: 41600 events read in total (2808ms).
[10:51:28.357] INFO: Test took 4032ms.
[10:51:28.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:29.108] INFO: Expecting 41600 events.
[10:51:32.264] INFO: 41600 events read in total (2630ms).
[10:51:32.265] INFO: Test took 3852ms.
[10:51:32.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:33.016] INFO: Expecting 41600 events.
[10:51:36.266] INFO: 41600 events read in total (2723ms).
[10:51:36.267] INFO: Test took 3947ms.
[10:51:36.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:37.020] INFO: Expecting 41600 events.
[10:51:40.297] INFO: 41600 events read in total (2750ms).
[10:51:40.298] INFO: Test took 3974ms.
[10:51:40.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:41.050] INFO: Expecting 41600 events.
[10:51:44.257] INFO: 41600 events read in total (2681ms).
[10:51:44.258] INFO: Test took 3903ms.
[10:51:44.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:45.009] INFO: Expecting 41600 events.
[10:51:48.303] INFO: 41600 events read in total (2767ms).
[10:51:48.304] INFO: Test took 3990ms.
[10:51:48.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:49.060] INFO: Expecting 41600 events.
[10:51:52.261] INFO: 41600 events read in total (2675ms).
[10:51:52.262] INFO: Test took 3902ms.
[10:51:52.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:53.020] INFO: Expecting 41600 events.
[10:51:56.330] INFO: 41600 events read in total (2784ms).
[10:51:56.331] INFO: Test took 4012ms.
[10:51:56.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:57.083] INFO: Expecting 41600 events.
[10:52:00.158] INFO: 41600 events read in total (2548ms).
[10:52:00.159] INFO: Test took 3771ms.
[10:52:00.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:00.551] INFO: enter test to run
[10:52:05.374] INFO: test: HighRate no parameter change
[10:52:05.374] INFO: running: highrate
[10:52:05.375] INFO: ----------------------------------------------------------------------
[10:52:05.375] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:52:05.375] INFO: ----------------------------------------------------------------------
[10:52:05.990] INFO: Expecting 208000 events.
[10:52:17.715] INFO: 208000 events read in total (11198ms).
[10:52:17.718] INFO: Test took 12337ms.
[10:52:17.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:18.139] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 1 0
[10:52:18.139] INFO: number of red-efficiency pixels: 117 72 114 175 187 172 182 143 118 107 135 110 115 63 38 26
[10:52:18.139] INFO: number of X-ray hits detected: 81289 49726 72824 115543 124484 129458 127357 88423 85840 102760 103135 89350 94195 54634 24770 24830
[10:52:18.139] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:52:18.139] INFO: number of Vcal hits detected: 207881 207928 207884 207822 207809 207821 207812 207853 207880 207892 207813 207840 207880 207936 207913 207974
[10:52:18.140] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 99.9 100.0 100.0 100.0
[10:52:18.140] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:52:18.140] INFO: X-ray hit rate [MHz/cm2]: 23.8 14.6 21.3 33.9 36.5 37.9 37.3 25.9 25.2 30.1 30.2 26.2 27.6 16.0 7.3 7.3
[10:52:18.140] INFO: PixTestHighRate::doXPixelAlive() done
[10:52:18.185] INFO: PixTest:: pg_setup set to default.
[10:52:18.198] INFO: enter test to run
[10:52:48.662] INFO: test: HighRate no parameter change
[10:52:48.662] INFO: running: highrate
[10:52:48.664] INFO: ----------------------------------------------------------------------
[10:52:48.664] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:52:48.664] INFO: ----------------------------------------------------------------------
[10:52:49.293] INFO: Expecting 208000 events.
[10:53:03.609] INFO: 208000 events read in total (13789ms).
[10:53:03.615] INFO: Test took 14941ms.
[10:53:03.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:04.245] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 1 0
[10:53:04.245] INFO: number of red-efficiency pixels: 349 159 334 565 708 619 683 456 374 433 394 386 401 194 51 53
[10:53:04.245] INFO: number of X-ray hits detected: 164771 101165 148538 232933 254072 262901 258905 180605 174697 208786 211455 181632 191724 111258 51040 50513
[10:53:04.245] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:53:04.245] INFO: number of Vcal hits detected: 207613 207828 207623 207377 207210 207306 207223 207483 207596 207534 207526 207536 207569 207795 207898 207945
[10:53:04.245] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[10:53:04.245] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.7 99.6 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[10:53:04.245] INFO: X-ray hit rate [MHz/cm2]: 48.3 29.7 43.5 68.3 74.5 77.1 75.9 52.9 51.2 61.2 62.0 53.2 56.2 32.6 15.0 14.8
[10:53:04.245] INFO: PixTestHighRate::doXPixelAlive() done
[10:53:04.290] INFO: PixTest:: pg_setup set to default.
[10:53:04.310] INFO: enter test to run
[10:53:42.373] INFO: test: HighRate no parameter change
[10:53:42.373] INFO: running: highrate
[10:53:42.374] INFO: ----------------------------------------------------------------------
[10:53:42.374] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:53:42.374] INFO: ----------------------------------------------------------------------
[10:53:42.996] INFO: Expecting 208000 events.
[10:53:59.482] INFO: 208000 events read in total (15959ms).
[10:53:59.490] INFO: Test took 17107ms.
[10:53:59.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:00.353] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 1 0 0 1 0
[10:54:00.353] INFO: number of red-efficiency pixels: 764 341 694 1276 1564 1403 1523 986 788 946 885 853 913 472 133 102
[10:54:00.353] INFO: number of X-ray hits detected: 248001 152321 222681 352323 381938 397218 388638 271827 263095 314046 317519 274632 288960 167708 77155 76562
[10:54:00.353] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:54:00.353] INFO: number of Vcal hits detected: 206948 207597 206996 206287 205835 206108 205799 206691 207086 206857 206908 206882 206929 207450 207816 207898
[10:54:00.353] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.6 99.3 99.1 99.2 99.1 99.4 99.6 99.5 99.5 99.5 99.5 99.8 99.9 100.0
[10:54:00.353] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.5 99.2 99.0 99.1 98.9 99.4 99.6 99.5 99.5 99.5 99.5 99.7 99.9 100.0
[10:54:00.353] INFO: X-ray hit rate [MHz/cm2]: 72.7 44.6 65.3 103.3 111.9 116.4 113.9 79.7 77.1 92.0 93.1 80.5 84.7 49.2 22.6 22.4
[10:54:00.353] INFO: PixTestHighRate::doXPixelAlive() done
[10:54:00.400] INFO: PixTest:: pg_setup set to default.
[10:54:00.411] INFO: enter test to run
[10:54:24.653] INFO: test: exit no parameter change
[10:54:25.129] QUIET: Connection to board 33 closed.
[10:54:25.130] INFO: pXar: this is the end, my friend