[11:13:29.398] INFO: *** Welcome to pxar ***
[11:13:29.398] INFO: *** Today: 2016/05/25
[11:13:29.416] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:13:29.416] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//dacParameters35_C15.dat
[11:13:29.420] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:13:29.420] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[11:13:29.440] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[11:13:29.545] INFO: clk: 4
[11:13:29.545] INFO: ctr: 4
[11:13:29.545] INFO: sda: 19
[11:13:29.545] INFO: tin: 9
[11:13:29.545] INFO: level: 15
[11:13:29.545] INFO: triggerdelay: 0
[11:13:29.545] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:13:29.545] INFO: Log level: INFO
[11:13:29.563] QUIET: Connection to board DTB_WREK4U opened.
[11:13:29.566] 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:
------------------------------------------------------
[11:13:29.569] INFO: RPC call hashes of host and DTB match: 398089610
[11:13:31.096] INFO: DUT info:
[11:13:31.096] INFO: The DUT currently contains the following objects:
[11:13:31.096] INFO: 2 TBM Cores tbm08c (2 ON)
[11:13:31.096] INFO: TBM Core alpha (0): 7 registers set
[11:13:31.096] INFO: TBM Core beta (1): 7 registers set
[11:13:31.096] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:13:31.096] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.096] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.097] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:13:31.501] INFO: enter 'restricted' command line mode
[11:13:31.501] INFO: enter test to run
[11:13:47.931] INFO: test: PixelAlive no parameter change
[11:13:47.931] INFO: running: pixelalive
[11:13:47.957] INFO: ----------------------------------------------------------------------
[11:13:47.957] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:13:47.957] INFO: ----------------------------------------------------------------------
[11:13:48.273] INFO: Expecting 41600 events.
[11:13:52.598] INFO: 41600 events read in total (3607ms).
[11:13:52.766] INFO: Test took 4806ms.
[11:13:52.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:53.043] INFO: PixTestAlive::aliveTest() done
[11:13:53.043] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:13:53.075] INFO: enter test to run
[11:14:17.250] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:14:17.251] INFO: running: highrate
[11:14:17.251] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:14:17.512] INFO: ----------------------------------------------------------------------
[11:14:17.512] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:14:17.512] INFO: ----------------------------------------------------------------------
[11:14:17.512] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:14:17.512] INFO: edge/corner pixel THR is adjusted
[11:14:17.512] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:14:18.490] INFO: Collecting data for 5 seconds...
[11:14:23.507] INFO: Done with hot pixel readout
[11:14:35.008] INFO: PixTest:: pg_setup set to default.
[11:14:35.009] INFO: 16 hot pixels found in step 0
[11:14:36.002] INFO: Collecting data for 5 seconds...
[11:14:41.017] INFO: Done with hot pixel readout
[11:14:52.393] INFO: PixTest:: pg_setup set to default.
[11:14:52.394] INFO: 14 hot pixels found in step 1
[11:14:53.388] INFO: Collecting data for 5 seconds...
[11:14:58.404] INFO: Done with hot pixel readout
[11:15:09.855] INFO: PixTest:: pg_setup set to default.
[11:15:09.856] INFO: 14 hot pixels found in step 2
[11:15:10.847] INFO: Collecting data for 5 seconds...
[11:15:15.863] INFO: Done with hot pixel readout
[11:15:27.088] INFO: PixTest:: pg_setup set to default.
[11:15:27.089] INFO: 13 hot pixels found in step 3
[11:15:28.080] INFO: Collecting data for 5 seconds...
[11:15:33.097] INFO: Done with hot pixel readout
[11:15:43.882] INFO: PixTest:: pg_setup set to default.
[11:15:43.883] INFO: 11 hot pixels found in step 4
[11:15:44.875] INFO: Collecting data for 5 seconds...
[11:15:49.887] INFO: Done with hot pixel readout
[11:16:00.706] INFO: PixTest:: pg_setup set to default.
[11:16:00.707] INFO: 10 hot pixels found in step 5
[11:16:01.699] INFO: Collecting data for 5 seconds...
[11:16:06.715] INFO: Done with hot pixel readout
[11:16:17.492] INFO: PixTest:: pg_setup set to default.
[11:16:17.493] INFO: 6 hot pixels found in step 6
[11:16:18.485] INFO: Collecting data for 5 seconds...
[11:16:23.501] INFO: Done with hot pixel readout
[11:16:34.705] INFO: PixTest:: pg_setup set to default.
[11:16:34.706] INFO: 5 hot pixels found in step 7
[11:16:35.698] INFO: Collecting data for 5 seconds...
[11:16:40.714] INFO: Done with hot pixel readout
[11:16:52.026] INFO: PixTest:: pg_setup set to default.
[11:16:52.027] INFO: 3 hot pixels found in step 8
[11:16:53.019] INFO: Collecting data for 5 seconds...
[11:16:58.035] INFO: Done with hot pixel readout
[11:17:09.129] INFO: PixTest:: pg_setup set to default.

[11:17:09.130] INFO: 8 hot pixels found in step 9
[11:17:10.121] INFO: Collecting data for 5 seconds...
[11:17:15.138] INFO: Done with hot pixel readout
[11:17:26.253] INFO: PixTest:: pg_setup set to default.


[11:17:26.254] INFO: 5 hot pixels found in step 10
[11:17:27.245] INFO: Collecting data for 5 seconds...
[11:17:32.263] INFO: Done with hot pixel readout
[11:17:43.598] INFO: PixTest:: pg_setup set to default.
[11:17:43.599] INFO: 4 hot pixels found in step 11
[11:17:44.591] INFO: Collecting data for 5 seconds...
[11:17:49.606] INFO: Done with hot pixel readout
[11:18:00.995] INFO: PixTest:: pg_setup set to default.

[11:18:00.996] INFO: 5 hot pixels found in step 12
[11:18:01.987] INFO: Collecting data for 5 seconds...
[11:18:07.004] INFO: Done with hot pixel readout
[11:18:18.412] INFO: PixTest:: pg_setup set to default.

[11:18:18.413] INFO: 2 hot pixels found in step 13
[11:18:19.405] INFO: Collecting data for 5 seconds...
[11:18:24.422] INFO: Done with hot pixel readout
[11:18:35.565] INFO: PixTest:: pg_setup set to default.
[11:18:35.566] INFO: 2 hot pixels found in step 14
[11:18:35.601] INFO: 2 hot pixels could not be trimmed and have been masked.
[11:18:35.605] INFO: PixTest::trimHotPixels() done
[11:18:35.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat
[11:18:35.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C1.dat
[11:18:35.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C2.dat
[11:18:35.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C3.dat
[11:18:35.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C4.dat
[11:18:35.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C5.dat
[11:18:35.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C6.dat
[11:18:35.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C7.dat
[11:18:35.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C8.dat
[11:18:35.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C9.dat
[11:18:35.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C10.dat
[11:18:35.666] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C11.dat
[11:18:35.677] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C12.dat
[11:18:35.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C13.dat
[11:18:35.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C14.dat
[11:18:35.703] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[11:18:35.712] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[11:18:35.725] INFO: enter test to run
[11:18:53.440] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:18:53.441] INFO: running: highrate
[11:18:53.445] INFO: ----------------------------------------------------------------------
[11:18:53.445] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:18:53.445] INFO: ----------------------------------------------------------------------
[11:18:53.445] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:18:53.445] INFO: edge/corner pixel THR is adjusted
[11:18:53.445] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:18:54.403] INFO: Collecting data for 1 seconds...
[11:18:55.407] INFO: Done with hot pixel readout
[11:18:59.196] INFO: PixTest:: pg_setup set to default.
[11:18:59.197] INFO: 0 hot pixels found in step 0
[11:18:59.202] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:18:59.294] INFO: PixTest::trimHotPixels() done
[11:18:59.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat
[11:18:59.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C1.dat
[11:18:59.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C2.dat
[11:18:59.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C3.dat
[11:18:59.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C4.dat
[11:18:59.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C5.dat
[11:18:59.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C6.dat
[11:18:59.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C7.dat
[11:18:59.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C8.dat
[11:18:59.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C9.dat
[11:18:59.351] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C10.dat
[11:18:59.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C11.dat
[11:18:59.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C12.dat
[11:18:59.366] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C13.dat
[11:18:59.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C14.dat
[11:18:59.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[11:18:59.382] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-04_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[11:18:59.391] INFO: enter test to run
[11:19:26.552] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:19:26.552] INFO: running: xray
[11:19:26.554] INFO: ----------------------------------------------------------------------
[11:19:26.554] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:19:26.554] INFO: ----------------------------------------------------------------------
[11:19:27.518] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:19:38.883] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:20:07.033] INFO: Resuming triggers.
[11:20:18.396] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:20:47.401] INFO: Resuming triggers.
[11:20:58.767] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:21:28.327] INFO: Resuming triggers.
[11:21:39.690] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:22:08.005] INFO: Resuming triggers.
[11:22:19.372] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:22:48.807] INFO: Resuming triggers.
[11:23:00.180] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:23:29.436] INFO: Resuming triggers.
[11:23:40.807] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:24:10.160] INFO: Resuming triggers.
[11:24:21.529] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[11:24:50.538] INFO: Resuming triggers.
[11:24:59.931] INFO: data taking finished, elapsed time: 100 seconds.
[11:25:24.321] INFO: PixTest:: pg_setup set to default.
[11:25:24.325] INFO: PixTestXray::doPhRun() done
[11:25:24.478] INFO: enter test to run
[11:25:45.509] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:25:45.509] INFO: running: xray
[11:25:45.511] INFO: ----------------------------------------------------------------------
[11:25:45.511] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:25:45.511] INFO: ----------------------------------------------------------------------
[11:25:46.475] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:25:53.282] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:26:23.414] INFO: Resuming triggers.
[11:26:30.223] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:27:01.067] INFO: Resuming triggers.
[11:27:07.873] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[11:27:36.604] INFO: Resuming triggers.
[11:27:43.409] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:28:13.589] INFO: Resuming triggers.
[11:28:20.396] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:28:51.259] INFO: Resuming triggers.
[11:28:58.068] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:29:28.140] INFO: Resuming triggers.
[11:29:34.947] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:30:06.098] INFO: Resuming triggers.
[11:30:12.905] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:30:42.646] INFO: Resuming triggers.
[11:30:49.455] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[11:31:19.613] INFO: Resuming triggers.
[11:31:26.422] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:31:56.580] INFO: Resuming triggers.
[11:32:03.391] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[11:32:33.546] INFO: Resuming triggers.
[11:32:40.358] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:33:10.187] INFO: Resuming triggers.
[11:33:16.999] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:33:47.430] INFO: Resuming triggers.
[11:33:54.244] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:34:22.791] INFO: Resuming triggers.
[11:34:27.813] INFO: data taking finished, elapsed time: 100 seconds.
[11:34:50.230] INFO: PixTest:: pg_setup set to default.
[11:34:50.233] INFO: PixTestXray::doPhRun() done
[11:34:50.382] INFO: enter test to run
[11:36:00.489] INFO: test: HighRate no parameter change
[11:36:00.489] INFO: running: highrate
[11:36:00.514] INFO: ----------------------------------------------------------------------
[11:36:00.514] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:36:00.514] INFO: ----------------------------------------------------------------------
[11:36:00.679] INFO: Expecting 768 events.
[11:36:01.813] INFO: 768 events read in total (418ms).
[11:36:01.814] INFO: Test took 1270ms.
[11:36:02.617] INFO: Expecting 41600 events.
[11:36:05.697] INFO: 41600 events read in total (2553ms).
[11:36:05.698] INFO: Test took 3860ms.
[11:36:05.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:06.461] INFO: Expecting 41600 events.
[11:36:09.672] INFO: 41600 events read in total (2684ms).
[11:36:09.673] INFO: Test took 3924ms.
[11:36:09.706] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:10.434] INFO: Expecting 41600 events.
[11:36:13.666] INFO: 41600 events read in total (2706ms).
[11:36:13.667] INFO: Test took 3942ms.
[11:36:13.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:14.422] INFO: Expecting 41600 events.
[11:36:17.619] INFO: 41600 events read in total (2670ms).
[11:36:17.620] INFO: Test took 3900ms.
[11:36:17.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:18.380] INFO: Expecting 41600 events.
[11:36:21.609] INFO: 41600 events read in total (2702ms).
[11:36:21.610] INFO: Test took 3937ms.
[11:36:21.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:22.367] INFO: Expecting 41600 events.
[11:36:25.597] INFO: 41600 events read in total (2703ms).
[11:36:25.598] INFO: Test took 3937ms.
[11:36:25.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:26.358] INFO: Expecting 41600 events.
[11:36:29.591] INFO: 41600 events read in total (2706ms).
[11:36:29.592] INFO: Test took 3943ms.
[11:36:29.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:30.348] INFO: Expecting 41600 events.
[11:36:33.517] INFO: 41600 events read in total (2642ms).
[11:36:33.518] INFO: Test took 3873ms.
[11:36:33.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:34.280] INFO: Expecting 41600 events.
[11:36:37.392] INFO: 41600 events read in total (2585ms).
[11:36:37.393] INFO: Test took 3822ms.
[11:36:37.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:38.147] INFO: Expecting 41600 events.
[11:36:41.375] INFO: 41600 events read in total (2701ms).
[11:36:41.376] INFO: Test took 3930ms.
[11:36:41.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:42.134] INFO: Expecting 41600 events.
[11:36:45.363] INFO: 41600 events read in total (2702ms).
[11:36:45.364] INFO: Test took 3936ms.
[11:36:45.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:46.124] INFO: Expecting 41600 events.
[11:36:49.353] INFO: 41600 events read in total (2702ms).
[11:36:49.354] INFO: Test took 3938ms.
[11:36:49.387] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:50.111] INFO: Expecting 41600 events.
[11:36:53.337] INFO: 41600 events read in total (2699ms).
[11:36:53.338] INFO: Test took 3934ms.
[11:36:53.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:54.095] INFO: Expecting 41600 events.
[11:36:57.142] INFO: 41600 events read in total (2520ms).
[11:36:57.143] INFO: Test took 3752ms.
[11:36:57.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:57.899] INFO: Expecting 41600 events.
[11:37:01.019] INFO: 41600 events read in total (2593ms).
[11:37:01.020] INFO: Test took 3824ms.
[11:37:01.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:01.778] INFO: Expecting 41600 events.
[11:37:05.026] INFO: 41600 events read in total (2721ms).
[11:37:05.027] INFO: Test took 3956ms.
[11:37:05.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:05.782] INFO: Expecting 41600 events.
[11:37:09.011] INFO: 41600 events read in total (2702ms).
[11:37:09.012] INFO: Test took 3932ms.
[11:37:09.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:09.769] INFO: Expecting 41600 events.
[11:37:13.022] INFO: 41600 events read in total (2726ms).
[11:37:13.023] INFO: Test took 3959ms.
[11:37:13.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:13.783] INFO: Expecting 41600 events.
[11:37:17.017] INFO: 41600 events read in total (2707ms).
[11:37:17.018] INFO: Test took 3944ms.
[11:37:17.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:17.776] INFO: Expecting 41600 events.
[11:37:20.732] INFO: 41600 events read in total (2429ms).
[11:37:20.733] INFO: Test took 3663ms.
[11:37:20.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:21.121] INFO: enter test to run
[11:38:05.616] INFO: test: HighRate no parameter change
[11:38:05.616] INFO: running: highrate
[11:38:05.618] INFO: ----------------------------------------------------------------------
[11:38:05.618] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:38:05.618] INFO: ----------------------------------------------------------------------
[11:38:06.238] INFO: Expecting 208000 events.
[11:38:17.981] INFO: 208000 events read in total (11216ms).
[11:38:17.984] INFO: Test took 12358ms.
[11:38:18.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:18.382] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:38:18.382] INFO: number of red-efficiency pixels: 77 40 75 140 162 121 130 226 106 122 118 81 93 80 20 25
[11:38:18.382] INFO: number of X-ray hits detected: 66397 42094 65445 103629 108452 114079 114365 81762 87697 98709 96130 78616 83863 49879 21581 26371
[11:38:18.382] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:38:18.382] INFO: number of Vcal hits detected: 207923 207959 207924 207858 207834 207873 207869 206744 207894 207876 207880 207917 207904 207918 207980 207975
[11:38:18.382] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.4 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:38:18.382] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.4 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:38:18.382] INFO: X-ray hit rate [MHz/cm2]: 19.5 12.3 19.2 30.4 31.8 33.4 33.5 24.0 25.7 28.9 28.2 23.0 24.6 14.6 6.3 7.7
[11:38:18.382] INFO: PixTestHighRate::doXPixelAlive() done
[11:38:18.428] INFO: PixTest:: pg_setup set to default.
[11:38:18.438] INFO: enter test to run
[11:38:38.840] INFO: test: HighRate no parameter change
[11:38:38.840] INFO: running: highrate
[11:38:38.841] INFO: ----------------------------------------------------------------------
[11:38:38.841] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:38:38.841] INFO: ----------------------------------------------------------------------
[11:38:39.454] INFO: Expecting 208000 events.
[11:38:52.477] INFO: 208000 events read in total (12496ms).
[11:38:52.482] INFO: Test took 13634ms.
[11:38:52.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:53.084] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:38:53.084] INFO: number of red-efficiency pixels: 204 126 227 454 475 435 408 373 229 426 313 266 296 183 48 53
[11:38:53.084] INFO: number of X-ray hits detected: 136570 87591 136467 214873 223605 234942 235361 170432 182439 203700 198930 163287 173321 103914 45229 55111
[11:38:53.084] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:38:53.084] INFO: number of Vcal hits detected: 207784 207873 207756 207514 207494 207542 207553 207583 207762 207525 207674 207717 207687 207810 207952 207947
[11:38:53.084] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[11:38:53.084] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[11:38:53.084] INFO: X-ray hit rate [MHz/cm2]: 40.0 25.7 40.0 63.0 65.5 68.9 69.0 50.0 53.5 59.7 58.3 47.9 50.8 30.5 13.3 16.2
[11:38:53.084] INFO: PixTestHighRate::doXPixelAlive() done
[11:38:53.129] INFO: PixTest:: pg_setup set to default.
[11:38:53.148] INFO: enter test to run
[11:39:17.903] INFO: test: HighRate no parameter change
[11:39:17.904] INFO: running: highrate
[11:39:17.905] INFO: ----------------------------------------------------------------------
[11:39:17.905] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:39:17.905] INFO: ----------------------------------------------------------------------
[11:39:18.527] INFO: Expecting 208000 events.
[11:39:33.477] INFO: 208000 events read in total (14424ms).
[11:39:33.485] INFO: Test took 15572ms.
[11:39:33.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:34.278] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:34.278] INFO: number of red-efficiency pixels: 420 246 434 1011 1078 930 884 735 534 992 711 580 571 416 73 107
[11:39:34.278] INFO: number of X-ray hits detected: 201828 130258 202560 319237 330983 348996 351565 252509 271844 302965 294706 242897 257101 153942 67392 82436
[11:39:34.278] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:39:34.278] INFO: number of Vcal hits detected: 207503 207733 207482 206738 206665 206902 206925 207078 207386 206776 207175 207343 207367 207512 207922 207890
[11:39:34.278] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.4 99.4 99.5 99.5 99.6 99.7 99.5 99.6 99.7 99.7 99.8 100.0 99.9
[11:39:34.278] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.4 99.4 99.5 99.5 99.6 99.7 99.4 99.6 99.7 99.7 99.8 100.0 99.9
[11:39:34.278] INFO: X-ray hit rate [MHz/cm2]: 59.2 38.2 59.4 93.6 97.0 102.3 103.0 74.0 79.7 88.8 86.4 71.2 75.4 45.1 19.8 24.2
[11:39:34.278] INFO: PixTestHighRate::doXPixelAlive() done
[11:39:34.323] INFO: PixTest:: pg_setup set to default.
[11:39:34.338] INFO: enter test to run
[11:39:44.695] INFO: test: exit no parameter change
[11:39:44.994] QUIET: Connection to board 32 closed.
[11:39:45.002] INFO: pXar: this is the end, my friend