[12:08:19.729] INFO: *** Welcome to pxar ***
[12:08:19.729] INFO: *** Today: 2016/05/09
[12:08:20.873] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:08:20.873] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//dacParameters35_C15.dat
[12:08:21.182] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:08:21.182] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:21.214] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:22.283] INFO: clk: 4
[12:08:22.283] INFO: ctr: 4
[12:08:22.283] INFO: sda: 19
[12:08:22.283] INFO: tin: 9
[12:08:22.283] INFO: level: 15
[12:08:22.283] INFO: triggerdelay: 0
[12:08:22.284] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:08:22.284] INFO: Log level: INFO
[12:08:22.302] QUIET: Connection to board DTB_WREKRL opened.
[12:08:22.306] 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:
------------------------------------------------------
[12:08:22.309] INFO: RPC call hashes of host and DTB match: 398089610
[12:08:23.835] INFO: DUT info:
[12:08:23.835] INFO: The DUT currently contains the following objects:
[12:08:23.835] INFO: 2 TBM Cores tbm08c (2 ON)
[12:08:23.835] INFO: TBM Core alpha (0): 7 registers set
[12:08:23.835] INFO: TBM Core beta (1): 7 registers set
[12:08:23.835] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:08:23.835] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:23.835] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:08:24.306] INFO: enter 'restricted' command line mode
[12:08:24.307] INFO: enter test to run
[12:08:33.293] INFO: test: PixelAlive no parameter change
[12:08:33.294] INFO: running: pixelalive
[12:08:33.303] INFO: ----------------------------------------------------------------------
[12:08:33.303] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:08:33.303] INFO: ----------------------------------------------------------------------
[12:08:33.620] INFO: Expecting 41600 events.
[12:08:37.923] INFO: 41600 events read in total (3584ms).
[12:08:38.093] INFO: Test took 4788ms.
[12:08:38.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:38.367] INFO: PixTestAlive::aliveTest() done
[12:08:38.367] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 2 0 0 1 0 0 0 0
[12:08:38.400] INFO: enter test to run
[12:09:11.045] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:09:11.045] INFO: running: highrate
[12:09:11.046] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:09:12.203] INFO: ----------------------------------------------------------------------
[12:09:12.203] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:09:12.203] INFO: ----------------------------------------------------------------------
[12:09:12.203] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:09:12.203] INFO: edge/corner pixel THR is adjusted
[12:09:12.203] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:09:13.162] INFO: Collecting data for 5 seconds...
[12:09:18.178] INFO: Done with hot pixel readout
[12:09:30.461] INFO: PixTest:: pg_setup set to default.
[12:09:30.462] INFO: 9 hot pixels found in step 0
[12:09:31.480] INFO: Collecting data for 5 seconds...
[12:09:36.497] INFO: Done with hot pixel readout
[12:09:48.748] INFO: PixTest:: pg_setup set to default.
[12:09:48.749] INFO: 12 hot pixels found in step 1
[12:09:49.743] INFO: Collecting data for 5 seconds...
[12:09:54.760] INFO: Done with hot pixel readout
[12:10:07.090] INFO: PixTest:: pg_setup set to default.
[12:10:07.091] INFO: 7 hot pixels found in step 2
[12:10:08.088] INFO: Collecting data for 5 seconds...
[12:10:13.105] INFO: Done with hot pixel readout
[12:10:25.571] INFO: PixTest:: pg_setup set to default.
[12:10:25.572] INFO: 6 hot pixels found in step 3
[12:10:26.569] INFO: Collecting data for 5 seconds...
[12:10:31.586] INFO: Done with hot pixel readout
[12:10:44.060] INFO: PixTest:: pg_setup set to default.
[12:10:44.061] INFO: 7 hot pixels found in step 4
[12:10:45.058] INFO: Collecting data for 5 seconds...
[12:10:50.074] INFO: Done with hot pixel readout
[12:11:02.532] INFO: PixTest:: pg_setup set to default.
[12:11:02.533] INFO: 10 hot pixels found in step 5
[12:11:03.531] INFO: Collecting data for 5 seconds...
[12:11:08.547] INFO: Done with hot pixel readout
[12:11:20.916] INFO: PixTest:: pg_setup set to default.
[12:11:20.917] INFO: 17 hot pixels found in step 6
[12:11:21.914] INFO: Collecting data for 5 seconds...
[12:11:26.931] INFO: Done with hot pixel readout
[12:11:39.385] INFO: PixTest:: pg_setup set to default.
[12:11:39.386] INFO: 8 hot pixels found in step 7
[12:11:40.383] INFO: Collecting data for 5 seconds...
[12:11:45.400] INFO: Done with hot pixel readout
[12:11:57.853] INFO: PixTest:: pg_setup set to default.
[12:11:57.854] INFO: 4 hot pixels found in step 8
[12:11:58.852] INFO: Collecting data for 5 seconds...
[12:12:03.868] INFO: Done with hot pixel readout
[12:12:16.309] INFO: PixTest:: pg_setup set to default.
[12:12:16.310] INFO: 7 hot pixels found in step 9
[12:12:17.308] INFO: Collecting data for 5 seconds...
[12:12:22.324] INFO: Done with hot pixel readout
[12:12:34.786] INFO: PixTest:: pg_setup set to default.
[12:12:34.787] INFO: 7 hot pixels found in step 10
[12:12:35.785] INFO: Collecting data for 5 seconds...
[12:12:40.801] INFO: Done with hot pixel readout
[12:12:53.265] INFO: PixTest:: pg_setup set to default.
[12:12:53.266] INFO: 5 hot pixels found in step 11
[12:12:54.264] INFO: Collecting data for 5 seconds...
[12:12:59.281] INFO: Done with hot pixel readout
[12:13:11.700] INFO: PixTest:: pg_setup set to default.
[12:13:11.701] INFO: 5 hot pixels found in step 12
[12:13:12.698] INFO: Collecting data for 5 seconds...
[12:13:17.714] INFO: Done with hot pixel readout
[12:13:30.158] INFO: PixTest:: pg_setup set to default.
[12:13:30.159] INFO: 8 hot pixels found in step 13
[12:13:31.156] INFO: Collecting data for 5 seconds...
[12:13:36.173] INFO: Done with hot pixel readout
[12:13:48.703] INFO: PixTest:: pg_setup set to default.
[12:13:48.704] INFO: 9 hot pixels found in step 14
[12:13:48.746] INFO: 9 hot pixels could not be trimmed and have been masked.
[12:13:48.750] INFO: PixTest::trimHotPixels() done
[12:13:48.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C0.dat
[12:13:48.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C1.dat
[12:13:48.764] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C2.dat
[12:13:48.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C3.dat
[12:13:48.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C4.dat
[12:13:48.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C5.dat
[12:13:48.792] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C6.dat
[12:13:48.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C7.dat
[12:13:48.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C8.dat
[12:13:48.811] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C9.dat
[12:13:48.818] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C10.dat
[12:13:48.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C11.dat
[12:13:48.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C12.dat
[12:13:48.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C13.dat
[12:13:48.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C14.dat
[12:13:48.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C15.dat
[12:13:48.858] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//defaultMaskFile.dat
[12:13:48.869] INFO: enter test to run
[12:14:15.323] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:14:15.323] INFO: running: highrate
[12:14:15.328] INFO: ----------------------------------------------------------------------
[12:14:15.328] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:14:15.328] INFO: ----------------------------------------------------------------------
[12:14:15.328] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:14:15.328] INFO: edge/corner pixel THR is adjusted
[12:14:15.328] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:14:16.285] INFO: Collecting data for 1 seconds...
[12:14:17.289] INFO: Done with hot pixel readout
[12:14:21.677] INFO: PixTest:: pg_setup set to default.
[12:14:21.678] INFO: 0 hot pixels found in step 0
[12:14:21.683] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:14:21.756] INFO: PixTest::trimHotPixels() done
[12:14:21.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C0.dat
[12:14:21.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C1.dat
[12:14:21.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C2.dat
[12:14:21.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C3.dat
[12:14:21.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C4.dat
[12:14:21.797] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C5.dat
[12:14:21.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C6.dat
[12:14:21.810] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C7.dat
[12:14:21.816] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C8.dat
[12:14:21.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C9.dat
[12:14:21.827] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C10.dat
[12:14:21.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C11.dat
[12:14:21.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C12.dat
[12:14:21.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C13.dat
[12:14:21.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C14.dat
[12:14:21.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//trimParameters35_C15.dat
[12:14:21.860] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-21_FPIXTest-17C-FNAL-160429-1430_2016-04-29_14h30m_1461958228/000_FPIXTest_p17//defaultMaskFile.dat
[12:14:21.870] INFO: enter test to run
[12:14:51.395] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:14:51.395] INFO: running: xray
[12:14:51.396] INFO: ----------------------------------------------------------------------
[12:14:51.396] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:14:51.396] INFO: ----------------------------------------------------------------------
[12:14:52.360] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:15:02.951] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:15:33.342] INFO: Resuming triggers.
[12:15:43.928] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:16:14.764] INFO: Resuming triggers.
[12:16:25.352] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:16:55.521] INFO: Resuming triggers.
[12:17:06.108] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:17:36.125] INFO: Resuming triggers.
[12:17:46.713] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:18:16.735] INFO: Resuming triggers.
[12:18:27.322] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:18:57.430] INFO: Resuming triggers.
[12:19:08.018] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:19:38.079] INFO: Resuming triggers.
[12:19:48.672] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[12:20:18.567] INFO: Resuming triggers.
[12:20:29.160] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:20:59.174] INFO: Resuming triggers.
[12:21:04.225] INFO: data taking finished, elapsed time: 100 seconds.
[12:21:18.799] INFO: PixTest:: pg_setup set to default.
[12:21:18.802] INFO: PixTestXray::doPhRun() done
[12:21:18.942] INFO: enter test to run
[12:22:54.655] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:22:54.655] INFO: running: xray
[12:22:54.656] INFO: ----------------------------------------------------------------------
[12:22:54.656] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:22:54.656] INFO: ----------------------------------------------------------------------
[12:22:55.621] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:23:01.511] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:23:32.263] INFO: Resuming triggers.
[12:23:38.156] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:24:08.971] INFO: Resuming triggers.
[12:24:14.862] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:24:45.682] INFO: Resuming triggers.
[12:24:51.573] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:25:22.941] INFO: Resuming triggers.
[12:25:28.831] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:25:59.832] INFO: Resuming triggers.
[12:26:05.726] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:26:37.561] INFO: Resuming triggers.
[12:26:43.454] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:27:15.383] INFO: Resuming triggers.
[12:27:21.274] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:27:52.080] INFO: Resuming triggers.
[12:27:57.974] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:28:28.663] INFO: Resuming triggers.
[12:28:34.555] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:29:05.327] INFO: Resuming triggers.
[12:29:11.223] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:29:41.985] INFO: Resuming triggers.
[12:29:47.881] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:30:18.504] INFO: Resuming triggers.
[12:30:24.397] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:30:55.481] INFO: Resuming triggers.
[12:31:01.371] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:31:32.109] INFO: Resuming triggers.
[12:31:37.002] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:32:08.771] INFO: Resuming triggers.
[12:32:14.666] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:32:45.200] INFO: Resuming triggers.
[12:32:51.090] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:33:21.822] INFO: Resuming triggers.
[12:33:21.998] INFO: data taking finished, elapsed time: 100 seconds.
[12:33:23.295] INFO: PixTest:: pg_setup set to default.
[12:33:23.298] INFO: PixTestXray::doPhRun() done
[12:33:23.447] INFO: enter test to run
[12:35:43.729] INFO: test: HighRate no parameter change
[12:35:43.730] INFO: running: highrate
[12:35:43.731] INFO: ----------------------------------------------------------------------
[12:35:43.731] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:35:43.731] INFO: ----------------------------------------------------------------------
[12:35:43.871] INFO: Expecting 768 events.
[12:35:44.005] INFO: 768 events read in total (418ms).
[12:35:45.005] INFO: Test took 1268ms.
[12:35:45.809] INFO: Expecting 41600 events.
[12:35:48.987] INFO: 41600 events read in total (2652ms).
[12:35:48.988] INFO: Test took 3975ms.
[12:35:49.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:49.747] INFO: Expecting 41600 events.
[12:35:53.047] INFO: 41600 events read in total (2773ms).
[12:35:53.048] INFO: Test took 4002ms.
[12:35:53.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:53.792] INFO: Expecting 41600 events.
[12:35:57.102] INFO: 41600 events read in total (2783ms).
[12:35:57.103] INFO: Test took 3999ms.
[12:35:57.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:57.859] INFO: Expecting 41600 events.
[12:36:01.117] INFO: 41600 events read in total (2731ms).
[12:36:01.118] INFO: Test took 3958ms.
[12:36:01.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:01.871] INFO: Expecting 41600 events.
[12:36:05.172] INFO: 41600 events read in total (2774ms).
[12:36:05.173] INFO: Test took 3997ms.
[12:36:05.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:05.922] INFO: Expecting 41600 events.
[12:36:09.223] INFO: 41600 events read in total (2775ms).
[12:36:09.224] INFO: Test took 3994ms.
[12:36:09.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:09.967] INFO: Expecting 41600 events.
[12:36:13.307] INFO: 41600 events read in total (2813ms).
[12:36:13.307] INFO: Test took 4026ms.
[12:36:13.346] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:14.054] INFO: Expecting 41600 events.
[12:36:17.344] INFO: 41600 events read in total (2763ms).
[12:36:17.345] INFO: Test took 3980ms.
[12:36:17.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:18.099] INFO: Expecting 41600 events.
[12:36:21.428] INFO: 41600 events read in total (2802ms).
[12:36:21.429] INFO: Test took 4027ms.
[12:36:21.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:22.177] INFO: Expecting 41600 events.
[12:36:25.541] INFO: 41600 events read in total (2838ms).
[12:36:25.542] INFO: Test took 4054ms.
[12:36:25.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:26.296] INFO: Expecting 41600 events.
[12:36:29.574] INFO: 41600 events read in total (2751ms).
[12:36:29.575] INFO: Test took 3975ms.
[12:36:29.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:30.330] INFO: Expecting 41600 events.
[12:36:33.673] INFO: 41600 events read in total (2816ms).
[12:36:33.674] INFO: Test took 4042ms.
[12:36:33.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:34.424] INFO: Expecting 41600 events.
[12:36:37.706] INFO: 41600 events read in total (2755ms).
[12:36:37.707] INFO: Test took 3976ms.
[12:36:37.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:38.459] INFO: Expecting 41600 events.
[12:36:41.716] INFO: 41600 events read in total (2731ms).
[12:36:41.717] INFO: Test took 3951ms.
[12:36:41.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:42.471] INFO: Expecting 41600 events.
[12:36:45.732] INFO: 41600 events read in total (2734ms).
[12:36:45.733] INFO: Test took 3957ms.
[12:36:45.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:46.479] INFO: Expecting 41600 events.
[12:36:49.714] INFO: 41600 events read in total (2708ms).
[12:36:49.715] INFO: Test took 3924ms.
[12:36:49.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:50.463] INFO: Expecting 41600 events.
[12:36:53.671] INFO: 41600 events read in total (2681ms).
[12:36:53.672] INFO: Test took 3899ms.
[12:36:53.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:54.426] INFO: Expecting 41600 events.
[12:36:57.767] INFO: 41600 events read in total (2814ms).
[12:36:57.768] INFO: Test took 4039ms.
[12:36:57.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:58.515] INFO: Expecting 41600 events.
[12:37:01.751] INFO: 41600 events read in total (2710ms).
[12:37:01.752] INFO: Test took 3924ms.
[12:37:01.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:02.500] INFO: Expecting 41600 events.
[12:37:05.630] INFO: 41600 events read in total (2603ms).
[12:37:05.631] INFO: Test took 3821ms.
[12:37:05.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:06.025] INFO: enter test to run
[12:38:14.384] INFO: test: HighRate no parameter change
[12:38:14.384] INFO: running: highrate
[12:38:14.385] INFO: ----------------------------------------------------------------------
[12:38:14.386] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:38:14.386] INFO: ----------------------------------------------------------------------
[12:38:15.009] INFO: Expecting 208000 events.
[12:38:27.304] INFO: 208000 events read in total (11768ms).
[12:38:27.308] INFO: Test took 12914ms.
[12:38:27.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:27.736] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 2 0 0 1 0 0 0 0
[12:38:27.736] INFO: number of red-efficiency pixels: 70 82 118 164 142 139 170 138 119 135 168 155 279 80 33 35
[12:38:27.736] INFO: number of X-ray hits detected: 60562 47689 76782 122491 125978 124006 128740 95138 93600 110160 111049 96978 99277 58934 27446 31684
[12:38:27.736] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:38:27.736] INFO: number of Vcal hits detected: 207929 207869 207879 207832 207856 207857 207821 207856 207782 207862 207827 207791 207710 207908 207966 207965
[12:38:27.736] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:38:27.736] INFO: Vcal hit overall efficiency (%): 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:38:27.736] INFO: X-ray hit rate [MHz/cm2]: 17.8 14.0 22.5 35.9 36.9 36.3 37.7 27.9 27.4 32.3 32.5 28.4 29.1 17.3 8.0 9.3
[12:38:27.736] INFO: PixTestHighRate::doXPixelAlive() done
[12:38:27.781] INFO: PixTest:: pg_setup set to default.
[12:38:27.799] INFO: enter test to run
[12:39:17.856] INFO: test: HighRate no parameter change
[12:39:17.856] INFO: running: highrate
[12:39:17.857] INFO: ----------------------------------------------------------------------
[12:39:17.857] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:39:17.857] INFO: ----------------------------------------------------------------------
[12:39:18.475] INFO: Expecting 208000 events.
[12:39:32.906] INFO: 208000 events read in total (13904ms).
[12:39:32.912] INFO: Test took 15046ms.
[12:39:33.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:33.580] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 2 0 0 1 0 0 0 0
[12:39:33.580] INFO: number of red-efficiency pixels: 238 208 480 555 566 576 586 524 355 615 635 394 575 232 97 72
[12:39:33.580] INFO: number of X-ray hits detected: 132758 104267 169075 268181 275595 271626 280557 208791 206869 242820 242567 211360 217840 128977 59837 69152
[12:39:33.580] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:39:33.580] INFO: number of Vcal hits detected: 207742 207727 207427 207392 207349 207353 207346 207419 207525 207323 207299 207525 207388 207721 207900 207928
[12:39:33.581] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.7 99.8 99.7 99.7 99.8 99.7 99.9 100.0 100.0
[12:39:33.581] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.7 99.7 99.7 99.7 99.7 99.8 99.7 99.7 99.8 99.7 99.9 100.0 100.0
[12:39:33.581] INFO: X-ray hit rate [MHz/cm2]: 38.9 30.6 49.6 78.6 80.8 79.6 82.2 61.2 60.6 71.2 71.1 62.0 63.9 37.8 17.5 20.3
[12:39:33.581] INFO: PixTestHighRate::doXPixelAlive() done
[12:39:33.630] INFO: PixTest:: pg_setup set to default.
[12:39:33.650] INFO: enter test to run
[12:39:52.504] INFO: test: HighRate no parameter change
[12:39:52.504] INFO: running: highrate
[12:39:52.505] INFO: ----------------------------------------------------------------------
[12:39:52.505] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:39:52.505] INFO: ----------------------------------------------------------------------
[12:39:53.119] INFO: Expecting 208000 events.
[12:40:10.175] INFO: 208000 events read in total (16529ms).
[12:40:10.184] INFO: Test took 17669ms.
[12:40:10.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:11.105] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 2 0 0 1 0 0 0 0
[12:40:11.105] INFO: number of red-efficiency pixels: 513 446 1061 1366 1479 1408 1479 1295 813 1493 1614 963 1143 527 154 135
[12:40:11.105] INFO: number of X-ray hits detected: 206329 162678 262199 416812 429284 422260 435729 325576 321022 377938 378307 331178 339719 201754 93384 109382
[12:40:11.106] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:40:11.106] INFO: number of Vcal hits detected: 207414 207432 206315 206168 205992 206098 205960 206087 206955 205946 205759 206773 206583 207273 207835 207863
[12:40:11.106] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.3 99.2 99.1 99.2 99.1 99.2 99.6 99.1 99.0 99.5 99.4 99.7 99.9 99.9
[12:40:11.106] INFO: Vcal hit overall efficiency (%): 99.7 99.7 99.2 99.1 99.0 99.1 99.0 99.1 99.5 99.0 98.9 99.4 99.3 99.7 99.9 99.9
[12:40:11.106] INFO: X-ray hit rate [MHz/cm2]: 60.5 47.7 76.9 122.2 125.8 123.8 127.7 95.4 94.1 110.8 110.9 97.1 99.6 59.1 27.4 32.1
[12:40:11.106] INFO: PixTestHighRate::doXPixelAlive() done
[12:40:11.151] INFO: PixTest:: pg_setup set to default.
[12:40:11.167] INFO: enter test to run
[12:40:16.167] INFO: test: exit no parameter change
[12:40:16.491] QUIET: Connection to board 33 closed.
[12:40:16.493] INFO: pXar: this is the end, my friend