[09:12:09.338] INFO: *** Welcome to pxar ***
[09:12:09.338] INFO: *** Today: 2016/04/19
[09:12:09.450] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:12:09.450] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//dacParameters35_C15.dat
[09:12:09.486] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:12:09.487] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//defaultMaskFile.dat
[09:12:09.487] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C15.dat
[09:12:09.568] INFO: clk: 4
[09:12:09.568] INFO: ctr: 4
[09:12:09.568] INFO: sda: 19
[09:12:09.568] INFO: tin: 9
[09:12:09.568] INFO: level: 15
[09:12:09.568] INFO: triggerdelay: 0
[09:12:09.568] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:12:09.568] INFO: Log level: INFO
[09:12:09.586] QUIET: Connection to board DTB_WREKRL opened.
[09:12:09.590] 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:
------------------------------------------------------
[09:12:09.593] INFO: RPC call hashes of host and DTB match: 398089610
[09:12:11.118] INFO: DUT info:
[09:12:11.118] INFO: The DUT currently contains the following objects:
[09:12:11.118] INFO: 2 TBM Cores tbm08c (2 ON)
[09:12:11.118] INFO: TBM Core alpha (0): 7 registers set
[09:12:11.118] INFO: TBM Core beta (1): 7 registers set
[09:12:11.118] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:12:11.118] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.118] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.118] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.118] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.118] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.119] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:12:11.522] INFO: enter 'restricted' command line mode
[09:12:11.522] INFO: enter test to run
[09:12:34.824] INFO: test: PixelAlive no parameter change
[09:12:34.825] INFO: running: pixelalive
[09:12:34.834] INFO: ----------------------------------------------------------------------
[09:12:34.834] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:12:34.834] INFO: ----------------------------------------------------------------------
[09:12:35.153] INFO: Expecting 41600 events.
[09:12:39.103] INFO: 41600 events read in total (3232ms).
[09:12:39.275] INFO: Test took 4439ms.
[09:12:39.282] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:39.543] INFO: PixTestAlive::aliveTest() done
[09:12:39.543] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:12:39.571] INFO: enter test to run
[09:13:05.168] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:13:05.169] INFO: running: highrate
[09:13:05.169] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:13:05.380] INFO: ----------------------------------------------------------------------
[09:13:05.380] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:13:05.380] INFO: ----------------------------------------------------------------------
[09:13:05.380] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:13:05.380] INFO: edge/corner pixel THR is adjusted
[09:13:05.380] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:13:06.340] INFO: Collecting data for 5 seconds...
[09:13:11.357] INFO: Done with hot pixel readout
[09:13:23.637] INFO: PixTest:: pg_setup set to default.
[09:13:23.638] INFO: 17 hot pixels found in step 0
[09:13:24.630] INFO: Collecting data for 5 seconds...
[09:13:29.647] INFO: Done with hot pixel readout
[09:13:41.851] INFO: PixTest:: pg_setup set to default.
[09:13:41.852] INFO: 29 hot pixels found in step 1
[09:13:42.849] INFO: Collecting data for 5 seconds...
[09:13:47.866] INFO: Done with hot pixel readout
[09:14:00.092] INFO: PixTest:: pg_setup set to default.
[09:14:00.093] INFO: 15 hot pixels found in step 2
[09:14:01.088] INFO: Collecting data for 5 seconds...
[09:14:06.104] INFO: Done with hot pixel readout
[09:14:18.342] INFO: PixTest:: pg_setup set to default.
[09:14:18.343] INFO: 20 hot pixels found in step 3
[09:14:19.338] INFO: Collecting data for 5 seconds...
[09:14:24.354] INFO: Done with hot pixel readout
[09:14:36.588] INFO: PixTest:: pg_setup set to default.

[09:14:36.589] INFO: 16 hot pixels found in step 4
[09:14:37.584] INFO: Collecting data for 5 seconds...
[09:14:42.602] INFO: Done with hot pixel readout
[09:14:54.850] INFO: PixTest:: pg_setup set to default.
[09:14:54.851] INFO: 11 hot pixels found in step 5
[09:14:55.845] INFO: Collecting data for 5 seconds...
[09:15:00.861] INFO: Done with hot pixel readout
[09:15:13.084] INFO: PixTest:: pg_setup set to default.
[09:15:13.085] INFO: 17 hot pixels found in step 6
[09:15:14.079] INFO: Collecting data for 5 seconds...
[09:15:19.096] INFO: Done with hot pixel readout
[09:15:31.332] INFO: PixTest:: pg_setup set to default.

[09:15:31.333] INFO: 19 hot pixels found in step 7
[09:15:32.329] INFO: Collecting data for 5 seconds...
[09:15:37.346] INFO: Done with hot pixel readout
[09:15:49.580] INFO: PixTest:: pg_setup set to default.
[09:15:49.581] INFO: 21 hot pixels found in step 8
[09:15:50.577] INFO: Collecting data for 5 seconds...
[09:15:55.594] INFO: Done with hot pixel readout
[09:16:07.820] INFO: PixTest:: pg_setup set to default.
[09:16:07.821] INFO: 19 hot pixels found in step 9
[09:16:08.816] INFO: Collecting data for 5 seconds...
[09:16:13.833] INFO: Done with hot pixel readout
[09:16:26.081] INFO: PixTest:: pg_setup set to default.
[09:16:26.082] INFO: 9 hot pixels found in step 10
[09:16:27.080] INFO: Collecting data for 5 seconds...
[09:16:32.097] INFO: Done with hot pixel readout
[09:16:44.359] INFO: PixTest:: pg_setup set to default.

[09:16:44.360] INFO: 13 hot pixels found in step 11
[09:16:45.355] INFO: Collecting data for 5 seconds...
[09:16:50.372] INFO: Done with hot pixel readout
[09:17:02.633] INFO: PixTest:: pg_setup set to default.


[09:17:02.634] INFO: 23 hot pixels found in step 12
[09:17:03.630] INFO: Collecting data for 5 seconds...
[09:17:08.646] INFO: Done with hot pixel readout
[09:17:20.897] INFO: PixTest:: pg_setup set to default.
[09:17:20.898] INFO: 16 hot pixels found in step 13
[09:17:21.893] INFO: Collecting data for 5 seconds...
[09:17:26.910] INFO: Done with hot pixel readout
[09:17:39.162] INFO: PixTest:: pg_setup set to default.
[09:17:39.163] INFO: 12 hot pixels found in step 14
[09:17:39.202] INFO: 12 hot pixels could not be trimmed and have been masked.
[09:17:39.205] INFO: PixTest::trimHotPixels() done
[09:17:39.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C0.dat
[09:17:39.211] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C1.dat
[09:17:39.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C2.dat
[09:17:39.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C3.dat
[09:17:39.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C4.dat
[09:17:39.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C5.dat
[09:17:39.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C6.dat
[09:17:39.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C7.dat
[09:17:39.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C8.dat
[09:17:39.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C9.dat
[09:17:39.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C10.dat
[09:17:39.265] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C11.dat
[09:17:39.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C12.dat
[09:17:39.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C13.dat
[09:17:39.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C14.dat
[09:17:39.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C15.dat
[09:17:39.292] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//defaultMaskFile.dat
[09:17:39.302] INFO: enter test to run
[09:18:03.734] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:18:03.734] INFO: running: highrate
[09:18:03.739] INFO: ----------------------------------------------------------------------
[09:18:03.739] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:18:03.739] INFO: ----------------------------------------------------------------------
[09:18:03.739] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:18:03.739] INFO: edge/corner pixel THR is adjusted
[09:18:03.739] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:18:04.696] INFO: Collecting data for 1 seconds...
[09:18:05.700] INFO: Done with hot pixel readout
[09:18:09.954] INFO: PixTest:: pg_setup set to default.
[09:18:09.954] INFO: 0 hot pixels found in step 0
[09:18:09.960] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:18:10.042] INFO: PixTest::trimHotPixels() done
[09:18:10.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C0.dat
[09:18:10.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C1.dat
[09:18:10.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C2.dat
[09:18:10.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C3.dat
[09:18:10.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C4.dat
[09:18:10.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C5.dat
[09:18:10.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C6.dat
[09:18:10.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C7.dat
[09:18:10.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C8.dat
[09:18:10.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C9.dat
[09:18:10.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C10.dat
[09:18:10.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C11.dat
[09:18:10.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C12.dat
[09:18:10.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C13.dat
[09:18:10.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C14.dat
[09:18:10.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//trimParameters35_C15.dat
[09:18:10.130] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-04_FPIXTest-17C-FNAL-160414-0854_2016-04-14_08h54m_1460642076/000_FPIXTest_p17//defaultMaskFile.dat
[09:18:10.140] INFO: enter test to run
[09:18:39.158] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:18:39.158] INFO: running: xray
[09:18:39.159] INFO: ----------------------------------------------------------------------
[09:18:39.159] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:18:39.159] INFO: ----------------------------------------------------------------------
[09:18:40.123] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:18:51.025] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:19:20.631] INFO: Resuming triggers.
[09:19:31.536] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:20:01.183] INFO: Resuming triggers.
[09:20:12.087] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[09:20:41.595] INFO: Resuming triggers.
[09:20:52.498] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:21:22.131] INFO: Resuming triggers.
[09:21:33.037] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[09:22:02.636] INFO: Resuming triggers.
[09:22:13.546] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[09:22:43.191] INFO: Resuming triggers.
[09:22:54.095] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[09:23:21.710] INFO: Resuming triggers.
[09:23:32.617] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[09:24:02.093] INFO: Resuming triggers.
[09:24:12.995] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[09:24:42.571] INFO: Resuming triggers.
[09:24:44.751] INFO: data taking finished, elapsed time: 100 seconds.
[09:24:51.008] INFO: PixTest:: pg_setup set to default.
[09:24:51.012] INFO: PixTestXray::doPhRun() done
[09:24:51.174] INFO: enter test to run
[09:25:25.755] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:25:25.755] INFO: running: xray
[09:25:25.756] INFO: ----------------------------------------------------------------------
[09:25:25.756] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:25:25.756] INFO: ----------------------------------------------------------------------
[09:25:26.732] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:25:32.984] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:26:03.089] INFO: Resuming triggers.
[09:26:09.341] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:26:39.388] INFO: Resuming triggers.
[09:26:45.638] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:27:15.675] INFO: Resuming triggers.
[09:27:21.925] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[09:27:51.977] INFO: Resuming triggers.
[09:27:58.227] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:28:28.318] INFO: Resuming triggers.
[09:28:34.567] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:29:04.572] INFO: Resuming triggers.
[09:29:10.820] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:29:40.859] INFO: Resuming triggers.
[09:29:47.110] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[09:30:17.119] INFO: Resuming triggers.
[09:30:23.370] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:30:53.342] INFO: Resuming triggers.
[09:30:59.593] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:31:29.683] INFO: Resuming triggers.
[09:31:35.936] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:32:05.948] INFO: Resuming triggers.
[09:32:12.200] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:32:42.231] INFO: Resuming triggers.
[09:32:48.481] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:33:13.654] INFO: Resuming triggers.
[09:33:19.907] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:33:49.896] INFO: Resuming triggers.
[09:33:56.147] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:34:26.171] INFO: Resuming triggers.
[09:34:32.422] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[09:35:02.464] INFO: Resuming triggers.
[09:35:02.791] INFO: data taking finished, elapsed time: 100 seconds.
[09:35:04.739] INFO: PixTest:: pg_setup set to default.
[09:35:04.743] INFO: PixTestXray::doPhRun() done
[09:35:04.895] INFO: enter test to run
[09:35:44.782] INFO: test: HighRate no parameter change
[09:35:44.783] INFO: running: highrate
[09:35:44.784] INFO: ----------------------------------------------------------------------
[09:35:44.784] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:35:44.784] INFO: ----------------------------------------------------------------------
[09:35:44.925] INFO: Expecting 768 events.
[09:35:46.059] INFO: 768 events read in total (418ms).
[09:35:46.059] INFO: Test took 1268ms.
[09:35:46.862] INFO: Expecting 41600 events.
[09:35:50.009] INFO: 41600 events read in total (2620ms).
[09:35:50.010] INFO: Test took 3927ms.
[09:35:50.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:50.771] INFO: Expecting 41600 events.
[09:35:54.010] INFO: 41600 events read in total (2712ms).
[09:35:54.011] INFO: Test took 3946ms.
[09:35:54.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:54.767] INFO: Expecting 41600 events.
[09:35:58.026] INFO: 41600 events read in total (2732ms).
[09:35:58.027] INFO: Test took 3959ms.
[09:35:58.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:58.783] INFO: Expecting 41600 events.
[09:36:02.050] INFO: 41600 events read in total (2740ms).
[09:36:02.051] INFO: Test took 3967ms.
[09:36:02.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:02.808] INFO: Expecting 41600 events.
[09:36:06.080] INFO: 41600 events read in total (2745ms).
[09:36:06.081] INFO: Test took 3974ms.
[09:36:06.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:06.838] INFO: Expecting 41600 events.
[09:36:10.120] INFO: 41600 events read in total (2755ms).
[09:36:10.121] INFO: Test took 3981ms.
[09:36:10.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:10.874] INFO: Expecting 41600 events.
[09:36:14.144] INFO: 41600 events read in total (2743ms).
[09:36:14.145] INFO: Test took 3967ms.
[09:36:14.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:14.902] INFO: Expecting 41600 events.
[09:36:18.185] INFO: 41600 events read in total (2756ms).
[09:36:18.186] INFO: Test took 3985ms.
[09:36:18.224] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:18.941] INFO: Expecting 41600 events.
[09:36:22.229] INFO: 41600 events read in total (2762ms).
[09:36:22.230] INFO: Test took 3986ms.
[09:36:22.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:22.983] INFO: Expecting 41600 events.
[09:36:26.261] INFO: 41600 events read in total (2751ms).
[09:36:26.262] INFO: Test took 3974ms.
[09:36:26.298] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:27.015] INFO: Expecting 41600 events.
[09:36:30.295] INFO: 41600 events read in total (2753ms).
[09:36:30.296] INFO: Test took 3980ms.
[09:36:30.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:31.051] INFO: Expecting 41600 events.
[09:36:34.327] INFO: 41600 events read in total (2749ms).
[09:36:34.328] INFO: Test took 3975ms.
[09:36:34.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:35.084] INFO: Expecting 41600 events.
[09:36:38.359] INFO: 41600 events read in total (2748ms).
[09:36:38.360] INFO: Test took 3975ms.
[09:36:38.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:39.116] INFO: Expecting 41600 events.
[09:36:42.389] INFO: 41600 events read in total (2746ms).
[09:36:42.390] INFO: Test took 3972ms.
[09:36:42.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:43.143] INFO: Expecting 41600 events.
[09:36:46.424] INFO: 41600 events read in total (2754ms).
[09:36:46.425] INFO: Test took 3976ms.
[09:36:46.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:47.181] INFO: Expecting 41600 events.
[09:36:50.457] INFO: 41600 events read in total (2749ms).
[09:36:50.458] INFO: Test took 3976ms.
[09:36:50.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:51.215] INFO: Expecting 41600 events.
[09:36:54.485] INFO: 41600 events read in total (2743ms).
[09:36:54.486] INFO: Test took 3972ms.
[09:36:54.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:55.239] INFO: Expecting 41600 events.
[09:36:58.521] INFO: 41600 events read in total (2756ms).
[09:36:58.522] INFO: Test took 3977ms.
[09:36:58.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:59.279] INFO: Expecting 41600 events.
[09:37:02.548] INFO: 41600 events read in total (2742ms).
[09:37:02.549] INFO: Test took 3970ms.
[09:37:02.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:03.302] INFO: Expecting 41600 events.
[09:37:06.401] INFO: 41600 events read in total (2572ms).
[09:37:06.402] INFO: Test took 3797ms.
[09:37:06.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:06.805] INFO: enter test to run
[09:37:25.214] INFO: test: HighRate no parameter change
[09:37:25.214] INFO: running: highrate
[09:37:25.215] INFO: ----------------------------------------------------------------------
[09:37:25.215] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:37:25.215] INFO: ----------------------------------------------------------------------
[09:37:25.826] INFO: Expecting 208000 events.
[09:37:37.985] INFO: 208000 events read in total (11632ms).
[09:37:37.988] INFO: Test took 12764ms.
[09:37:38.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:38.404] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 160 0
[09:37:38.404] INFO: number of red-efficiency pixels: 100 43 99 173 150 170 154 140 103 112 160 119 140 88 188 38
[09:37:38.404] INFO: number of X-ray hits detected: 68428 48612 77070 126862 132483 132442 127346 87317 84418 103627 108153 95464 102926 60617 25175 30461
[09:37:38.404] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:37:38.404] INFO: number of Vcal hits detected: 207896 207957 207898 207822 207846 207824 207843 207858 207893 207887 207834 207879 207857 207911 199972 207962
[09:37:38.404] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0
[09:37:38.404] INFO: Vcal hit overall 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 99.9 100.0 96.1 100.0
[09:37:38.404] INFO: X-ray hit rate [MHz/cm2]: 20.1 14.2 22.6 37.2 38.8 38.8 37.3 25.6 24.7 30.4 31.7 28.0 30.2 17.8 7.4 8.9
[09:37:38.404] INFO: PixTestHighRate::doXPixelAlive() done
[09:37:38.452] INFO: PixTest:: pg_setup set to default.
[09:37:38.467] INFO: enter test to run
[09:38:14.637] INFO: test: HighRate no parameter change
[09:38:14.637] INFO: running: highrate
[09:38:14.639] INFO: ----------------------------------------------------------------------
[09:38:14.639] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:38:14.639] INFO: ----------------------------------------------------------------------
[09:38:15.256] INFO: Expecting 208000 events.
[09:38:29.402] INFO: 208000 events read in total (13619ms).
[09:38:29.407] INFO: Test took 14758ms.
[09:38:29.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:30.061] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 160 0
[09:38:30.061] INFO: number of red-efficiency pixels: 240 142 292 553 533 740 554 400 360 361 540 321 325 255 226 74
[09:38:30.061] INFO: number of X-ray hits detected: 142284 101227 159450 261662 274551 275329 264471 182234 175497 215552 224103 197311 215039 125453 53318 63779
[09:38:30.061] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:38:30.061] INFO: number of Vcal hits detected: 207738 207855 207673 207392 207422 207152 207382 207543 207620 207623 207398 207664 207654 207723 199933 207923
[09:38:30.061] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[09:38:30.061] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.9 96.1 100.0
[09:38:30.061] INFO: X-ray hit rate [MHz/cm2]: 41.7 29.7 46.7 76.7 80.5 80.7 77.5 53.4 51.4 63.2 65.7 57.8 63.0 36.8 15.6 18.7
[09:38:30.061] INFO: PixTestHighRate::doXPixelAlive() done
[09:38:30.122] INFO: PixTest:: pg_setup set to default.
[09:38:30.140] INFO: enter test to run
[09:39:03.101] INFO: test: HighRate no parameter change
[09:39:03.101] INFO: running: highrate
[09:39:03.102] INFO: ----------------------------------------------------------------------
[09:39:03.102] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:39:03.102] INFO: ----------------------------------------------------------------------
[09:39:03.718] INFO: Expecting 208000 events.
[09:39:20.056] INFO: 208000 events read in total (15811ms).
[09:39:20.065] INFO: Test took 16954ms.
[09:39:20.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:20.960] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 160 0
[09:39:20.961] INFO: number of red-efficiency pixels: 495 248 612 1285 1231 1652 1206 857 724 847 1193 673 778 583 255 137
[09:39:20.961] INFO: number of X-ray hits detected: 213079 152856 239735 392973 412830 411782 396247 271947 264958 324174 336758 295925 321723 188223 79000 95959
[09:39:20.961] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:39:20.961] INFO: number of Vcal hits detected: 207417 207732 207156 206327 206411 205565 206467 206873 207149 207002 206463 207221 207099 207303 199901 207854
[09:39:20.961] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.3 99.3 99.0 99.3 99.5 99.6 99.6 99.3 99.7 99.6 99.7 100.0 99.9
[09:39:20.961] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.2 99.2 98.8 99.3 99.5 99.6 99.5 99.3 99.6 99.6 99.7 96.1 99.9
[09:39:20.961] INFO: X-ray hit rate [MHz/cm2]: 62.5 44.8 70.3 115.2 121.0 120.7 116.1 79.7 77.7 95.0 98.7 86.7 94.3 55.2 23.2 28.1
[09:39:20.961] INFO: PixTestHighRate::doXPixelAlive() done
[09:39:21.008] INFO: PixTest:: pg_setup set to default.
[09:39:21.029] INFO: enter test to run
[09:39:24.893] INFO: test: exit no parameter change
[09:39:25.225] QUIET: Connection to board 33 closed.
[09:39:25.226] INFO: pXar: this is the end, my friend