[17:14:42.870] INFO: *** Welcome to pxar ***
[17:14:42.870] INFO: *** Today: 2016/05/09
[17:14:43.290] INFO: *** Version: v1.9.0-796-gef167-dirty
[17:14:43.290] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//dacParameters35_C15.dat
[17:14:43.344] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:14:43.345] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[17:14:43.345] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[17:14:43.446] INFO: clk: 4
[17:14:43.446] INFO: ctr: 4
[17:14:43.446] INFO: sda: 19
[17:14:43.447] INFO: tin: 9
[17:14:43.447] INFO: level: 15
[17:14:43.447] INFO: triggerdelay: 0
[17:14:43.447] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[17:14:43.447] INFO: Log level: INFO
[17:14:43.462] QUIET: Connection to board DTB_WREKRL opened.
[17:14:43.466] 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:
------------------------------------------------------
[17:14:43.469] INFO: RPC call hashes of host and DTB match: 398089610
[17:14:45.020] INFO: DUT info:
[17:14:45.020] INFO: The DUT currently contains the following objects:
[17:14:45.020] INFO: 2 TBM Cores tbm08c (2 ON)
[17:14:45.034] INFO: TBM Core alpha (0): 7 registers set
[17:14:45.034] INFO: TBM Core beta (1): 7 registers set
[17:14:45.034] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:14:45.035] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.035] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:14:45.481] INFO: enter 'restricted' command line mode
[17:14:45.481] INFO: enter test to run
[17:14:52.447] INFO: test: PixelAlive no parameter change
[17:14:52.447] INFO: running: pixelalive
[17:14:52.481] INFO: ----------------------------------------------------------------------
[17:14:52.481] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:14:52.481] INFO: ----------------------------------------------------------------------
[17:14:52.797] INFO: Expecting 41600 events.
[17:14:57.144] INFO: 41600 events read in total (3629ms).
[17:14:57.308] INFO: Test took 4825ms.
[17:14:57.323] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:57.618] INFO: PixTestAlive::aliveTest() done
[17:14:57.618] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:14:57.654] INFO: enter test to run
[17:17:25.662] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:17:25.662] INFO: running: highrate
[17:17:25.662] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:17:25.931] INFO: ----------------------------------------------------------------------
[17:17:25.931] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:17:25.931] INFO: ----------------------------------------------------------------------
[17:17:25.931] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:17:25.931] INFO: edge/corner pixel THR is adjusted
[17:17:25.931] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:17:26.914] INFO: Collecting data for 5 seconds...
[17:17:31.931] INFO: Done with hot pixel readout
[17:17:43.896] INFO: PixTest:: pg_setup set to default.
[17:17:43.897] INFO: 21 hot pixels found in step 0
[17:17:44.889] INFO: Collecting data for 5 seconds...
[17:17:49.906] INFO: Done with hot pixel readout
[17:18:01.841] INFO: PixTest:: pg_setup set to default.
[17:18:01.841] INFO: 21 hot pixels found in step 1
[17:18:02.838] INFO: Collecting data for 5 seconds...
[17:18:07.855] INFO: Done with hot pixel readout
[17:18:19.793] INFO: PixTest:: pg_setup set to default.
[17:18:19.794] INFO: 21 hot pixels found in step 2
[17:18:20.787] INFO: Collecting data for 5 seconds...
[17:18:25.804] INFO: Done with hot pixel readout
[17:18:37.741] INFO: PixTest:: pg_setup set to default.

[17:18:37.741] INFO: 19 hot pixels found in step 3
[17:18:38.735] INFO: Collecting data for 5 seconds...
[17:18:43.751] INFO: Done with hot pixel readout
[17:18:55.686] INFO: PixTest:: pg_setup set to default.
[17:18:55.687] INFO: 15 hot pixels found in step 4
[17:18:56.680] INFO: Collecting data for 5 seconds...
[17:19:01.696] INFO: Done with hot pixel readout
[17:19:13.628] INFO: PixTest:: pg_setup set to default.

[17:19:13.629] INFO: 18 hot pixels found in step 5
[17:19:14.624] INFO: Collecting data for 5 seconds...
[17:19:19.641] INFO: Done with hot pixel readout
[17:19:31.555] INFO: PixTest:: pg_setup set to default.




[17:19:31.556] INFO: 19 hot pixels found in step 6
[17:19:32.549] INFO: Collecting data for 5 seconds...
[17:19:37.565] INFO: Done with hot pixel readout
[17:19:49.468] INFO: PixTest:: pg_setup set to default.

[17:19:49.469] INFO: 12 hot pixels found in step 7
[17:19:50.462] INFO: Collecting data for 5 seconds...
[17:19:55.478] INFO: Done with hot pixel readout
[17:20:07.359] INFO: PixTest:: pg_setup set to default.

[17:20:07.360] INFO: 7 hot pixels found in step 8
[17:20:08.353] INFO: Collecting data for 5 seconds...
[17:20:13.369] INFO: Done with hot pixel readout
[17:20:25.300] INFO: PixTest:: pg_setup set to default.



[17:20:25.301] INFO: 6 hot pixels found in step 9
[17:20:26.295] INFO: Collecting data for 5 seconds...
[17:20:31.312] INFO: Done with hot pixel readout
[17:20:43.229] INFO: PixTest:: pg_setup set to default.



[17:20:43.230] INFO: 4 hot pixels found in step 10
[17:20:44.224] INFO: Collecting data for 5 seconds...
[17:20:49.240] INFO: Done with hot pixel readout
[17:21:01.166] INFO: PixTest:: pg_setup set to default.

[17:21:01.167] INFO: 3 hot pixels found in step 11
[17:21:02.160] INFO: Collecting data for 5 seconds...
[17:21:07.177] INFO: Done with hot pixel readout
[17:21:19.093] INFO: PixTest:: pg_setup set to default.

[17:21:19.094] INFO: 3 hot pixels found in step 12
[17:21:20.088] INFO: Collecting data for 5 seconds...
[17:21:25.106] INFO: Done with hot pixel readout
[17:21:37.050] INFO: PixTest:: pg_setup set to default.


[17:21:37.051] INFO: 6 hot pixels found in step 13
[17:21:38.045] INFO: Collecting data for 5 seconds...
[17:21:43.061] INFO: Done with hot pixel readout
[17:21:55.022] INFO: PixTest:: pg_setup set to default.

[17:21:55.023] INFO: 6 hot pixels found in step 14
[17:21:55.059] INFO: 6 hot pixels could not be trimmed and have been masked.
[17:21:55.063] INFO: PixTest::trimHotPixels() done
[17:21:55.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat
[17:21:55.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C1.dat
[17:21:55.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C2.dat
[17:21:55.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C3.dat
[17:21:55.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C4.dat
[17:21:55.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C5.dat
[17:21:55.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C6.dat
[17:21:55.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C7.dat
[17:21:55.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C8.dat
[17:21:55.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C9.dat
[17:21:55.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C10.dat
[17:21:55.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C11.dat
[17:21:55.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C12.dat
[17:21:55.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C13.dat
[17:21:55.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C14.dat
[17:21:55.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[17:21:55.151] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[17:21:55.161] INFO: enter test to run
[17:22:20.804] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:22:20.804] INFO: running: highrate
[17:22:20.808] INFO: ----------------------------------------------------------------------
[17:22:20.808] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:22:20.808] INFO: ----------------------------------------------------------------------
[17:22:20.808] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:22:20.808] INFO: edge/corner pixel THR is adjusted
[17:22:20.808] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:22:21.766] INFO: Collecting data for 1 seconds...
[17:22:22.769] INFO: Done with hot pixel readout
[17:22:26.923] INFO: PixTest:: pg_setup set to default.
[17:22:26.924] INFO: 0 hot pixels found in step 0
[17:22:26.929] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:22:27.014] INFO: PixTest::trimHotPixels() done
[17:22:27.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat
[17:22:27.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C1.dat
[17:22:27.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C2.dat
[17:22:27.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C3.dat
[17:22:27.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C4.dat
[17:22:27.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C5.dat
[17:22:27.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C6.dat
[17:22:27.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C7.dat
[17:22:27.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C8.dat
[17:22:27.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C9.dat
[17:22:27.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C10.dat
[17:22:27.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C11.dat
[17:22:27.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C12.dat
[17:22:27.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C13.dat
[17:22:27.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C14.dat
[17:22:27.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[17:22:27.105] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-05_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[17:22:27.115] INFO: enter test to run
[17:22:46.931] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:22:46.931] INFO: running: xray
[17:22:46.933] INFO: ----------------------------------------------------------------------
[17:22:46.933] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:22:46.933] INFO: ----------------------------------------------------------------------
[17:22:47.895] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:22:59.394] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:23:28.679] INFO: Resuming triggers.
[17:23:40.179] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[17:24:09.585] INFO: Resuming triggers.
[17:24:21.088] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:24:50.334] INFO: Resuming triggers.
[17:25:01.840] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[17:25:31.331] INFO: Resuming triggers.
[17:25:42.837] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[17:26:12.382] INFO: Resuming triggers.
[17:26:23.886] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[17:26:53.469] INFO: Resuming triggers.
[17:27:04.976] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[17:27:35.204] INFO: Resuming triggers.
[17:27:46.708] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[17:28:15.957] INFO: Resuming triggers.
[17:28:24.274] INFO: data taking finished, elapsed time: 100 seconds.
[17:28:45.704] INFO: PixTest:: pg_setup set to default.
[17:28:45.707] INFO: PixTestXray::doPhRun() done
[17:28:45.880] INFO: enter test to run
[17:29:07.729] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:29:07.729] INFO: running: xray
[17:29:07.730] INFO: ----------------------------------------------------------------------
[17:29:07.730] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:29:07.730] INFO: ----------------------------------------------------------------------
[17:29:08.693] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:29:15.024] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:29:45.127] INFO: Resuming triggers.
[17:29:51.459] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[17:30:21.393] INFO: Resuming triggers.
[17:30:27.723] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[17:30:57.696] INFO: Resuming triggers.
[17:31:04.031] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[17:31:34.052] INFO: Resuming triggers.
[17:31:40.387] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[17:32:10.504] INFO: Resuming triggers.
[17:32:16.839] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[17:32:46.887] INFO: Resuming triggers.
[17:32:53.218] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[17:33:23.293] INFO: Resuming triggers.
[17:33:29.621] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[17:33:59.707] INFO: Resuming triggers.
[17:34:06.037] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[17:34:36.117] INFO: Resuming triggers.
[17:34:42.448] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[17:35:12.560] INFO: Resuming triggers.
[17:35:18.890] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:35:48.964] INFO: Resuming triggers.
[17:35:55.297] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[17:36:26.307] INFO: Resuming triggers.
[17:36:32.642] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[17:37:03.037] INFO: Resuming triggers.
[17:37:09.367] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[17:37:40.322] INFO: Resuming triggers.
[17:37:46.655] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[17:38:17.763] INFO: Resuming triggers.
[17:38:23.117] INFO: data taking finished, elapsed time: 100 seconds.
[17:38:49.320] INFO: PixTest:: pg_setup set to default.
[17:38:49.323] INFO: PixTestXray::doPhRun() done
[17:38:49.471] INFO: enter test to run
[17:39:47.380] INFO: test: HighRate no parameter change
[17:39:47.380] INFO: running: highrate
[17:39:47.381] INFO: ----------------------------------------------------------------------
[17:39:47.381] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:39:47.381] INFO: ----------------------------------------------------------------------
[17:39:47.521] INFO: Expecting 768 events.
[17:39:48.655] INFO: 768 events read in total (418ms).
[17:39:48.655] INFO: Test took 1268ms.
[17:39:49.458] INFO: Expecting 41600 events.
[17:39:52.607] INFO: 41600 events read in total (2622ms).
[17:39:52.608] INFO: Test took 3944ms.
[17:39:52.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:53.369] INFO: Expecting 41600 events.
[17:39:56.593] INFO: 41600 events read in total (2697ms).
[17:39:56.594] INFO: Test took 3934ms.
[17:39:56.628] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:57.352] INFO: Expecting 41600 events.
[17:40:00.586] INFO: 41600 events read in total (2707ms).
[17:40:00.587] INFO: Test took 3941ms.
[17:40:00.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:01.342] INFO: Expecting 41600 events.
[17:40:04.594] INFO: 41600 events read in total (2726ms).
[17:40:04.595] INFO: Test took 3956ms.
[17:40:04.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:05.348] INFO: Expecting 41600 events.
[17:40:08.594] INFO: 41600 events read in total (2719ms).
[17:40:08.595] INFO: Test took 3946ms.
[17:40:08.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:09.354] INFO: Expecting 41600 events.
[17:40:12.590] INFO: 41600 events read in total (2709ms).
[17:40:12.591] INFO: Test took 3943ms.
[17:40:12.625] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:13.350] INFO: Expecting 41600 events.
[17:40:16.607] INFO: 41600 events read in total (2730ms).
[17:40:16.608] INFO: Test took 3965ms.
[17:40:16.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:17.364] INFO: Expecting 41600 events.
[17:40:20.630] INFO: 41600 events read in total (2739ms).
[17:40:20.630] INFO: Test took 3970ms.
[17:40:20.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:21.389] INFO: Expecting 41600 events.
[17:40:24.634] INFO: 41600 events read in total (2718ms).
[17:40:24.635] INFO: Test took 3953ms.
[17:40:24.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:25.389] INFO: Expecting 41600 events.
[17:40:28.643] INFO: 41600 events read in total (2727ms).
[17:40:28.644] INFO: Test took 3956ms.
[17:40:28.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:29.401] INFO: Expecting 41600 events.
[17:40:32.655] INFO: 41600 events read in total (2727ms).
[17:40:32.656] INFO: Test took 3960ms.
[17:40:32.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:33.415] INFO: Expecting 41600 events.
[17:40:36.663] INFO: 41600 events read in total (2721ms).
[17:40:36.664] INFO: Test took 3954ms.
[17:40:36.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:37.423] INFO: Expecting 41600 events.
[17:40:40.666] INFO: 41600 events read in total (2716ms).
[17:40:40.667] INFO: Test took 3949ms.
[17:40:40.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:41.422] INFO: Expecting 41600 events.
[17:40:44.686] INFO: 41600 events read in total (2737ms).
[17:40:44.687] INFO: Test took 3966ms.
[17:40:44.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:45.441] INFO: Expecting 41600 events.
[17:40:48.695] INFO: 41600 events read in total (2727ms).
[17:40:48.696] INFO: Test took 3956ms.
[17:40:48.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:49.451] INFO: Expecting 41600 events.
[17:40:52.695] INFO: 41600 events read in total (2717ms).
[17:40:52.696] INFO: Test took 3946ms.
[17:40:52.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:53.455] INFO: Expecting 41600 events.
[17:40:56.710] INFO: 41600 events read in total (2728ms).
[17:40:56.711] INFO: Test took 3962ms.
[17:40:56.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:57.466] INFO: Expecting 41600 events.
[17:41:00.706] INFO: 41600 events read in total (2713ms).
[17:41:00.707] INFO: Test took 3942ms.
[17:41:00.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:01.462] INFO: Expecting 41600 events.
[17:41:04.681] INFO: 41600 events read in total (2692ms).
[17:41:04.682] INFO: Test took 3923ms.
[17:41:04.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:05.442] INFO: Expecting 41600 events.
[17:41:08.516] INFO: 41600 events read in total (2547ms).
[17:41:08.517] INFO: Test took 3781ms.
[17:41:08.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:08.914] INFO: enter test to run
[17:41:28.379] INFO: test: HighRate no parameter change
[17:41:28.379] INFO: running: highrate
[17:41:28.380] INFO: ----------------------------------------------------------------------
[17:41:28.380] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:41:28.380] INFO: ----------------------------------------------------------------------
[17:41:28.997] INFO: Expecting 208000 events.
[17:41:40.932] INFO: 208000 events read in total (11408ms).
[17:41:40.935] INFO: Test took 12546ms.
[17:41:41.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:41.336] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:41:41.336] INFO: number of red-efficiency pixels: 75 48 71 126 161 152 124 105 99 119 133 93 113 52 22 34
[17:41:41.336] INFO: number of X-ray hits detected: 65808 43299 66890 104958 117845 120062 114556 85262 77799 103405 105629 90048 84501 53251 23939 29470
[17:41:41.336] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:41:41.336] INFO: number of Vcal hits detected: 207924 207952 207928 207873 207834 207843 207871 207892 207898 207863 207863 207904 207883 207948 207978 207964
[17:41:41.336] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[17:41:41.336] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[17:41:41.336] INFO: X-ray hit rate [MHz/cm2]: 19.3 12.7 19.6 30.8 34.5 35.2 33.6 25.0 22.8 30.3 31.0 26.4 24.8 15.6 7.0 8.6
[17:41:41.336] INFO: PixTestHighRate::doXPixelAlive() done
[17:41:41.383] INFO: PixTest:: pg_setup set to default.
[17:41:41.394] INFO: enter test to run
[17:42:14.659] INFO: test: HighRate no parameter change
[17:42:14.659] INFO: running: highrate
[17:42:14.660] INFO: ----------------------------------------------------------------------
[17:42:14.660] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:42:14.660] INFO: ----------------------------------------------------------------------
[17:42:15.278] INFO: Expecting 208000 events.
[17:42:29.116] INFO: 208000 events read in total (13311ms).
[17:42:29.122] INFO: Test took 14454ms.
[17:42:29.434] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:42:29.739] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:42:29.739] INFO: number of red-efficiency pixels: 173 114 243 381 562 542 564 292 260 394 519 265 352 184 58 77
[17:42:29.739] INFO: number of X-ray hits detected: 138240 91786 142963 220290 250791 255321 243174 178579 165258 218001 222455 190306 179200 112918 50708 62642
[17:42:29.740] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:42:29.740] INFO: number of Vcal hits detected: 207815 207880 207735 207590 207398 207405 207384 207689 207722 207548 207434 207721 207630 207806 207942 207922
[17:42:29.740] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.7 99.9 99.8 99.9 100.0 100.0
[17:42:29.740] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.7 99.9 99.8 99.9 100.0 100.0
[17:42:29.740] INFO: X-ray hit rate [MHz/cm2]: 40.5 26.9 41.9 64.6 73.5 74.8 71.3 52.3 48.4 63.9 65.2 55.8 52.5 33.1 14.9 18.4
[17:42:29.740] INFO: PixTestHighRate::doXPixelAlive() done
[17:42:29.788] INFO: PixTest:: pg_setup set to default.
[17:42:29.802] INFO: enter test to run
[17:42:48.827] INFO: test: HighRate no parameter change
[17:42:48.827] INFO: running: highrate
[17:42:48.828] INFO: ----------------------------------------------------------------------
[17:42:48.828] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:42:48.828] INFO: ----------------------------------------------------------------------
[17:42:49.444] INFO: Expecting 208000 events.
[17:43:05.407] INFO: 208000 events read in total (15436ms).
[17:43:05.415] INFO: Test took 16579ms.
[17:43:05.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:43:06.274] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:43:06.274] INFO: number of red-efficiency pixels: 427 218 555 906 1470 1332 1387 680 560 877 1207 642 752 352 87 129
[17:43:06.274] INFO: number of X-ray hits detected: 213840 142359 221445 340128 387005 392250 372812 276515 254963 338236 344366 293702 277023 174410 78439 96721
[17:43:06.274] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:43:06.275] INFO: number of Vcal hits detected: 207524 207761 207311 206894 205992 206219 206101 207198 207349 206918 206525 207296 207129 207600 207907 207867
[17:43:06.275] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.1 99.2 99.2 99.6 99.7 99.5 99.3 99.7 99.6 99.8 100.0 99.9
[17:43:06.275] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.0 99.1 99.1 99.6 99.7 99.5 99.3 99.7 99.6 99.8 100.0 99.9
[17:43:06.275] INFO: X-ray hit rate [MHz/cm2]: 62.7 41.7 64.9 99.7 113.4 115.0 109.3 81.0 74.7 99.1 100.9 86.1 81.2 51.1 23.0 28.3
[17:43:06.275] INFO: PixTestHighRate::doXPixelAlive() done
[17:43:06.326] INFO: PixTest:: pg_setup set to default.
[17:43:06.342] INFO: enter test to run
[17:43:26.082] INFO: test: exit no parameter change
[17:43:26.442] QUIET: Connection to board 33 closed.
[17:43:26.444] INFO: pXar: this is the end, my friend