[14:15:31.998] INFO: *** Welcome to pxar ***
[14:15:31.998] INFO: *** Today: 2016/05/20
[14:15:32.015] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:15:32.015] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//dacParameters35_C15.dat
[14:15:32.015] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:15:32.015] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//defaultMaskFile.dat
[14:15:32.016] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C15.dat
[14:15:32.087] INFO: clk: 4
[14:15:32.087] INFO: ctr: 4
[14:15:32.087] INFO: sda: 19
[14:15:32.087] INFO: tin: 9
[14:15:32.087] INFO: level: 15
[14:15:32.087] INFO: triggerdelay: 0
[14:15:32.087] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:15:32.087] INFO: Log level: INFO
[14:15:32.102] QUIET: Connection to board DTB_WREK4U opened.
[14:15:32.105] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[14:15:32.108] INFO: RPC call hashes of host and DTB match: 398089610
[14:15:33.643] INFO: DUT info:
[14:15:33.643] INFO: The DUT currently contains the following objects:
[14:15:33.643] INFO: 2 TBM Cores tbm08c (2 ON)
[14:15:33.643] INFO: TBM Core alpha (0): 7 registers set
[14:15:33.643] INFO: TBM Core beta (1): 7 registers set
[14:15:33.643] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:15:33.643] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:33.644] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:34.047] INFO: enter 'restricted' command line mode
[14:15:34.047] INFO: enter test to run
[14:15:37.158] INFO: test: PixelAlive no parameter change
[14:15:37.158] INFO: running: pixelalive
[14:15:37.168] INFO: ----------------------------------------------------------------------
[14:15:37.168] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:15:37.168] INFO: ----------------------------------------------------------------------
[14:15:37.486] INFO: Expecting 41600 events.
[14:15:41.785] INFO: 41600 events read in total (3581ms).
[14:15:41.950] INFO: Test took 4780ms.
[14:15:41.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:42.220] INFO: PixTestAlive::aliveTest() done
[14:15:42.220] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:15:42.250] INFO: enter test to run
[14:16:37.534] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:16:37.534] INFO: running: highrate
[14:16:37.534] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:16:37.723] INFO: ----------------------------------------------------------------------
[14:16:37.723] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:16:37.723] INFO: ----------------------------------------------------------------------
[14:16:37.723] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:16:37.723] INFO: edge/corner pixel THR is adjusted
[14:16:37.723] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:16:38.681] INFO: Collecting data for 5 seconds...
[14:16:43.700] INFO: Done with hot pixel readout
[14:16:55.693] INFO: PixTest:: pg_setup set to default.
[14:16:55.693] INFO: 16 hot pixels found in step 0
[14:16:56.707] INFO: Collecting data for 5 seconds...
[14:17:01.726] INFO: Done with hot pixel readout
[14:17:13.714] INFO: PixTest:: pg_setup set to default.
[14:17:13.715] INFO: 14 hot pixels found in step 1
[14:17:14.704] INFO: Collecting data for 5 seconds...
[14:17:19.723] INFO: Done with hot pixel readout
[14:17:31.658] INFO: PixTest:: pg_setup set to default.
[14:17:31.659] INFO: 17 hot pixels found in step 2
[14:17:32.650] INFO: Collecting data for 5 seconds...
[14:17:37.669] INFO: Done with hot pixel readout
[14:17:49.459] INFO: PixTest:: pg_setup set to default.
[14:17:49.460] INFO: 14 hot pixels found in step 3
[14:17:50.450] INFO: Collecting data for 5 seconds...
[14:17:55.469] INFO: Done with hot pixel readout
[14:18:07.377] INFO: PixTest:: pg_setup set to default.
[14:18:07.378] INFO: 9 hot pixels found in step 4
[14:18:08.368] INFO: Collecting data for 5 seconds...
[14:18:13.386] INFO: Done with hot pixel readout
[14:18:25.262] INFO: PixTest:: pg_setup set to default.

[14:18:25.263] INFO: 5 hot pixels found in step 5
[14:18:26.252] INFO: Collecting data for 5 seconds...
[14:18:31.270] INFO: Done with hot pixel readout
[14:18:43.059] INFO: PixTest:: pg_setup set to default.

[14:18:43.060] INFO: 8 hot pixels found in step 6
[14:18:44.049] INFO: Collecting data for 5 seconds...
[14:18:49.066] INFO: Done with hot pixel readout
[14:19:00.749] INFO: PixTest:: pg_setup set to default.
[14:19:00.750] INFO: 14 hot pixels found in step 7
[14:19:01.738] INFO: Collecting data for 5 seconds...
[14:19:06.755] INFO: Done with hot pixel readout
[14:19:18.639] INFO: PixTest:: pg_setup set to default.

[14:19:18.640] INFO: 10 hot pixels found in step 8
[14:19:19.629] INFO: Collecting data for 5 seconds...
[14:19:24.646] INFO: Done with hot pixel readout
[14:19:36.519] INFO: PixTest:: pg_setup set to default.
[14:19:36.519] INFO: 10 hot pixels found in step 9
[14:19:37.508] INFO: Collecting data for 5 seconds...
[14:19:42.525] INFO: Done with hot pixel readout
[14:19:54.267] INFO: PixTest:: pg_setup set to default.
[14:19:54.268] INFO: 12 hot pixels found in step 10
[14:19:55.258] INFO: Collecting data for 5 seconds...
[14:20:00.274] INFO: Done with hot pixel readout
[14:20:12.066] INFO: PixTest:: pg_setup set to default.
[14:20:12.067] INFO: 8 hot pixels found in step 11
[14:20:13.057] INFO: Collecting data for 5 seconds...
[14:20:18.074] INFO: Done with hot pixel readout
[14:20:29.697] INFO: PixTest:: pg_setup set to default.
[14:20:29.698] INFO: 8 hot pixels found in step 12
[14:20:30.688] INFO: Collecting data for 5 seconds...
[14:20:35.704] INFO: Done with hot pixel readout
[14:20:47.574] INFO: PixTest:: pg_setup set to default.
[14:20:47.575] INFO: 7 hot pixels found in step 13
[14:20:48.564] INFO: Collecting data for 5 seconds...
[14:20:53.582] INFO: Done with hot pixel readout
[14:21:05.406] INFO: PixTest:: pg_setup set to default.

[14:21:05.407] INFO: 7 hot pixels found in step 14
[14:21:05.440] INFO: 7 hot pixels could not be trimmed and have been masked.
[14:21:05.443] INFO: PixTest::trimHotPixels() done
[14:21:05.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C0.dat
[14:21:05.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C1.dat
[14:21:05.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C2.dat
[14:21:05.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C3.dat
[14:21:05.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C4.dat
[14:21:05.474] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C5.dat
[14:21:05.479] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C6.dat
[14:21:05.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C7.dat
[14:21:05.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C8.dat
[14:21:05.495] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C9.dat
[14:21:05.500] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C10.dat
[14:21:05.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C11.dat
[14:21:05.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C12.dat
[14:21:05.516] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C13.dat
[14:21:05.521] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C14.dat
[14:21:05.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C15.dat
[14:21:05.532] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//defaultMaskFile.dat
[14:21:05.550] INFO: enter test to run
[14:21:21.948] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:21:21.948] INFO: running: highrate
[14:21:21.952] INFO: ----------------------------------------------------------------------
[14:21:21.952] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:21:21.952] INFO: ----------------------------------------------------------------------
[14:21:21.952] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:21:21.952] INFO: edge/corner pixel THR is adjusted
[14:21:21.953] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:21:22.915] INFO: Collecting data for 1 seconds...
[14:21:23.919] INFO: Done with hot pixel readout
[14:21:27.954] INFO: PixTest:: pg_setup set to default.
[14:21:27.955] INFO: 0 hot pixels found in step 0
[14:21:27.960] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:21:28.052] INFO: PixTest::trimHotPixels() done
[14:21:28.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C0.dat
[14:21:28.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C1.dat
[14:21:28.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C2.dat
[14:21:28.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C3.dat
[14:21:28.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C4.dat
[14:21:28.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C5.dat
[14:21:28.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C6.dat
[14:21:28.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C7.dat
[14:21:28.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C8.dat
[14:21:28.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C9.dat
[14:21:28.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C10.dat
[14:21:28.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C11.dat
[14:21:28.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C12.dat
[14:21:28.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C13.dat
[14:21:28.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C14.dat
[14:21:28.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//trimParameters35_C15.dat
[14:21:28.140] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-17_FPIXTest-17C-FNAL-160518-1313_2016-05-18_13h13m_1463595192/000_FPIXTest_p17//defaultMaskFile.dat
[14:21:28.150] INFO: enter test to run
[14:21:43.835] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:21:43.836] INFO: running: xray
[14:21:43.837] INFO: ----------------------------------------------------------------------
[14:21:43.837] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:21:43.837] INFO: ----------------------------------------------------------------------
[14:21:44.800] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:21:56.171] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:22:25.596] INFO: Resuming triggers.
[14:22:36.970] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:23:06.448] INFO: Resuming triggers.
[14:23:17.821] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:23:47.281] INFO: Resuming triggers.
[14:23:58.653] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:24:28.108] INFO: Resuming triggers.
[14:24:39.477] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:25:08.917] INFO: Resuming triggers.
[14:25:20.290] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:25:50.188] INFO: Resuming triggers.
[14:26:01.559] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:26:30.884] INFO: Resuming triggers.
[14:26:42.252] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:27:11.122] INFO: Resuming triggers.
[14:27:20.504] INFO: data taking finished, elapsed time: 100 seconds.
[14:27:45.069] INFO: PixTest:: pg_setup set to default.
[14:27:45.072] INFO: PixTestXray::doPhRun() done
[14:27:45.254] INFO: enter test to run
[14:27:58.329] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:27:58.329] INFO: running: xray
[14:27:58.330] INFO: ----------------------------------------------------------------------
[14:27:58.330] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:27:58.330] INFO: ----------------------------------------------------------------------
[14:27:59.294] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:28:05.926] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:28:37.283] INFO: Resuming triggers.
[14:28:43.918] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:29:13.982] INFO: Resuming triggers.
[14:29:20.617] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:29:50.608] INFO: Resuming triggers.
[14:29:57.241] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:30:26.803] INFO: Resuming triggers.
[14:30:33.436] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:31:03.220] INFO: Resuming triggers.
[14:31:09.854] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:31:39.600] INFO: Resuming triggers.
[14:31:46.234] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:32:14.823] INFO: Resuming triggers.
[14:32:21.461] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:32:50.420] INFO: Resuming triggers.
[14:32:57.054] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:33:26.640] INFO: Resuming triggers.
[14:33:33.277] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:34:02.613] INFO: Resuming triggers.
[14:34:09.249] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:34:38.710] INFO: Resuming triggers.
[14:34:45.343] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:35:14.970] INFO: Resuming triggers.
[14:35:21.602] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:35:51.342] INFO: Resuming triggers.
[14:35:57.974] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:36:27.535] INFO: Resuming triggers.
[14:36:34.167] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:37:04.201] INFO: Resuming triggers.
[14:37:05.033] INFO: data taking finished, elapsed time: 100 seconds.
[14:37:09.109] INFO: PixTest:: pg_setup set to default.
[14:37:09.112] INFO: PixTestXray::doPhRun() done
[14:37:09.263] INFO: enter test to run
[14:37:59.380] INFO: test: HighRate no parameter change
[14:37:59.380] INFO: running: highrate
[14:37:59.399] INFO: ----------------------------------------------------------------------
[14:37:59.399] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:37:59.399] INFO: ----------------------------------------------------------------------
[14:37:59.554] INFO: Expecting 768 events.
[14:38:00.690] INFO: 768 events read in total (421ms).
[14:38:00.690] INFO: Test took 1269ms.
[14:38:01.493] INFO: Expecting 41600 events.
[14:38:04.520] INFO: 41600 events read in total (2500ms).
[14:38:04.521] INFO: Test took 3806ms.
[14:38:04.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:05.276] INFO: Expecting 41600 events.
[14:38:08.438] INFO: 41600 events read in total (2635ms).
[14:38:08.439] INFO: Test took 3867ms.
[14:38:08.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:09.196] INFO: Expecting 41600 events.
[14:38:12.419] INFO: 41600 events read in total (2696ms).
[14:38:12.420] INFO: Test took 3928ms.
[14:38:12.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:13.172] INFO: Expecting 41600 events.
[14:38:16.418] INFO: 41600 events read in total (2719ms).
[14:38:16.419] INFO: Test took 3946ms.
[14:38:16.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:17.176] INFO: Expecting 41600 events.
[14:38:20.461] INFO: 41600 events read in total (2758ms).
[14:38:20.462] INFO: Test took 3989ms.
[14:38:20.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:21.218] INFO: Expecting 41600 events.
[14:38:24.412] INFO: 41600 events read in total (2668ms).
[14:38:24.413] INFO: Test took 3897ms.
[14:38:24.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:25.171] INFO: Expecting 41600 events.
[14:38:28.357] INFO: 41600 events read in total (2659ms).
[14:38:28.358] INFO: Test took 3891ms.
[14:38:28.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:29.115] INFO: Expecting 41600 events.
[14:38:32.367] INFO: 41600 events read in total (2725ms).
[14:38:32.368] INFO: Test took 3955ms.
[14:38:32.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:33.124] INFO: Expecting 41600 events.
[14:38:36.323] INFO: 41600 events read in total (2672ms).
[14:38:36.324] INFO: Test took 3902ms.
[14:38:36.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:37.076] INFO: Expecting 41600 events.
[14:38:40.078] INFO: 41600 events read in total (2475ms).
[14:38:40.079] INFO: Test took 3701ms.
[14:38:40.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:40.832] INFO: Expecting 41600 events.
[14:38:44.032] INFO: 41600 events read in total (2674ms).
[14:38:44.033] INFO: Test took 3901ms.
[14:38:44.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:44.791] INFO: Expecting 41600 events.
[14:38:48.033] INFO: 41600 events read in total (2716ms).
[14:38:48.034] INFO: Test took 3946ms.
[14:38:48.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:48.789] INFO: Expecting 41600 events.
[14:38:51.994] INFO: 41600 events read in total (2678ms).
[14:38:51.995] INFO: Test took 3905ms.
[14:38:52.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:52.747] INFO: Expecting 41600 events.
[14:38:55.984] INFO: 41600 events read in total (2710ms).
[14:38:55.985] INFO: Test took 3935ms.
[14:38:56.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:56.742] INFO: Expecting 41600 events.
[14:38:59.997] INFO: 41600 events read in total (2728ms).
[14:38:59.998] INFO: Test took 3960ms.
[14:39:00.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:00.748] INFO: Expecting 41600 events.
[14:39:04.023] INFO: 41600 events read in total (2749ms).
[14:39:04.024] INFO: Test took 3972ms.
[14:39:04.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:04.784] INFO: Expecting 41600 events.
[14:39:07.005] INFO: 41600 events read in total (2694ms).
[14:39:08.006] INFO: Test took 3927ms.
[14:39:08.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:08.761] INFO: Expecting 41600 events.
[14:39:11.976] INFO: 41600 events read in total (2688ms).
[14:39:11.977] INFO: Test took 3916ms.
[14:39:12.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:12.733] INFO: Expecting 41600 events.
[14:39:15.910] INFO: 41600 events read in total (2650ms).
[14:39:15.911] INFO: Test took 3880ms.
[14:39:15.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:16.670] INFO: Expecting 41600 events.
[14:39:19.788] INFO: 41600 events read in total (2591ms).
[14:39:19.789] INFO: Test took 3823ms.
[14:39:19.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:20.183] INFO: enter test to run
[14:39:39.596] INFO: test: HighRate no parameter change
[14:39:39.596] INFO: running: highrate
[14:39:39.597] INFO: ----------------------------------------------------------------------
[14:39:39.597] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:39.597] INFO: ----------------------------------------------------------------------
[14:39:40.213] INFO: Expecting 208000 events.
[14:39:51.794] INFO: 208000 events read in total (11054ms).
[14:39:51.797] INFO: Test took 12192ms.
[14:39:51.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:52.201] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:39:52.201] INFO: number of red-efficiency pixels: 76 60 75 143 193 118 166 112 128 108 116 104 93 68 23 41
[14:39:52.201] INFO: number of X-ray hits detected: 67681 47671 67673 111739 118815 115141 116214 91880 86521 94629 91962 84767 85761 49307 21926 27195
[14:39:52.201] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:39:52.201] INFO: number of Vcal hits detected: 207924 207940 207876 207849 207800 207880 207832 207886 207871 207892 207883 207838 207903 207932 207977 207959
[14:39:52.201] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:39:52.201] INFO: Vcal hit overall efficiency (%): 100.0 100.0 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 100.0
[14:39:52.201] INFO: X-ray hit rate [MHz/cm2]: 19.8 14.0 19.8 32.8 34.8 33.7 34.1 26.9 25.4 27.7 27.0 24.8 25.1 14.5 6.4 8.0
[14:39:52.201] INFO: PixTestHighRate::doXPixelAlive() done
[14:39:52.245] INFO: PixTest:: pg_setup set to default.
[14:39:52.258] INFO: enter test to run
[14:40:09.995] INFO: test: HighRate no parameter change
[14:40:09.995] INFO: running: highrate
[14:40:09.997] INFO: ----------------------------------------------------------------------
[14:40:09.997] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:40:09.997] INFO: ----------------------------------------------------------------------
[14:40:10.617] INFO: Expecting 208000 events.
[14:40:24.305] INFO: 208000 events read in total (13161ms).
[14:40:24.311] INFO: Test took 14305ms.
[14:40:24.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:24.909] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:40:24.909] INFO: number of red-efficiency pixels: 222 157 310 455 577 438 595 365 339 290 318 266 260 147 55 66
[14:40:24.909] INFO: number of X-ray hits detected: 140840 99009 140656 230898 246468 237693 241157 190592 179626 195475 189498 175507 177341 102944 45640 56065
[14:40:24.909] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:40:24.909] INFO: number of Vcal hits detected: 207769 207830 207611 207509 207370 207535 207335 207596 207642 207702 207666 207651 207725 207840 207945 207931
[14:40:24.909] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[14:40:24.909] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 100.0 100.0
[14:40:24.909] INFO: X-ray hit rate [MHz/cm2]: 41.3 29.0 41.2 67.7 72.2 69.7 70.7 55.9 52.6 57.3 55.5 51.4 52.0 30.2 13.4 16.4
[14:40:24.909] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:24.954] INFO: PixTest:: pg_setup set to default.
[14:40:24.967] INFO: enter test to run
[14:40:42.339] INFO: test: HighRate no parameter change
[14:40:42.339] INFO: running: highrate
[14:40:42.341] INFO: ----------------------------------------------------------------------
[14:40:42.341] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:40:42.341] INFO: ----------------------------------------------------------------------
[14:40:42.954] INFO: Expecting 208000 events.
[14:40:58.584] INFO: 208000 events read in total (15103ms).
[14:40:58.591] INFO: Test took 16242ms.
[14:40:59.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:59.385] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:40:59.385] INFO: number of red-efficiency pixels: 485 322 676 1059 1387 967 1350 893 770 625 688 537 545 377 103 125
[14:40:59.385] INFO: number of X-ray hits detected: 210159 148674 211648 347334 369228 357483 359731 285557 269673 293194 285220 264426 264267 154146 68593 84625
[14:40:59.385] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:40:59.385] INFO: number of Vcal hits detected: 207444 207642 207044 206711 206195 206836 206191 206866 207117 207303 207214 207316 207415 207579 207892 207873
[14:40:59.385] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.4 99.2 99.5 99.2 99.5 99.6 99.7 99.7 99.7 99.7 99.8 100.0 99.9
[14:40:59.385] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.1 99.4 99.1 99.5 99.6 99.7 99.6 99.7 99.7 99.8 99.9 99.9
[14:40:59.385] INFO: X-ray hit rate [MHz/cm2]: 61.6 43.6 62.0 101.8 108.2 104.8 105.4 83.7 79.0 85.9 83.6 77.5 77.5 45.2 20.1 24.8
[14:40:59.385] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:59.436] INFO: PixTest:: pg_setup set to default.
[14:40:59.452] INFO: enter test to run
[14:41:01.787] INFO: test: exit no parameter change
[14:41:02.155] QUIET: Connection to board 32 closed.
[14:41:02.163] INFO: pXar: this is the end, my friend