[10:11:20.569] INFO: *** Welcome to pxar ***
[10:11:20.569] INFO: *** Today: 2016/05/31
[10:11:20.585] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:11:20.585] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//dacParameters35_C15.dat
[10:11:20.624] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:11:20.624] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[10:11:20.633] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[10:11:20.712] INFO: clk: 4
[10:11:20.712] INFO: ctr: 4
[10:11:20.712] INFO: sda: 19
[10:11:20.712] INFO: tin: 9
[10:11:20.712] INFO: level: 15
[10:11:20.712] INFO: triggerdelay: 0
[10:11:20.712] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:11:20.712] INFO: Log level: INFO
[10:11:20.730] QUIET: Connection to board DTB_WREKRL opened.
[10:11:20.734] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[10:11:20.736] INFO: RPC call hashes of host and DTB match: 398089610
[10:11:22.268] INFO: DUT info:
[10:11:22.268] INFO: The DUT currently contains the following objects:
[10:11:22.268] INFO: 2 TBM Cores tbm08c (2 ON)
[10:11:22.268] INFO: TBM Core alpha (0): 7 registers set
[10:11:22.268] INFO: TBM Core beta (1): 7 registers set
[10:11:22.268] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:11:22.268] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.268] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:11:22.671] INFO: enter 'restricted' command line mode
[10:11:22.671] INFO: enter test to run
[10:11:50.635] INFO: test: PixelAlive no parameter change
[10:11:50.635] INFO: running: pixelalive
[10:11:50.644] INFO: ----------------------------------------------------------------------
[10:11:50.644] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:11:50.644] INFO: ----------------------------------------------------------------------
[10:11:50.965] INFO: Expecting 41600 events.
[10:11:55.281] INFO: 41600 events read in total (3597ms).
[10:11:55.448] INFO: Test took 4800ms.
[10:11:55.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:55.724] INFO: PixTestAlive::aliveTest() done
[10:11:55.724] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 1 2 0 0
[10:11:55.758] INFO: enter test to run
[10:12:39.531] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:12:39.531] INFO: running: highrate
[10:12:39.531] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:12:39.768] INFO: ----------------------------------------------------------------------
[10:12:39.768] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:12:39.768] INFO: ----------------------------------------------------------------------
[10:12:39.768] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:12:39.768] INFO: edge/corner pixel THR is adjusted
[10:12:39.768] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:12:40.727] INFO: Collecting data for 5 seconds...
[10:12:45.743] INFO: Done with hot pixel readout
[10:12:57.572] INFO: PixTest:: pg_setup set to default.
[10:12:57.572] INFO: 11 hot pixels found in step 0
[10:12:58.582] INFO: Collecting data for 5 seconds...
[10:13:03.597] INFO: Done with hot pixel readout
[10:13:15.446] INFO: PixTest:: pg_setup set to default.
[10:13:15.447] INFO: 10 hot pixels found in step 1
[10:13:16.439] INFO: Collecting data for 5 seconds...
[10:13:21.455] INFO: Done with hot pixel readout
[10:13:33.251] INFO: PixTest:: pg_setup set to default.
[10:13:33.252] INFO: 12 hot pixels found in step 2
[10:13:34.244] INFO: Collecting data for 5 seconds...
[10:13:39.259] INFO: Done with hot pixel readout
[10:13:51.074] INFO: PixTest:: pg_setup set to default.
[10:13:51.075] INFO: 12 hot pixels found in step 3
[10:13:52.066] INFO: Collecting data for 5 seconds...
[10:13:57.082] INFO: Done with hot pixel readout
[10:14:08.837] INFO: PixTest:: pg_setup set to default.
[10:14:08.838] INFO: 10 hot pixels found in step 4
[10:14:09.829] INFO: Collecting data for 5 seconds...
[10:14:14.844] INFO: Done with hot pixel readout
[10:14:26.609] INFO: PixTest:: pg_setup set to default.
[10:14:26.610] INFO: 10 hot pixels found in step 5
[10:14:27.601] INFO: Collecting data for 5 seconds...
[10:14:32.617] INFO: Done with hot pixel readout
[10:14:44.408] INFO: PixTest:: pg_setup set to default.

[10:14:44.409] INFO: 10 hot pixels found in step 6
[10:14:45.400] INFO: Collecting data for 5 seconds...
[10:14:50.415] INFO: Done with hot pixel readout
[10:15:02.187] INFO: PixTest:: pg_setup set to default.

[10:15:02.188] INFO: 7 hot pixels found in step 7
[10:15:03.181] INFO: Collecting data for 5 seconds...
[10:15:08.197] INFO: Done with hot pixel readout
[10:15:19.901] INFO: PixTest:: pg_setup set to default.

[10:15:19.902] INFO: 2 hot pixels found in step 8
[10:15:20.893] INFO: Collecting data for 5 seconds...
[10:15:25.908] INFO: Done with hot pixel readout
[10:15:37.650] INFO: PixTest:: pg_setup set to default.

[10:15:37.651] INFO: 6 hot pixels found in step 9
[10:15:38.642] INFO: Collecting data for 5 seconds...
[10:15:43.657] INFO: Done with hot pixel readout
[10:15:55.410] INFO: PixTest:: pg_setup set to default.

[10:15:55.411] INFO: 1 hot pixels found in step 10
[10:15:55.446] INFO: 1 hot pixels could not be trimmed and have been masked.
[10:15:55.450] INFO: PixTest::trimHotPixels() done
[10:15:55.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat
[10:15:55.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C1.dat
[10:15:55.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C2.dat
[10:15:55.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C3.dat
[10:15:55.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C4.dat
[10:15:55.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C5.dat
[10:15:55.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C6.dat
[10:15:55.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C7.dat
[10:15:55.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C8.dat
[10:15:55.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C9.dat
[10:15:55.514] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C10.dat
[10:15:55.519] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C11.dat
[10:15:55.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C12.dat
[10:15:55.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C13.dat
[10:15:55.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C14.dat
[10:15:55.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[10:15:55.545] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[10:15:55.559] INFO: enter test to run
[10:16:32.225] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:16:32.225] INFO: running: highrate
[10:16:32.229] INFO: ----------------------------------------------------------------------
[10:16:32.229] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:16:32.230] INFO: ----------------------------------------------------------------------
[10:16:32.230] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:16:32.230] INFO: edge/corner pixel THR is adjusted
[10:16:32.230] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:16:33.187] INFO: Collecting data for 1 seconds...
[10:16:34.191] INFO: Done with hot pixel readout
[10:16:38.243] INFO: PixTest:: pg_setup set to default.
[10:16:38.244] INFO: 0 hot pixels found in step 0
[10:16:38.249] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:16:38.338] INFO: PixTest::trimHotPixels() done
[10:16:38.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C0.dat
[10:16:38.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C1.dat
[10:16:38.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C2.dat
[10:16:38.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C3.dat
[10:16:38.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C4.dat
[10:16:38.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C5.dat
[10:16:38.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C6.dat
[10:16:38.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C7.dat
[10:16:38.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C8.dat
[10:16:38.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C9.dat
[10:16:38.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C10.dat
[10:16:38.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C11.dat
[10:16:38.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C12.dat
[10:16:38.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C13.dat
[10:16:38.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C14.dat
[10:16:38.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//trimParameters35_C15.dat
[10:16:38.435] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-14_FPIXTest-17C-FNAL-160524-0931_2016-05-24_09h31m_1464100312/000_FPIXTest_p17//defaultMaskFile.dat
[10:16:38.444] INFO: enter test to run
[10:17:10.169] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:17:10.169] INFO: running: xray
[10:17:10.170] INFO: ----------------------------------------------------------------------
[10:17:10.170] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:17:10.170] INFO: ----------------------------------------------------------------------
[10:17:11.133] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:17:22.571] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:17:52.009] INFO: Resuming triggers.
[10:18:03.449] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:18:32.815] INFO: Resuming triggers.
[10:18:44.259] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:19:13.562] INFO: Resuming triggers.
[10:19:24.004] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[10:19:54.396] INFO: Resuming triggers.
[10:20:05.841] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:20:35.228] INFO: Resuming triggers.
[10:20:46.670] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:21:15.965] INFO: Resuming triggers.
[10:21:27.406] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:21:56.709] INFO: Resuming triggers.
[10:22:08.153] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[10:22:37.432] INFO: Resuming triggers.
[10:22:46.205] INFO: data taking finished, elapsed time: 100 seconds.
[10:23:08.846] INFO: PixTest:: pg_setup set to default.
[10:23:08.849] INFO: PixTestXray::doPhRun() done
[10:23:09.023] INFO: enter test to run
[10:23:48.310] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:23:48.310] INFO: running: xray
[10:23:48.311] INFO: ----------------------------------------------------------------------
[10:23:48.311] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:23:48.311] INFO: ----------------------------------------------------------------------
[10:23:49.280] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:23:55.873] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:24:25.925] INFO: Resuming triggers.
[10:24:32.518] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:25:02.564] INFO: Resuming triggers.
[10:25:09.157] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:25:39.022] INFO: Resuming triggers.
[10:25:45.615] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:26:15.454] INFO: Resuming triggers.
[10:26:22.046] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:26:52.087] INFO: Resuming triggers.
[10:26:58.682] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[10:27:28.605] INFO: Resuming triggers.
[10:27:35.202] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:28:05.080] INFO: Resuming triggers.
[10:28:11.674] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:28:41.618] INFO: Resuming triggers.
[10:28:48.217] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:29:18.142] INFO: Resuming triggers.
[10:29:24.740] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:29:54.614] INFO: Resuming triggers.
[10:30:01.211] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:30:31.103] INFO: Resuming triggers.
[10:30:37.702] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[10:31:07.617] INFO: Resuming triggers.
[10:31:14.215] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[10:31:44.161] INFO: Resuming triggers.
[10:31:50.758] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:32:20.650] INFO: Resuming triggers.
[10:32:27.249] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:32:57.101] INFO: Resuming triggers.
[10:32:58.465] INFO: data taking finished, elapsed time: 100 seconds.
[10:33:04.989] INFO: PixTest:: pg_setup set to default.
[10:33:04.993] INFO: PixTestXray::doPhRun() done
[10:33:05.142] INFO: enter test to run
[10:33:40.017] INFO: test: HighRate no parameter change
[10:33:40.017] INFO: running: highrate
[10:33:40.018] INFO: ----------------------------------------------------------------------
[10:33:40.018] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:33:40.018] INFO: ----------------------------------------------------------------------
[10:33:40.159] INFO: Expecting 768 events.
[10:33:41.291] INFO: 768 events read in total (417ms).
[10:33:41.291] INFO: Test took 1267ms.
[10:33:42.094] INFO: Expecting 41600 events.
[10:33:45.175] INFO: 41600 events read in total (2554ms).
[10:33:45.176] INFO: Test took 3877ms.
[10:33:45.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:45.938] INFO: Expecting 41600 events.
[10:33:49.125] INFO: 41600 events read in total (2660ms).
[10:33:49.126] INFO: Test took 3898ms.
[10:33:49.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:49.886] INFO: Expecting 41600 events.
[10:33:53.110] INFO: 41600 events read in total (2697ms).
[10:33:53.111] INFO: Test took 3932ms.
[10:33:53.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:53.872] INFO: Expecting 41600 events.
[10:33:57.102] INFO: 41600 events read in total (2703ms).
[10:33:57.103] INFO: Test took 3940ms.
[10:33:57.137] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:57.858] INFO: Expecting 41600 events.
[10:34:01.101] INFO: 41600 events read in total (2717ms).
[10:34:01.102] INFO: Test took 3947ms.
[10:34:01.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:01.861] INFO: Expecting 41600 events.
[10:34:05.082] INFO: 41600 events read in total (2694ms).
[10:34:05.083] INFO: Test took 3929ms.
[10:34:05.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:05.839] INFO: Expecting 41600 events.
[10:34:09.068] INFO: 41600 events read in total (2702ms).
[10:34:09.069] INFO: Test took 3935ms.
[10:34:09.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:09.828] INFO: Expecting 41600 events.
[10:34:13.074] INFO: 41600 events read in total (2719ms).
[10:34:13.075] INFO: Test took 3953ms.
[10:34:13.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:13.830] INFO: Expecting 41600 events.
[10:34:17.063] INFO: 41600 events read in total (2706ms).
[10:34:17.063] INFO: Test took 3934ms.
[10:34:17.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:17.824] INFO: Expecting 41600 events.
[10:34:21.057] INFO: 41600 events read in total (2707ms).
[10:34:21.058] INFO: Test took 3942ms.
[10:34:21.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:21.818] INFO: Expecting 41600 events.
[10:34:25.086] INFO: 41600 events read in total (2741ms).
[10:34:25.087] INFO: Test took 3975ms.
[10:34:25.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:25.844] INFO: Expecting 41600 events.
[10:34:29.082] INFO: 41600 events read in total (2711ms).
[10:34:29.084] INFO: Test took 3945ms.
[10:34:29.125] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:29.839] INFO: Expecting 41600 events.
[10:34:33.070] INFO: 41600 events read in total (2704ms).
[10:34:33.071] INFO: Test took 3927ms.
[10:34:33.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:33.829] INFO: Expecting 41600 events.
[10:34:37.062] INFO: 41600 events read in total (2706ms).
[10:34:37.063] INFO: Test took 3937ms.
[10:34:37.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:37.818] INFO: Expecting 41600 events.
[10:34:41.070] INFO: 41600 events read in total (2725ms).
[10:34:41.071] INFO: Test took 3956ms.
[10:34:41.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:41.825] INFO: Expecting 41600 events.
[10:34:45.055] INFO: 41600 events read in total (2703ms).
[10:34:45.056] INFO: Test took 3931ms.
[10:34:45.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:45.812] INFO: Expecting 41600 events.
[10:34:49.041] INFO: 41600 events read in total (2702ms).
[10:34:49.042] INFO: Test took 3933ms.
[10:34:49.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:49.801] INFO: Expecting 41600 events.
[10:34:53.046] INFO: 41600 events read in total (2718ms).
[10:34:53.047] INFO: Test took 3951ms.
[10:34:53.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:53.803] INFO: Expecting 41600 events.
[10:34:57.019] INFO: 41600 events read in total (2689ms).
[10:34:57.020] INFO: Test took 3919ms.
[10:34:57.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:57.779] INFO: Expecting 41600 events.
[10:35:00.878] INFO: 41600 events read in total (2572ms).
[10:35:00.879] INFO: Test took 3807ms.
[10:35:00.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:01.275] INFO: enter test to run
[10:35:08.953] INFO: test: HighRate no parameter change
[10:35:08.953] INFO: running: highrate
[10:35:08.954] INFO: ----------------------------------------------------------------------
[10:35:08.954] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:35:08.954] INFO: ----------------------------------------------------------------------
[10:35:09.566] INFO: Expecting 208000 events.
[10:35:21.438] INFO: 208000 events read in total (11345ms).
[10:35:21.441] INFO: Test took 12481ms.
[10:35:21.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:21.840] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 1 2 0 0
[10:35:21.840] INFO: number of red-efficiency pixels: 72 44 88 162 148 144 143 92 97 137 119 90 113 58 25 23
[10:35:21.840] INFO: number of X-ray hits detected: 66879 46452 69456 112299 119844 121248 113008 84235 78301 97908 94157 81278 86195 50594 22330 24745
[10:35:21.840] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:35:21.840] INFO: number of Vcal hits detected: 207927 207955 207860 207828 207802 207846 207854 207908 207902 207858 207879 207907 207837 207843 207975 207977
[10:35:21.840] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:35:21.840] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 99.9 100.0 100.0
[10:35:21.840] INFO: X-ray hit rate [MHz/cm2]: 19.6 13.6 20.4 32.9 35.1 35.5 33.1 24.7 23.0 28.7 27.6 23.8 25.3 14.8 6.5 7.3
[10:35:21.840] INFO: PixTestHighRate::doXPixelAlive() done
[10:35:21.891] INFO: PixTest:: pg_setup set to default.
[10:35:21.906] INFO: enter test to run
[10:35:45.824] INFO: test: HighRate no parameter change
[10:35:45.825] INFO: running: highrate
[10:35:45.826] INFO: ----------------------------------------------------------------------
[10:35:45.826] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:35:45.826] INFO: ----------------------------------------------------------------------
[10:35:46.442] INFO: Expecting 208000 events.
[10:36:00.178] INFO: 208000 events read in total (13209ms).
[10:36:00.183] INFO: Test took 14349ms.
[10:36:00.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:00.787] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 1 2 0 0
[10:36:00.788] INFO: number of red-efficiency pixels: 221 124 303 542 533 465 376 310 275 387 393 278 263 145 50 48
[10:36:00.788] INFO: number of X-ray hits detected: 138802 96501 144456 233486 249162 252711 237555 176334 163537 205196 197242 169623 180304 105275 46933 52195
[10:36:00.788] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:36:00.788] INFO: number of Vcal hits detected: 207766 207867 207624 207404 207360 207494 207596 207668 207717 207588 207586 207705 207677 207739 207948 207949
[10:36:00.788] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:36:00.788] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:36:00.788] INFO: X-ray hit rate [MHz/cm2]: 40.7 28.3 42.3 68.4 73.0 74.1 69.6 51.7 47.9 60.1 57.8 49.7 52.8 30.9 13.8 15.3
[10:36:00.788] INFO: PixTestHighRate::doXPixelAlive() done
[10:36:00.832] INFO: PixTest:: pg_setup set to default.
[10:36:00.850] INFO: enter test to run
[10:36:26.800] INFO: test: HighRate no parameter change
[10:36:26.800] INFO: running: highrate
[10:36:26.801] INFO: ----------------------------------------------------------------------
[10:36:26.801] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:36:26.801] INFO: ----------------------------------------------------------------------
[10:36:27.419] INFO: Expecting 208000 events.
[10:36:43.172] INFO: 208000 events read in total (15226ms).
[10:36:43.180] INFO: Test took 16370ms.
[10:36:43.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:44.010] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 1 2 0 0
[10:36:44.010] INFO: number of red-efficiency pixels: 536 264 696 1248 1260 1076 962 680 610 1042 914 659 560 328 101 102
[10:36:44.010] INFO: number of X-ray hits detected: 210172 146414 219891 355069 378096 383027 359281 266665 248332 310846 299341 257711 275224 161368 70634 78725
[10:36:44.010] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:36:44.010] INFO: number of Vcal hits detected: 207341 207710 207015 206363 206323 206623 206832 207180 207310 206741 206899 207259 207324 207529 207898 207892
[10:36:44.010] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.3 99.3 99.4 99.5 99.6 99.7 99.4 99.5 99.7 99.7 99.8 100.0 100.0
[10:36:44.010] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.2 99.2 99.3 99.4 99.6 99.7 99.4 99.5 99.6 99.7 99.8 100.0 99.9
[10:36:44.010] INFO: X-ray hit rate [MHz/cm2]: 61.6 42.9 64.5 104.1 110.8 112.3 105.3 78.2 72.8 91.1 87.7 75.5 80.7 47.3 20.7 23.1
[10:36:44.010] INFO: PixTestHighRate::doXPixelAlive() done
[10:36:44.062] INFO: PixTest:: pg_setup set to default.
[10:36:44.078] INFO: enter test to run
[10:36:46.880] INFO: test: exit no parameter change
[10:36:47.184] QUIET: Connection to board 33 closed.
[10:36:47.185] INFO: pXar: this is the end, my friend