[18:53:27.960] INFO: *** Welcome to pxar ***
[18:53:27.961] INFO: *** Today: 2016/06/24
[18:53:32.177] INFO: *** Version: v1.9.0-814-g7497
[18:53:32.177] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//dacParameters35_C15.dat
[18:53:32.178] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:53:32.178] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[18:53:32.178] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[18:53:32.251] INFO: clk: 4
[18:53:32.251] INFO: ctr: 4
[18:53:32.251] INFO: sda: 19
[18:53:32.251] INFO: tin: 9
[18:53:32.251] INFO: level: 15
[18:53:32.251] INFO: triggerdelay: 0
[18:53:32.251] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:53:32.251] INFO: Log level: INFO
[18:53:32.265] QUIET: Connection to board DTB_WREKRL opened.
[18:53:32.268] 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:
------------------------------------------------------
[18:53:32.271] INFO: RPC call hashes of host and DTB match: 398089610
[18:53:33.796] INFO: DUT info:
[18:53:33.796] INFO: The DUT currently contains the following objects:
[18:53:33.796] INFO: 2 TBM Cores tbm08c (2 ON)
[18:53:33.796] INFO: TBM Core alpha (0): 7 registers set
[18:53:33.796] INFO: TBM Core beta (1): 7 registers set
[18:53:33.796] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:53:33.796] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:33.797] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:53:34.200] INFO: enter 'restricted' command line mode
[18:53:34.200] INFO: enter test to run
[18:53:39.202] INFO: test: PixelAlive no parameter change
[18:53:39.202] INFO: running: pixelalive
[18:53:39.211] INFO: ----------------------------------------------------------------------
[18:53:39.211] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:53:39.211] INFO: ----------------------------------------------------------------------
[18:53:39.534] INFO: Expecting 41600 events.
[18:53:43.878] INFO: 41600 events read in total (3625ms).
[18:53:44.048] INFO: Test took 4835ms.
[18:53:44.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:44.320] INFO: PixTestAlive::aliveTest() done
[18:53:44.320] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 2 0
[18:53:44.357] INFO: enter test to run
[18:54:20.746] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:54:20.746] INFO: running: highrate
[18:54:20.746] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:54:20.896] INFO: ----------------------------------------------------------------------
[18:54:20.896] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:54:20.896] INFO: ----------------------------------------------------------------------
[18:54:20.896] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:54:20.896] INFO: edge/corner pixel THR is adjusted
[18:54:20.896] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:54:21.855] INFO: Collecting data for 5 seconds...
[18:54:26.871] INFO: Done with hot pixel readout
[18:54:38.852] INFO: PixTest:: pg_setup set to default.
[18:54:38.853] INFO: 15 hot pixels found in step 0
[18:54:39.868] INFO: Collecting data for 5 seconds...
[18:54:44.885] INFO: Done with hot pixel readout
[18:54:56.951] INFO: PixTest:: pg_setup set to default.
[18:54:56.952] INFO: 22 hot pixels found in step 1
[18:54:57.946] INFO: Collecting data for 5 seconds...
[18:55:02.962] INFO: Done with hot pixel readout
[18:55:15.011] INFO: PixTest:: pg_setup set to default.

[18:55:15.012] INFO: 9 hot pixels found in step 2
[18:55:16.006] INFO: Collecting data for 5 seconds...
[18:55:21.023] INFO: Done with hot pixel readout
[18:55:33.056] INFO: PixTest:: pg_setup set to default.


[18:55:33.057] INFO: 7 hot pixels found in step 3
[18:55:34.050] INFO: Collecting data for 5 seconds...
[18:55:39.067] INFO: Done with hot pixel readout
[18:55:51.140] INFO: PixTest:: pg_setup set to default.
[18:55:51.141] INFO: 12 hot pixels found in step 4
[18:55:52.134] INFO: Collecting data for 5 seconds...
[18:55:57.152] INFO: Done with hot pixel readout
[18:56:09.250] INFO: PixTest:: pg_setup set to default.

[18:56:09.250] INFO: 8 hot pixels found in step 5
[18:56:10.244] INFO: Collecting data for 5 seconds...
[18:56:15.261] INFO: Done with hot pixel readout
[18:56:27.311] INFO: PixTest:: pg_setup set to default.
[18:56:27.312] INFO: 7 hot pixels found in step 6
[18:56:28.305] INFO: Collecting data for 5 seconds...
[18:56:33.322] INFO: Done with hot pixel readout
[18:56:45.456] INFO: PixTest:: pg_setup set to default.

[18:56:45.457] INFO: 10 hot pixels found in step 7
[18:56:46.450] INFO: Collecting data for 5 seconds...
[18:56:51.467] INFO: Done with hot pixel readout
[18:57:03.491] INFO: PixTest:: pg_setup set to default.

[18:57:03.492] INFO: 8 hot pixels found in step 8
[18:57:04.487] INFO: Collecting data for 5 seconds...
[18:57:09.505] INFO: Done with hot pixel readout
[18:57:21.479] INFO: PixTest:: pg_setup set to default.
[18:57:21.480] INFO: 11 hot pixels found in step 9
[18:57:22.474] INFO: Collecting data for 5 seconds...
[18:57:27.491] INFO: Done with hot pixel readout
[18:57:39.310] INFO: PixTest:: pg_setup set to default.
[18:57:39.311] INFO: 11 hot pixels found in step 10
[18:57:40.305] INFO: Collecting data for 5 seconds...
[18:57:45.322] INFO: Done with hot pixel readout
[18:57:57.313] INFO: PixTest:: pg_setup set to default.

[18:57:57.314] INFO: 9 hot pixels found in step 11
[18:57:58.311] INFO: Collecting data for 5 seconds...
[18:58:03.328] INFO: Done with hot pixel readout
[18:58:15.310] INFO: PixTest:: pg_setup set to default.

[18:58:15.311] INFO: 8 hot pixels found in step 12
[18:58:16.307] INFO: Collecting data for 5 seconds...
[18:58:21.322] INFO: Done with hot pixel readout
[18:58:33.326] INFO: PixTest:: pg_setup set to default.
[18:58:33.327] INFO: 12 hot pixels found in step 13
[18:58:34.323] INFO: Collecting data for 5 seconds...
[18:58:39.338] INFO: Done with hot pixel readout
[18:58:51.342] INFO: PixTest:: pg_setup set to default.
[18:58:51.343] INFO: 9 hot pixels found in step 14
[18:58:51.381] INFO: 9 hot pixels could not be trimmed and have been masked.
[18:58:51.384] INFO: PixTest::trimHotPixels() done
[18:58:51.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat
[18:58:51.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C1.dat
[18:58:51.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C2.dat
[18:58:51.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C3.dat
[18:58:51.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C4.dat
[18:58:51.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C5.dat
[18:58:51.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C6.dat
[18:58:51.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C7.dat
[18:58:51.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C8.dat
[18:58:51.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C9.dat
[18:58:51.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C10.dat
[18:58:51.474] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C11.dat
[18:58:51.479] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C12.dat
[18:58:51.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C13.dat
[18:58:51.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C14.dat
[18:58:51.495] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[18:58:51.500] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[18:58:51.518] INFO: enter test to run
[19:00:08.455] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[19:00:08.456] INFO: running: highrate
[19:00:08.460] INFO: ----------------------------------------------------------------------
[19:00:08.460] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[19:00:08.460] INFO: ----------------------------------------------------------------------
[19:00:08.460] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[19:00:08.460] INFO: edge/corner pixel THR is adjusted
[19:00:08.460] INFO: PixTestHighRate::trimHotPixels: step 0...
[19:00:09.417] INFO: Collecting data for 1 seconds...
[19:00:10.421] INFO: Done with hot pixel readout
[19:00:14.635] INFO: PixTest:: pg_setup set to default.
[19:00:14.635] INFO: 0 hot pixels found in step 0
[19:00:14.641] INFO: 0 hot pixels could not be trimmed and have been masked.
[19:00:14.713] INFO: PixTest::trimHotPixels() done
[19:00:14.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C0.dat
[19:00:14.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C1.dat
[19:00:14.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C2.dat
[19:00:14.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C3.dat
[19:00:14.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C4.dat
[19:00:14.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C5.dat
[19:00:14.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C6.dat
[19:00:14.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C7.dat
[19:00:14.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C8.dat
[19:00:14.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C9.dat
[19:00:14.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C10.dat
[19:00:14.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C11.dat
[19:00:14.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C12.dat
[19:00:14.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C13.dat
[19:00:14.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C14.dat
[19:00:14.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//trimParameters35_C15.dat
[19:00:14.807] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160623-1132_2016-06-23_11h32m_1466699572/000_FPIXTest_p17//defaultMaskFile.dat
[19:00:14.817] INFO: enter test to run
[19:00:43.159] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[19:00:43.159] INFO: running: xray
[19:00:43.160] INFO: ----------------------------------------------------------------------
[19:00:43.160] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:00:43.160] INFO: ----------------------------------------------------------------------
[19:00:44.123] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:00:55.540] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[19:01:25.609] INFO: Resuming triggers.
[19:01:37.019] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[19:02:07.460] INFO: Resuming triggers.
[19:02:18.873] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[19:02:49.498] INFO: Resuming triggers.
[19:03:00.910] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[19:03:30.462] INFO: Resuming triggers.
[19:03:41.873] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[19:04:11.403] INFO: Resuming triggers.
[19:04:22.816] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[19:04:52.342] INFO: Resuming triggers.
[19:05:03.753] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[19:05:33.252] INFO: Resuming triggers.
[19:05:44.666] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[19:06:14.239] INFO: Resuming triggers.
[19:06:23.275] INFO: data taking finished, elapsed time: 100 seconds.
[19:06:47.031] INFO: PixTest:: pg_setup set to default.
[19:06:47.034] INFO: PixTestXray::doPhRun() done
[19:06:47.171] INFO: enter test to run
[19:07:12.829] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[19:07:12.829] INFO: running: xray
[19:07:12.830] INFO: ----------------------------------------------------------------------
[19:07:12.830] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:07:12.830] INFO: ----------------------------------------------------------------------
[19:07:13.793] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:07:20.174] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[19:07:50.528] INFO: Resuming triggers.
[19:07:56.909] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[19:08:27.307] INFO: Resuming triggers.
[19:08:33.692] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[19:09:03.934] INFO: Resuming triggers.
[19:09:10.321] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[19:09:40.684] INFO: Resuming triggers.
[19:09:47.072] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[19:10:17.459] INFO: Resuming triggers.
[19:10:23.846] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[19:10:54.196] INFO: Resuming triggers.
[19:11:00.583] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[19:11:31.565] INFO: Resuming triggers.
[19:11:37.953] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[19:12:08.965] INFO: Resuming triggers.
[19:12:15.353] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[19:12:46.240] INFO: Resuming triggers.
[19:12:52.628] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[19:13:24.233] INFO: Resuming triggers.
[19:13:30.615] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[19:14:01.927] INFO: Resuming triggers.
[19:14:08.314] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[19:14:39.288] INFO: Resuming triggers.
[19:14:45.675] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[19:15:15.969] INFO: Resuming triggers.
[19:15:22.355] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[19:15:52.643] INFO: Resuming triggers.
[19:15:59.027] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[19:16:29.366] INFO: Resuming triggers.
[19:16:33.920] INFO: data taking finished, elapsed time: 100 seconds.
[19:16:55.744] INFO: PixTest:: pg_setup set to default.
[19:16:55.747] INFO: PixTestXray::doPhRun() done
[19:16:55.897] INFO: enter test to run
[19:17:28.328] INFO: test: HighRate no parameter change
[19:17:28.329] INFO: running: highrate
[19:17:28.330] INFO: ----------------------------------------------------------------------
[19:17:28.330] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[19:17:28.330] INFO: ----------------------------------------------------------------------
[19:17:28.481] INFO: Expecting 768 events.
[19:17:29.615] INFO: 768 events read in total (418ms).
[19:17:29.615] INFO: Test took 1269ms.
[19:17:30.418] INFO: Expecting 41600 events.
[19:17:33.551] INFO: 41600 events read in total (2606ms).
[19:17:33.552] INFO: Test took 3928ms.
[19:17:33.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:34.313] INFO: Expecting 41600 events.
[19:17:37.548] INFO: 41600 events read in total (2709ms).
[19:17:37.549] INFO: Test took 3943ms.
[19:17:37.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:38.304] INFO: Expecting 41600 events.
[19:17:41.557] INFO: 41600 events read in total (2726ms).
[19:17:41.558] INFO: Test took 3955ms.
[19:17:41.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:42.314] INFO: Expecting 41600 events.
[19:17:45.564] INFO: 41600 events read in total (2723ms).
[19:17:45.565] INFO: Test took 3953ms.
[19:17:45.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:46.319] INFO: Expecting 41600 events.
[19:17:49.587] INFO: 41600 events read in total (2741ms).
[19:17:49.588] INFO: Test took 3970ms.
[19:17:49.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:50.346] INFO: Expecting 41600 events.
[19:17:53.605] INFO: 41600 events read in total (2732ms).
[19:17:53.606] INFO: Test took 3963ms.
[19:17:53.641] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:54.364] INFO: Expecting 41600 events.
[19:17:57.625] INFO: 41600 events read in total (2734ms).
[19:17:57.626] INFO: Test took 3965ms.
[19:17:57.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:58.382] INFO: Expecting 41600 events.
[19:18:01.646] INFO: 41600 events read in total (2737ms).
[19:18:01.647] INFO: Test took 3966ms.
[19:18:01.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:02.404] INFO: Expecting 41600 events.
[19:18:05.678] INFO: 41600 events read in total (2747ms).
[19:18:05.679] INFO: Test took 3979ms.
[19:18:05.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:06.437] INFO: Expecting 41600 events.
[19:18:09.695] INFO: 41600 events read in total (2731ms).
[19:18:09.696] INFO: Test took 3961ms.
[19:18:09.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:10.452] INFO: Expecting 41600 events.
[19:18:13.716] INFO: 41600 events read in total (2738ms).
[19:18:13.717] INFO: Test took 3966ms.
[19:18:13.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:14.473] INFO: Expecting 41600 events.
[19:18:17.737] INFO: 41600 events read in total (2737ms).
[19:18:17.738] INFO: Test took 3965ms.
[19:18:17.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:18.493] INFO: Expecting 41600 events.
[19:18:21.743] INFO: 41600 events read in total (2723ms).
[19:18:21.744] INFO: Test took 3951ms.
[19:18:21.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:22.499] INFO: Expecting 41600 events.
[19:18:25.765] INFO: 41600 events read in total (2739ms).
[19:18:25.766] INFO: Test took 3967ms.
[19:18:25.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:26.522] INFO: Expecting 41600 events.
[19:18:29.787] INFO: 41600 events read in total (2738ms).
[19:18:29.788] INFO: Test took 3968ms.
[19:18:29.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:30.547] INFO: Expecting 41600 events.
[19:18:33.817] INFO: 41600 events read in total (2744ms).
[19:18:33.818] INFO: Test took 3975ms.
[19:18:33.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:34.573] INFO: Expecting 41600 events.
[19:18:37.826] INFO: 41600 events read in total (2726ms).
[19:18:37.827] INFO: Test took 3954ms.
[19:18:37.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:38.586] INFO: Expecting 41600 events.
[19:18:41.867] INFO: 41600 events read in total (2755ms).
[19:18:41.868] INFO: Test took 3986ms.
[19:18:41.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:42.622] INFO: Expecting 41600 events.
[19:18:45.883] INFO: 41600 events read in total (2734ms).
[19:18:45.885] INFO: Test took 3963ms.
[19:18:45.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:46.632] INFO: Expecting 41600 events.
[19:18:49.749] INFO: 41600 events read in total (2590ms).
[19:18:49.750] INFO: Test took 3802ms.
[19:18:49.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:50.139] INFO: enter test to run
[19:19:03.336] INFO: test: HighRate no parameter change
[19:19:03.336] INFO: running: highrate
[19:19:03.337] INFO: ----------------------------------------------------------------------
[19:19:03.337] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:19:03.337] INFO: ----------------------------------------------------------------------
[19:19:03.955] INFO: Expecting 208000 events.
[19:19:15.931] INFO: 208000 events read in total (11449ms).
[19:19:15.935] INFO: Test took 12588ms.
[19:19:16.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:16.344] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 2 0
[19:19:16.344] INFO: number of red-efficiency pixels: 75 43 87 118 187 147 147 101 115 160 158 127 108 60 39 17
[19:19:16.344] INFO: number of X-ray hits detected: 63795 42399 68729 107602 112916 121731 118529 84274 82148 114953 115539 91752 96420 59281 22950 24282
[19:19:16.344] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:19:16.344] INFO: number of Vcal hits detected: 207924 207953 207912 207881 207811 207846 207846 207896 207884 207834 207837 207870 207890 207890 207863 207983
[19:19:16.344] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[19:19:16.344] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0
[19:19:16.344] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.4 20.1 31.5 33.1 35.7 34.7 24.7 24.1 33.7 33.9 26.9 28.3 17.4 6.7 7.1
[19:19:16.344] INFO: PixTestHighRate::doXPixelAlive() done
[19:19:16.389] INFO: PixTest:: pg_setup set to default.
[19:19:16.399] INFO: enter test to run
[19:19:36.912] INFO: test: HighRate no parameter change
[19:19:36.912] INFO: running: highrate
[19:19:36.913] INFO: ----------------------------------------------------------------------
[19:19:36.913] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:19:36.913] INFO: ----------------------------------------------------------------------
[19:19:37.529] INFO: Expecting 208000 events.
[19:19:51.311] INFO: 208000 events read in total (13255ms).
[19:19:51.316] INFO: Test took 14393ms.
[19:19:51.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:51.931] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 2 0
[19:19:51.931] INFO: number of red-efficiency pixels: 215 113 250 519 516 602 448 250 214 553 572 330 301 223 53 68
[19:19:51.931] INFO: number of X-ray hits detected: 131459 86242 140575 219511 231440 248692 241709 173751 169240 235259 237134 188617 196823 121100 46495 50470
[19:19:51.931] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:19:51.931] INFO: number of Vcal hits detected: 207763 207877 207724 207430 207435 207305 207515 207728 207773 207389 207374 207645 207672 207716 207847 207932
[19:19:51.931] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.9 99.9 99.7 99.7 99.9 99.9 99.9 100.0 100.0
[19:19:51.931] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.8 99.9 99.9 99.7 99.7 99.8 99.8 99.9 99.9 100.0
[19:19:51.931] INFO: X-ray hit rate [MHz/cm2]: 38.5 25.3 41.2 64.3 67.8 72.9 70.8 50.9 49.6 69.0 69.5 55.3 57.7 35.5 13.6 14.8
[19:19:51.931] INFO: PixTestHighRate::doXPixelAlive() done
[19:19:51.977] INFO: PixTest:: pg_setup set to default.
[19:19:51.991] INFO: enter test to run
[19:20:10.079] INFO: test: HighRate no parameter change
[19:20:10.079] INFO: running: highrate
[19:20:10.080] INFO: ----------------------------------------------------------------------
[19:20:10.081] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:20:10.081] INFO: ----------------------------------------------------------------------
[19:20:10.698] INFO: Expecting 208000 events.
[19:20:26.556] INFO: 208000 events read in total (15331ms).
[19:20:26.563] INFO: Test took 16473ms.
[19:20:27.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:20:27.390] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 2 0
[19:20:27.390] INFO: number of red-efficiency pixels: 482 206 568 1144 1285 1444 1061 604 544 1365 1386 758 687 468 88 94
[19:20:27.391] INFO: number of X-ray hits detected: 200208 131865 214754 335731 352898 378731 370556 265670 259027 359532 362384 287806 300856 186432 71603 77708
[19:20:27.391] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:20:27.391] INFO: number of Vcal hits detected: 207433 207752 207281 206573 206366 205972 206642 207269 207372 206141 206098 207070 207197 207385 207804 207904
[19:20:27.391] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.3 99.1 99.4 99.7 99.7 99.2 99.2 99.6 99.6 99.8 100.0 100.0
[19:20:27.391] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.3 99.2 99.0 99.3 99.6 99.7 99.1 99.1 99.6 99.6 99.7 99.9 100.0
[19:20:27.391] INFO: X-ray hit rate [MHz/cm2]: 58.7 38.7 62.9 98.4 103.4 111.0 108.6 77.9 75.9 105.4 106.2 84.4 88.2 54.6 21.0 22.8
[19:20:27.391] INFO: PixTestHighRate::doXPixelAlive() done
[19:20:27.441] INFO: PixTest:: pg_setup set to default.
[19:20:27.454] INFO: enter test to run
[19:20:30.855] INFO: test: exit no parameter change
[19:20:31.165] QUIET: Connection to board 33 closed.
[19:20:31.167] INFO: pXar: this is the end, my friend