[11:53:56.953] INFO: *** Welcome to pxar ***
[11:53:56.953] INFO: *** Today: 2016/05/06
[11:53:57.339] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:53:57.339] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C15.dat
[11:53:57.394] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:53:57.394] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[11:53:57.395] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[11:53:57.492] INFO: clk: 4
[11:53:57.492] INFO: ctr: 4
[11:53:57.492] INFO: sda: 19
[11:53:57.492] INFO: tin: 9
[11:53:57.492] INFO: level: 15
[11:53:57.492] INFO: triggerdelay: 0
[11:53:57.492] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:53:57.492] INFO: Log level: INFO
[11:53:57.509] QUIET: Connection to board DTB_WREKRL opened.
[11:53:57.513] 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:
------------------------------------------------------
[11:53:57.516] INFO: RPC call hashes of host and DTB match: 398089610
[11:53:59.047] INFO: DUT info:
[11:53:59.047] INFO: The DUT currently contains the following objects:
[11:53:59.047] INFO: 2 TBM Cores tbm08c (2 ON)
[11:53:59.047] INFO: TBM Core alpha (0): 7 registers set
[11:53:59.047] INFO: TBM Core beta (1): 7 registers set
[11:53:59.047] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:53:59.047] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.047] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.048] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:59.451] INFO: enter 'restricted' command line mode
[11:53:59.451] INFO: enter test to run
[11:54:23.222] INFO: test: PixelAlive no parameter change
[11:54:23.222] INFO: running: pixelalive
[11:54:23.240] INFO: ----------------------------------------------------------------------
[11:54:23.240] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:54:23.240] INFO: ----------------------------------------------------------------------
[11:54:23.561] INFO: Expecting 41600 events.
[11:54:27.899] INFO: 41600 events read in total (3619ms).
[11:54:28.064] INFO: Test took 4821ms.
[11:54:28.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:28.333] INFO: PixTestAlive::aliveTest() done
[11:54:28.334] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:54:28.367] INFO: enter test to run
[11:55:06.670] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:55:06.670] INFO: running: highrate
[11:55:06.670] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:55:06.886] INFO: ----------------------------------------------------------------------
[11:55:06.886] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:55:06.886] INFO: ----------------------------------------------------------------------
[11:55:06.886] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:55:06.887] INFO: edge/corner pixel THR is adjusted
[11:55:06.887] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:55:07.845] INFO: Collecting data for 5 seconds...
[11:55:12.864] INFO: Done with hot pixel readout
[11:55:25.414] INFO: PixTest:: pg_setup set to default.

[11:55:25.415] INFO: 15 hot pixels found in step 0
[11:55:26.408] INFO: Collecting data for 5 seconds...
[11:55:31.428] INFO: Done with hot pixel readout
[11:55:43.820] INFO: PixTest:: pg_setup set to default.


[11:55:43.821] INFO: 18 hot pixels found in step 1
[11:55:44.823] INFO: Collecting data for 5 seconds...
[11:55:49.842] INFO: Done with hot pixel readout
[11:56:02.344] INFO: PixTest:: pg_setup set to default.
[11:56:02.345] INFO: 12 hot pixels found in step 2
[11:56:03.341] INFO: Collecting data for 5 seconds...
[11:56:08.360] INFO: Done with hot pixel readout
[11:56:20.786] INFO: PixTest:: pg_setup set to default.

[11:56:20.787] INFO: 7 hot pixels found in step 3
[11:56:21.784] INFO: Collecting data for 5 seconds...
[11:56:26.803] INFO: Done with hot pixel readout
[11:56:39.336] INFO: PixTest:: pg_setup set to default.
[11:56:39.337] INFO: 16 hot pixels found in step 4
[11:56:40.333] INFO: Collecting data for 5 seconds...
[11:56:45.351] INFO: Done with hot pixel readout
[11:56:57.734] INFO: PixTest:: pg_setup set to default.
[11:56:57.735] INFO: 8 hot pixels found in step 5
[11:56:58.732] INFO: Collecting data for 5 seconds...
[11:57:03.749] INFO: Done with hot pixel readout
[11:57:16.031] INFO: PixTest:: pg_setup set to default.
[11:57:16.032] INFO: 10 hot pixels found in step 6
[11:57:17.030] INFO: Collecting data for 5 seconds...
[11:57:22.046] INFO: Done with hot pixel readout
[11:57:34.350] INFO: PixTest:: pg_setup set to default.

[11:57:34.350] INFO: 14 hot pixels found in step 7
[11:57:35.347] INFO: Collecting data for 5 seconds...
[11:57:40.364] INFO: Done with hot pixel readout
[11:57:52.662] INFO: PixTest:: pg_setup set to default.



[11:57:52.663] INFO: 16 hot pixels found in step 8
[11:57:53.660] INFO: Collecting data for 5 seconds...
[11:57:58.676] INFO: Done with hot pixel readout
[11:58:10.965] INFO: PixTest:: pg_setup set to default.
[11:58:10.965] INFO: 15 hot pixels found in step 9
[11:58:11.962] INFO: Collecting data for 5 seconds...
[11:58:16.979] INFO: Done with hot pixel readout
[11:58:29.289] INFO: PixTest:: pg_setup set to default.


[11:58:29.290] INFO: 15 hot pixels found in step 10
[11:58:30.286] INFO: Collecting data for 5 seconds...
[11:58:35.303] INFO: Done with hot pixel readout
[11:58:47.576] INFO: PixTest:: pg_setup set to default.
[11:58:47.577] INFO: 11 hot pixels found in step 11
[11:58:48.574] INFO: Collecting data for 5 seconds...
[11:58:53.591] INFO: Done with hot pixel readout
[11:59:05.889] INFO: PixTest:: pg_setup set to default.

[11:59:05.889] INFO: 10 hot pixels found in step 12
[11:59:06.885] INFO: Collecting data for 5 seconds...
[11:59:11.901] INFO: Done with hot pixel readout
[11:59:24.178] INFO: PixTest:: pg_setup set to default.

[11:59:24.179] INFO: 11 hot pixels found in step 13
[11:59:25.174] INFO: Collecting data for 5 seconds...
[11:59:30.192] INFO: Done with hot pixel readout
[11:59:42.459] INFO: PixTest:: pg_setup set to default.

[11:59:42.460] INFO: 8 hot pixels found in step 14
[11:59:42.500] INFO: 8 hot pixels could not be trimmed and have been masked.
[11:59:42.569] INFO: PixTest::trimHotPixels() done
[11:59:42.569] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[11:59:42.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[11:59:42.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[11:59:42.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[11:59:42.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[11:59:42.596] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[11:59:42.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[11:59:42.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[11:59:42.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[11:59:42.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[11:59:42.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[11:59:42.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[11:59:42.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[11:59:42.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[11:59:42.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[11:59:42.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[11:59:42.654] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[11:59:42.664] INFO: enter test to run
[12:00:22.435] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:00:22.435] INFO: running: highrate
[12:00:22.440] INFO: ----------------------------------------------------------------------
[12:00:22.440] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:00:22.440] INFO: ----------------------------------------------------------------------
[12:00:22.440] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:00:22.440] INFO: edge/corner pixel THR is adjusted
[12:00:22.440] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:00:23.399] INFO: Collecting data for 1 seconds...
[12:00:24.403] INFO: Done with hot pixel readout
[12:00:28.230] INFO: PixTest:: pg_setup set to default.
[12:00:28.231] INFO: 0 hot pixels found in step 0
[12:00:28.237] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:00:28.331] INFO: PixTest::trimHotPixels() done
[12:00:28.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[12:00:28.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[12:00:28.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[12:00:28.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[12:00:28.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[12:00:28.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[12:00:28.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[12:00:28.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[12:00:28.383] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[12:00:28.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[12:00:28.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[12:00:28.399] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[12:00:28.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[12:00:28.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[12:00:28.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[12:00:28.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[12:00:28.426] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-13_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[12:00:28.436] INFO: enter test to run
[12:00:50.403] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:00:50.403] INFO: running: xray
[12:00:50.427] INFO: ----------------------------------------------------------------------
[12:00:50.427] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:00:50.427] INFO: ----------------------------------------------------------------------
[12:00:51.423] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:01:02.725] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:01:32.244] INFO: Resuming triggers.
[12:01:43.547] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:02:13.123] INFO: Resuming triggers.
[12:02:24.430] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:02:53.769] INFO: Resuming triggers.
[12:03:05.076] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:03:34.493] INFO: Resuming triggers.
[12:03:45.799] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:04:15.221] INFO: Resuming triggers.
[12:04:26.529] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:04:55.813] INFO: Resuming triggers.
[12:05:07.117] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[12:05:36.495] INFO: Resuming triggers.
[12:05:47.798] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:06:17.501] INFO: Resuming triggers.
[12:06:27.402] INFO: data taking finished, elapsed time: 100 seconds.
[12:06:53.843] INFO: PixTest:: pg_setup set to default.
[12:06:53.846] INFO: PixTestXray::doPhRun() done
[12:06:54.027] INFO: enter test to run
[12:08:10.040] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:08:10.040] INFO: running: xray
[12:08:10.041] INFO: ----------------------------------------------------------------------
[12:08:10.041] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:08:10.041] INFO: ----------------------------------------------------------------------
[12:08:11.025] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:08:17.848] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:08:47.981] INFO: Resuming triggers.
[12:08:54.804] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:09:24.917] INFO: Resuming triggers.
[12:09:31.742] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:10:01.822] INFO: Resuming triggers.
[12:10:08.647] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[12:10:38.829] INFO: Resuming triggers.
[12:10:45.653] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:11:15.820] INFO: Resuming triggers.
[12:11:22.646] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:11:52.738] INFO: Resuming triggers.
[12:11:59.561] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:12:30.589] INFO: Resuming triggers.
[12:12:37.413] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:13:08.084] INFO: Resuming triggers.
[12:13:14.912] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:13:45.023] INFO: Resuming triggers.
[12:13:51.849] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:14:21.925] INFO: Resuming triggers.
[12:14:28.751] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:14:58.815] INFO: Resuming triggers.
[12:15:05.643] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:15:35.713] INFO: Resuming triggers.
[12:15:42.540] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:16:12.682] INFO: Resuming triggers.
[12:16:19.510] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:16:49.708] INFO: Resuming triggers.
[12:16:54.488] INFO: data taking finished, elapsed time: 100 seconds.
[12:17:16.455] INFO: PixTest:: pg_setup set to default.
[12:17:16.458] INFO: PixTestXray::doPhRun() done
[12:17:16.608] INFO: enter test to run
[12:17:52.860] INFO: test: HighRate no parameter change
[12:17:52.860] INFO: running: highrate
[12:17:52.861] INFO: ----------------------------------------------------------------------
[12:17:52.861] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:17:52.861] INFO: ----------------------------------------------------------------------
[12:17:52.001] INFO: Expecting 768 events.
[12:17:54.161] INFO: 768 events read in total (444ms).
[12:17:54.169] INFO: Test took 1302ms.
[12:17:54.964] INFO: Expecting 41600 events.
[12:17:58.053] INFO: 41600 events read in total (2563ms).
[12:17:58.054] INFO: Test took 3877ms.
[12:17:58.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:58.819] INFO: Expecting 41600 events.
[12:18:02.063] INFO: 41600 events read in total (2717ms).
[12:18:02.064] INFO: Test took 3963ms.
[12:18:02.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:02.825] INFO: Expecting 41600 events.
[12:18:06.108] INFO: 41600 events read in total (2756ms).
[12:18:06.109] INFO: Test took 3995ms.
[12:18:06.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:06.869] INFO: Expecting 41600 events.
[12:18:10.088] INFO: 41600 events read in total (2692ms).
[12:18:10.089] INFO: Test took 3930ms.
[12:18:10.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:10.846] INFO: Expecting 41600 events.
[12:18:14.075] INFO: 41600 events read in total (2702ms).
[12:18:14.076] INFO: Test took 3937ms.
[12:18:14.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:14.836] INFO: Expecting 41600 events.
[12:18:18.060] INFO: 41600 events read in total (2697ms).
[12:18:18.060] INFO: Test took 3936ms.
[12:18:18.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:18.821] INFO: Expecting 41600 events.
[12:18:22.108] INFO: 41600 events read in total (2760ms).
[12:18:22.109] INFO: Test took 4000ms.
[12:18:22.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:22.862] INFO: Expecting 41600 events.
[12:18:26.124] INFO: 41600 events read in total (2735ms).
[12:18:26.125] INFO: Test took 3967ms.
[12:18:26.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:26.863] INFO: Expecting 41600 events.
[12:18:30.117] INFO: 41600 events read in total (2728ms).
[12:18:30.118] INFO: Test took 3943ms.
[12:18:30.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:30.878] INFO: Expecting 41600 events.
[12:18:34.156] INFO: 41600 events read in total (2752ms).
[12:18:34.157] INFO: Test took 3990ms.
[12:18:34.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:34.910] INFO: Expecting 41600 events.
[12:18:38.143] INFO: 41600 events read in total (2706ms).
[12:18:38.144] INFO: Test took 3938ms.
[12:18:38.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:38.900] INFO: Expecting 41600 events.
[12:18:42.127] INFO: 41600 events read in total (2700ms).
[12:18:42.128] INFO: Test took 3936ms.
[12:18:42.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:42.884] INFO: Expecting 41600 events.
[12:18:46.131] INFO: 41600 events read in total (2720ms).
[12:18:46.132] INFO: Test took 3955ms.
[12:18:46.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:46.884] INFO: Expecting 41600 events.
[12:18:50.162] INFO: 41600 events read in total (2752ms).
[12:18:50.163] INFO: Test took 3982ms.
[12:18:50.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:50.915] INFO: Expecting 41600 events.
[12:18:54.219] INFO: 41600 events read in total (2777ms).
[12:18:54.220] INFO: Test took 4008ms.
[12:18:54.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:54.972] INFO: Expecting 41600 events.
[12:18:58.172] INFO: 41600 events read in total (2673ms).
[12:18:58.173] INFO: Test took 3905ms.
[12:18:58.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:58.932] INFO: Expecting 41600 events.
[12:19:02.156] INFO: 41600 events read in total (2698ms).
[12:19:02.157] INFO: Test took 3937ms.
[12:19:02.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:02.915] INFO: Expecting 41600 events.
[12:19:06.129] INFO: 41600 events read in total (2687ms).
[12:19:06.130] INFO: Test took 3924ms.
[12:19:06.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:06.890] INFO: Expecting 41600 events.
[12:19:10.088] INFO: 41600 events read in total (2672ms).
[12:19:10.089] INFO: Test took 3911ms.
[12:19:10.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:10.848] INFO: Expecting 41600 events.
[12:19:13.913] INFO: 41600 events read in total (2538ms).
[12:19:13.914] INFO: Test took 3776ms.
[12:19:13.944] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:14.314] INFO: enter test to run
[12:19:37.451] INFO: test: HighRate no parameter change
[12:19:37.451] INFO: running: highrate
[12:19:37.452] INFO: ----------------------------------------------------------------------
[12:19:37.452] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:19:37.452] INFO: ----------------------------------------------------------------------
[12:19:38.068] INFO: Expecting 208000 events.
[12:19:49.736] INFO: 208000 events read in total (11141ms).
[12:19:49.739] INFO: Test took 12279ms.
[12:19:49.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:50.114] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:19:50.114] INFO: number of red-efficiency pixels: 80 52 78 110 139 120 105 79 68 97 107 84 110 63 21 22
[12:19:50.114] INFO: number of X-ray hits detected: 58538 37874 58660 96032 99759 96214 101206 71319 69467 86243 84963 74609 77475 46706 20338 23330
[12:19:50.114] 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:19:50.114] INFO: number of Vcal hits detected: 207916 207947 207920 207888 207861 207879 207893 207919 207930 207903 207889 207916 207889 207936 207979 207978
[12:19:50.114] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0
[12:19:50.114] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0
[12:19:50.114] INFO: X-ray hit rate [MHz/cm2]: 17.2 11.1 17.2 28.1 29.2 28.2 29.7 20.9 20.4 25.3 24.9 21.9 22.7 13.7 6.0 6.8
[12:19:50.114] INFO: PixTestHighRate::doXPixelAlive() done
[12:19:50.159] INFO: PixTest:: pg_setup set to default.
[12:19:50.175] INFO: enter test to run
[12:20:14.242] INFO: test: HighRate no parameter change
[12:20:14.242] INFO: running: highrate
[12:20:14.244] INFO: ----------------------------------------------------------------------
[12:20:14.244] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:20:14.244] INFO: ----------------------------------------------------------------------
[12:20:14.862] INFO: Expecting 208000 events.
[12:20:28.372] INFO: 208000 events read in total (12984ms).
[12:20:28.377] INFO: Test took 14125ms.
[12:20:28.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:28.953] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:20:28.953] INFO: number of red-efficiency pixels: 249 100 274 385 500 359 403 336 261 376 370 253 330 168 47 67
[12:20:28.953] INFO: number of X-ray hits detected: 132870 86642 133143 216888 225788 218259 229444 161318 159234 197049 193594 170032 174989 106210 46924 53495
[12:20:28.953] 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:20:28.953] INFO: number of Vcal hits detected: 207731 207896 207700 207589 207465 207612 207578 207647 207725 207605 207608 207734 207650 207817 207953 207933
[12:20:28.953] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[12:20:28.953] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[12:20:28.953] INFO: X-ray hit rate [MHz/cm2]: 38.9 25.4 39.0 63.6 66.2 64.0 67.3 47.3 46.7 57.8 56.7 49.8 51.3 31.1 13.8 15.7
[12:20:28.953] INFO: PixTestHighRate::doXPixelAlive() done
[12:20:28.000] INFO: PixTest:: pg_setup set to default.
[12:20:29.018] INFO: enter test to run
[12:20:42.794] INFO: test: HighRate no parameter change
[12:20:42.794] INFO: running: highrate
[12:20:42.796] INFO: ----------------------------------------------------------------------
[12:20:42.796] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:20:42.796] INFO: ----------------------------------------------------------------------
[12:20:43.411] INFO: Expecting 208000 events.
[12:20:58.675] INFO: 208000 events read in total (14737ms).
[12:20:58.682] INFO: Test took 15878ms.
[12:20:59.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:59.437] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:20:59.437] INFO: number of red-efficiency pixels: 492 200 590 888 1189 840 918 694 596 907 836 476 707 415 83 100
[12:20:59.437] INFO: number of X-ray hits detected: 200326 128815 200261 324996 339765 326186 344410 242668 238764 296036 290231 253457 262320 159291 70413 80129
[12:20:59.437] 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:20:59.437] INFO: number of Vcal hits detected: 207428 207786 207277 206932 206486 206993 206892 207123 207329 206919 207023 207468 207165 207514 207916 207897
[12:20:59.437] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.3 99.6 99.5 99.6 99.7 99.5 99.6 99.8 99.6 99.8 100.0 100.0
[12:20:59.438] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.3 99.5 99.5 99.6 99.7 99.5 99.5 99.7 99.6 99.8 100.0 100.0
[12:20:59.438] INFO: X-ray hit rate [MHz/cm2]: 58.7 37.8 58.7 95.3 99.6 95.6 100.9 71.1 70.0 86.8 85.1 74.3 76.9 46.7 20.6 23.5
[12:20:59.438] INFO: PixTestHighRate::doXPixelAlive() done
[12:20:59.484] INFO: PixTest:: pg_setup set to default.
[12:20:59.501] INFO: enter test to run
[12:21:20.466] INFO: test: exit no parameter change
[12:21:20.857] QUIET: Connection to board 33 closed.
[12:21:20.858] INFO: pXar: this is the end, my friend