[13:55:13.723] INFO: *** Welcome to pxar ***
[13:55:13.723] INFO: *** Today: 2016/04/22
[13:55:13.892] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:55:13.892] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/dacParameters35_C15.dat
[13:55:13.915] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/tbmParameters_C0b.dat
[13:55:13.915] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/defaultMaskFile.dat
[13:55:13.915] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C15.dat
[13:55:14.032] INFO: clk: 4
[13:55:14.032] INFO: ctr: 4
[13:55:14.032] INFO: sda: 19
[13:55:14.032] INFO: tin: 9
[13:55:14.032] INFO: level: 15
[13:55:14.032] INFO: triggerdelay: 0
[13:55:14.032] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:55:14.032] INFO: Log level: INFO
[13:55:14.051] QUIET: Connection to board DTB_WREKRL opened.
[13:55:14.054] 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:
------------------------------------------------------
[13:55:14.057] INFO: RPC call hashes of host and DTB match: 398089610
[13:55:15.583] INFO: DUT info:
[13:55:15.583] INFO: The DUT currently contains the following objects:
[13:55:15.584] INFO: 2 TBM Cores tbm08c (2 ON)
[13:55:15.584] INFO: TBM Core alpha (0): 7 registers set
[13:55:15.584] INFO: TBM Core beta (1): 7 registers set
[13:55:15.584] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:55:15.584] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.584] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:55:15.987] INFO: enter 'restricted' command line mode
[13:55:15.988] INFO: enter test to run
[13:55:31.242] INFO: test: PixelAlive no parameter change
[13:55:31.242] INFO: running: pixelalive
[13:55:31.252] INFO: ----------------------------------------------------------------------
[13:55:31.252] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:55:31.252] INFO: ----------------------------------------------------------------------
[13:55:31.570] INFO: Expecting 41600 events.
[13:55:35.908] INFO: 41600 events read in total (3619ms).
[13:55:36.072] INFO: Test took 4818ms.
[13:55:36.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:36.343] INFO: PixTestAlive::aliveTest() done
[13:55:36.343] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[13:55:36.375] INFO: enter test to run
[13:56:02.026] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:56:02.026] INFO: running: highrate
[13:56:02.027] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/phCalibrationFitErr35_C15.dat
[13:56:02.251] INFO: ----------------------------------------------------------------------
[13:56:02.251] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:56:02.251] INFO: ----------------------------------------------------------------------
[13:56:02.251] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:56:02.251] INFO: edge/corner pixel THR is adjusted
[13:56:02.251] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:56:03.209] INFO: Collecting data for 5 seconds...
[13:56:08.227] INFO: Done with hot pixel readout
[13:56:20.147] INFO: PixTest:: pg_setup set to default.
[13:56:20.148] INFO: 12 hot pixels found in step 0
[13:56:21.142] INFO: Collecting data for 5 seconds...
[13:56:26.158] INFO: Done with hot pixel readout
[13:56:38.108] INFO: PixTest:: pg_setup set to default.
[13:56:38.109] INFO: 12 hot pixels found in step 1
[13:56:39.105] INFO: Collecting data for 5 seconds...
[13:56:44.120] INFO: Done with hot pixel readout
[13:56:56.115] INFO: PixTest:: pg_setup set to default.
[13:56:56.115] INFO: 9 hot pixels found in step 2
[13:56:57.111] INFO: Collecting data for 5 seconds...
[13:57:02.127] INFO: Done with hot pixel readout
[13:57:13.970] INFO: PixTest:: pg_setup set to default.
[13:57:13.971] INFO: 12 hot pixels found in step 3
[13:57:14.965] INFO: Collecting data for 5 seconds...
[13:57:19.982] INFO: Done with hot pixel readout
[13:57:31.928] INFO: PixTest:: pg_setup set to default.
[13:57:31.929] INFO: 9 hot pixels found in step 4
[13:57:32.924] INFO: Collecting data for 5 seconds...
[13:57:37.941] INFO: Done with hot pixel readout
[13:57:49.862] INFO: PixTest:: pg_setup set to default.
[13:57:49.863] INFO: 8 hot pixels found in step 5
[13:57:50.858] INFO: Collecting data for 5 seconds...
[13:57:55.874] INFO: Done with hot pixel readout
[13:58:07.843] INFO: PixTest:: pg_setup set to default.
[13:58:07.844] INFO: 7 hot pixels found in step 6
[13:58:08.838] INFO: Collecting data for 5 seconds...
[13:58:13.855] INFO: Done with hot pixel readout
[13:58:25.815] INFO: PixTest:: pg_setup set to default.
[13:58:25.816] INFO: 6 hot pixels found in step 7
[13:58:26.811] INFO: Collecting data for 5 seconds...
[13:58:31.827] INFO: Done with hot pixel readout
[13:58:43.801] INFO: PixTest:: pg_setup set to default.


[13:58:43.802] INFO: 3 hot pixels found in step 8
[13:58:44.797] INFO: Collecting data for 5 seconds...
[13:58:49.814] INFO: Done with hot pixel readout
[13:59:01.750] INFO: PixTest:: pg_setup set to default.


[13:59:01.750] INFO: 7 hot pixels found in step 9
[13:59:02.744] INFO: Collecting data for 5 seconds...
[13:59:07.761] INFO: Done with hot pixel readout
[13:59:19.595] INFO: PixTest:: pg_setup set to default.

[13:59:19.595] INFO: 5 hot pixels found in step 10
[13:59:20.591] INFO: Collecting data for 5 seconds...
[13:59:25.603] INFO: Done with hot pixel readout
[13:59:34.832] INFO: PixTest:: pg_setup set to default.


[13:59:34.833] INFO: 3 hot pixels found in step 11
[13:59:35.826] INFO: Collecting data for 5 seconds...
[13:59:40.837] INFO: Done with hot pixel readout
[13:59:52.750] INFO: PixTest:: pg_setup set to default.


[13:59:52.751] INFO: 4 hot pixels found in step 12
[13:59:53.749] INFO: Collecting data for 5 seconds...
[13:59:58.766] INFO: Done with hot pixel readout
[14:00:10.725] INFO: PixTest:: pg_setup set to default.


[14:00:10.726] INFO: 3 hot pixels found in step 13
[14:00:11.722] INFO: Collecting data for 5 seconds...
[14:00:16.738] INFO: Done with hot pixel readout
[14:00:28.691] INFO: PixTest:: pg_setup set to default.

[14:00:28.692] INFO: 4 hot pixels found in step 14
[14:00:28.730] INFO: 4 hot pixels could not be trimmed and have been masked.
[14:00:28.734] INFO: PixTest::trimHotPixels() done
[14:00:28.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C0.dat
[14:00:28.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C1.dat
[14:00:28.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C2.dat
[14:00:28.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C3.dat
[14:00:28.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C4.dat
[14:00:28.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C5.dat
[14:00:28.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C6.dat
[14:00:28.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C7.dat
[14:00:28.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C8.dat
[14:00:28.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C9.dat
[14:00:28.788] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C10.dat
[14:00:28.793] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C11.dat
[14:00:28.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C12.dat
[14:00:28.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C13.dat
[14:00:28.809] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C14.dat
[14:00:28.814] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C15.dat
[14:00:28.819] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/defaultMaskFile.dat
[14:00:28.829] INFO: enter test to run
[14:01:12.072] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:01:12.072] INFO: running: highrate
[14:01:12.076] INFO: ----------------------------------------------------------------------
[14:01:12.077] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:01:12.077] INFO: ----------------------------------------------------------------------
[14:01:12.077] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:01:12.077] INFO: edge/corner pixel THR is adjusted
[14:01:12.077] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:01:13.035] INFO: Collecting data for 1 seconds...
[14:01:14.038] INFO: Done with hot pixel readout
[14:01:18.155] INFO: PixTest:: pg_setup set to default.
[14:01:18.156] INFO: 0 hot pixels found in step 0
[14:01:18.161] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:01:18.249] INFO: PixTest::trimHotPixels() done
[14:01:18.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C0.dat
[14:01:18.259] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C1.dat
[14:01:18.264] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C2.dat
[14:01:18.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C3.dat
[14:01:18.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C4.dat
[14:01:18.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C5.dat
[14:01:18.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C6.dat
[14:01:18.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C7.dat
[14:01:18.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C8.dat
[14:01:18.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C9.dat
[14:01:18.306] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C10.dat
[14:01:18.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C11.dat
[14:01:18.317] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C12.dat
[14:01:18.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C13.dat
[14:01:18.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C14.dat
[14:01:18.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/trimParameters35_C15.dat
[14:01:18.338] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17/defaultMaskFile.dat
[14:01:18.347] INFO: enter test to run
[14:01:54.776] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:01:54.776] INFO: running: xray
[14:01:54.777] INFO: ----------------------------------------------------------------------
[14:01:54.777] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:01:54.777] INFO: ----------------------------------------------------------------------
[14:01:55.740] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:02:07.098] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:02:36.473] INFO: Resuming triggers.
[14:02:47.842] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:03:17.251] INFO: Resuming triggers.
[14:03:28.614] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:03:57.982] INFO: Resuming triggers.
[14:04:09.345] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:04:38.709] INFO: Resuming triggers.
[14:04:50.077] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:05:19.486] INFO: Resuming triggers.
[14:05:30.848] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:06:00.238] INFO: Resuming triggers.
[14:06:11.608] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:06:41.038] INFO: Resuming triggers.
[14:06:52.402] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:07:21.746] INFO: Resuming triggers.
[14:07:31.151] INFO: data taking finished, elapsed time: 100 seconds.
[14:07:55.574] INFO: PixTest:: pg_setup set to default.
[14:07:55.577] INFO: PixTestXray::doPhRun() done
[14:07:55.712] INFO: enter test to run
[14:08:37.453] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:08:37.453] INFO: running: xray
[14:08:37.454] INFO: ----------------------------------------------------------------------
[14:08:37.454] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:08:37.454] INFO: ----------------------------------------------------------------------
[14:08:38.433] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:08:44.853] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:09:14.822] INFO: Resuming triggers.
[14:09:21.245] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:09:48.482] INFO: Resuming triggers.
[14:09:54.894] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:10:24.923] INFO: Resuming triggers.
[14:10:31.339] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[14:11:01.374] INFO: Resuming triggers.
[14:11:07.788] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[14:11:37.760] INFO: Resuming triggers.
[14:11:44.173] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[14:12:14.198] INFO: Resuming triggers.
[14:12:20.612] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:12:50.676] INFO: Resuming triggers.
[14:12:57.092] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:13:27.161] INFO: Resuming triggers.
[14:13:33.576] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:14:03.640] INFO: Resuming triggers.
[14:14:10.057] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:14:40.137] INFO: Resuming triggers.
[14:14:46.551] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:15:16.631] INFO: Resuming triggers.
[14:15:23.043] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:15:53.183] INFO: Resuming triggers.
[14:15:59.597] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:16:29.573] INFO: Resuming triggers.
[14:16:35.990] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:17:06.112] INFO: Resuming triggers.
[14:17:12.530] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:17:42.600] INFO: Resuming triggers.
[14:17:46.689] INFO: data taking finished, elapsed time: 100 seconds.
[14:18:06.070] INFO: PixTest:: pg_setup set to default.
[14:18:06.073] INFO: PixTestXray::doPhRun() done
[14:18:06.221] INFO: enter test to run
[14:18:58.712] INFO: test: HighRate no parameter change
[14:18:58.712] INFO: running: highrate
[14:18:58.713] INFO: ----------------------------------------------------------------------
[14:18:58.713] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:18:58.713] INFO: ----------------------------------------------------------------------
[14:18:58.853] INFO: Expecting 768 events.
[14:18:59.987] INFO: 768 events read in total (418ms).
[14:18:59.988] INFO: Test took 1269ms.
[14:19:00.791] INFO: Expecting 41600 events.
[14:19:03.906] INFO: 41600 events read in total (2588ms).
[14:19:03.907] INFO: Test took 3912ms.
[14:19:03.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:04.671] INFO: Expecting 41600 events.
[14:19:07.878] INFO: 41600 events read in total (2680ms).
[14:19:07.879] INFO: Test took 3919ms.
[14:19:07.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:08.639] INFO: Expecting 41600 events.
[14:19:11.873] INFO: 41600 events read in total (2707ms).
[14:19:11.874] INFO: Test took 3941ms.
[14:19:11.910] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:12.632] INFO: Expecting 41600 events.
[14:19:15.893] INFO: 41600 events read in total (2735ms).
[14:19:15.895] INFO: Test took 3968ms.
[14:19:15.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:16.652] INFO: Expecting 41600 events.
[14:19:19.911] INFO: 41600 events read in total (2732ms).
[14:19:19.912] INFO: Test took 3963ms.
[14:19:19.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:20.668] INFO: Expecting 41600 events.
[14:19:23.931] INFO: 41600 events read in total (2736ms).
[14:19:23.932] INFO: Test took 3964ms.
[14:19:23.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:24.685] INFO: Expecting 41600 events.
[14:19:27.953] INFO: 41600 events read in total (2741ms).
[14:19:27.953] INFO: Test took 3966ms.
[14:19:27.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:28.709] INFO: Expecting 41600 events.
[14:19:31.960] INFO: 41600 events read in total (2724ms).
[14:19:31.961] INFO: Test took 3953ms.
[14:19:31.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:32.717] INFO: Expecting 41600 events.
[14:19:35.967] INFO: 41600 events read in total (2723ms).
[14:19:35.968] INFO: Test took 3953ms.
[14:19:35.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:36.722] INFO: Expecting 41600 events.
[14:19:39.551] INFO: 41600 events read in total (2302ms).
[14:19:39.551] INFO: Test took 3529ms.
[14:19:39.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:40.312] INFO: Expecting 41600 events.
[14:19:43.314] INFO: 41600 events read in total (2475ms).
[14:19:43.315] INFO: Test took 3709ms.
[14:19:43.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:44.075] INFO: Expecting 41600 events.
[14:19:46.963] INFO: 41600 events read in total (2362ms).
[14:19:46.964] INFO: Test took 3595ms.
[14:19:46.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:47.724] INFO: Expecting 41600 events.
[14:19:50.582] INFO: 41600 events read in total (2331ms).
[14:19:50.583] INFO: Test took 3563ms.
[14:19:50.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:51.342] INFO: Expecting 41600 events.
[14:19:54.580] INFO: 41600 events read in total (2711ms).
[14:19:54.581] INFO: Test took 3943ms.
[14:19:54.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:55.342] INFO: Expecting 41600 events.
[14:19:58.580] INFO: 41600 events read in total (2711ms).
[14:19:58.581] INFO: Test took 3945ms.
[14:19:58.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:59.340] INFO: Expecting 41600 events.
[14:20:02.598] INFO: 41600 events read in total (2731ms).
[14:20:02.599] INFO: Test took 3963ms.
[14:20:02.635] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:03.357] INFO: Expecting 41600 events.
[14:20:06.597] INFO: 41600 events read in total (2713ms).
[14:20:06.598] INFO: Test took 3944ms.
[14:20:06.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:07.356] INFO: Expecting 41600 events.
[14:20:10.612] INFO: 41600 events read in total (2729ms).
[14:20:10.613] INFO: Test took 3961ms.
[14:20:10.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:11.368] INFO: Expecting 41600 events.
[14:20:14.618] INFO: 41600 events read in total (2723ms).
[14:20:14.619] INFO: Test took 3953ms.
[14:20:14.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:15.373] INFO: Expecting 41600 events.
[14:20:18.485] INFO: 41600 events read in total (2585ms).
[14:20:18.486] INFO: Test took 3814ms.
[14:20:18.520] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:18.880] INFO: enter test to run
[14:20:26.247] INFO: test: HighRate no parameter change
[14:20:26.248] INFO: running: highrate
[14:20:26.249] INFO: ----------------------------------------------------------------------
[14:20:26.249] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:20:26.249] INFO: ----------------------------------------------------------------------
[14:20:26.860] INFO: Expecting 208000 events.
[14:20:38.770] INFO: 208000 events read in total (11383ms).
[14:20:38.773] INFO: Test took 12516ms.
[14:20:38.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:39.175] INFO: number of dead pixels (per ROC): 0 0 0 0 39 0 0 1 0 0 0 0 0 0 0 0
[14:20:39.176] INFO: number of red-efficiency pixels: 77 42 99 177 246 179 152 100 111 145 109 118 108 67 24 38
[14:20:39.176] INFO: number of X-ray hits detected: 67850 45640 70544 117009 116829 122653 119863 85911 78767 104590 100613 87123 90919 54315 24255 27933
[14:20:39.176] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:20:39.176] INFO: number of Vcal hits detected: 207920 207958 207901 207817 204941 207818 207845 207847 207889 207855 207877 207879 207891 207933 207976 207961
[14:20:39.176] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.5 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:20:39.176] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 98.5 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:20:39.176] INFO: X-ray hit rate [MHz/cm2]: 19.9 13.4 20.7 34.3 34.2 36.0 35.1 25.2 23.1 30.7 29.5 25.5 26.6 15.9 7.1 8.2
[14:20:39.176] INFO: PixTestHighRate::doXPixelAlive() done
[14:20:39.226] INFO: PixTest:: pg_setup set to default.
[14:20:39.236] INFO: enter test to run
[14:21:00.639] INFO: test: HighRate no parameter change
[14:21:00.639] INFO: running: highrate
[14:21:00.640] INFO: ----------------------------------------------------------------------
[14:21:00.640] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:00.640] INFO: ----------------------------------------------------------------------
[14:21:01.257] INFO: Expecting 208000 events.
[14:21:15.095] INFO: 208000 events read in total (13312ms).
[14:21:15.100] INFO: Test took 14451ms.
[14:21:15.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:15.732] INFO: number of dead pixels (per ROC): 0 0 0 0 37 0 0 1 0 0 0 0 0 0 0 0
[14:21:15.732] INFO: number of red-efficiency pixels: 262 135 266 593 705 684 486 356 285 476 342 361 356 199 67 81
[14:21:15.732] INFO: number of X-ray hits detected: 143337 95534 148027 244655 243692 257526 251951 181711 166765 219195 209336 182915 191329 113703 51760 58288
[14:21:15.732] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:21:15.732] INFO: number of Vcal hits detected: 207725 207858 207699 207340 201468 207218 207466 207567 207703 207485 207604 207615 207629 207780 207930 207918
[14:21:15.732] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 97.7 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:21:15.732] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 96.9 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:21:15.732] INFO: X-ray hit rate [MHz/cm2]: 42.0 28.0 43.4 71.7 71.4 75.5 73.8 53.3 48.9 64.2 61.4 53.6 56.1 33.3 15.2 17.1
[14:21:15.732] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:15.781] INFO: PixTest:: pg_setup set to default.
[14:21:15.792] INFO: enter test to run
[14:21:38.207] INFO: test: HighRate no parameter change
[14:21:38.207] INFO: running: highrate
[14:21:38.208] INFO: ----------------------------------------------------------------------
[14:21:38.208] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:38.208] INFO: ----------------------------------------------------------------------
[14:21:38.828] INFO: Expecting 208000 events.
[14:21:54.681] INFO: 208000 events read in total (15326ms).
[14:21:54.691] INFO: Test took 16472ms.
[14:21:55.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:55.545] INFO: number of dead pixels (per ROC): 0 0 0 0 10 0 0 1 0 0 0 0 0 0 0 0
[14:21:55.545] INFO: number of red-efficiency pixels: 571 321 652 1402 1499 1597 1150 766 634 1121 750 801 892 506 101 100
[14:21:55.545] INFO: number of X-ray hits detected: 216449 144868 223424 368760 367663 387753 379097 273805 252704 331242 316694 275511 287022 172260 77791 87805
[14:21:55.545] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:21:55.545] INFO: number of Vcal hits detected: 207323 207651 207138 206084 199068 205759 206551 206968 207266 206572 207093 207045 206954 207402 207895 207897
[14:21:55.545] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.2 95.9 99.0 99.4 99.6 99.7 99.4 99.6 99.6 99.5 99.7 100.0 100.0
[14:21:55.545] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.1 95.7 98.9 99.3 99.5 99.6 99.3 99.6 99.5 99.5 99.7 99.9 100.0
[14:21:55.545] INFO: X-ray hit rate [MHz/cm2]: 63.4 42.5 65.5 108.1 107.8 113.7 111.1 80.3 74.1 97.1 92.8 80.8 84.1 50.5 22.8 25.7
[14:21:55.545] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:55.592] INFO: PixTest:: pg_setup set to default.
[14:21:55.606] INFO: enter test to run
[14:22:02.575] INFO: test: exit no parameter change
[14:22:02.914] QUIET: Connection to board 33 closed.
[14:22:02.915] INFO: pXar: this is the end, my friend