[16:07:57.213] INFO: *** Welcome to pxar ***
[16:07:57.213] INFO: *** Today: 2016/06/24
[16:07:57.234] INFO: *** Version: v1.9.0-814-g7497
[16:07:57.235] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C15.dat
[16:07:57.265] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:07:57.265] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[16:07:57.267] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[16:07:57.413] INFO: clk: 4
[16:07:57.413] INFO: ctr: 4
[16:07:57.413] INFO: sda: 19
[16:07:57.414] INFO: tin: 9
[16:07:57.414] INFO: level: 15
[16:07:57.414] INFO: triggerdelay: 0
[16:07:57.414] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:07:57.414] INFO: Log level: INFO
[16:07:57.432] QUIET: Connection to board DTB_WREKRL opened.
[16:07:57.435] 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:
------------------------------------------------------
[16:07:57.438] INFO: RPC call hashes of host and DTB match: 398089610
[16:07:58.968] INFO: DUT info:
[16:07:58.968] INFO: The DUT currently contains the following objects:
[16:07:58.968] INFO: 2 TBM Cores tbm08c (2 ON)
[16:07:58.968] INFO: TBM Core alpha (0): 7 registers set
[16:07:58.968] INFO: TBM Core beta (1): 7 registers set
[16:07:58.968] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:07:58.968] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.968] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.968] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.968] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:58.969] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:07:59.372] INFO: enter 'restricted' command line mode
[16:07:59.372] INFO: enter test to run
[16:08:04.453] INFO: test: PixelAlive no parameter change
[16:08:04.453] INFO: running: pixelalive
[16:08:04.462] INFO: ----------------------------------------------------------------------
[16:08:04.462] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:08:04.462] INFO: ----------------------------------------------------------------------
[16:08:04.781] INFO: Expecting 41600 events.
[16:08:09.110] INFO: 41600 events read in total (3610ms).
[16:08:09.278] INFO: Test took 4814ms.
[16:08:09.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:09.553] INFO: PixTestAlive::aliveTest() done
[16:08:09.553] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:08:09.585] INFO: enter test to run
[16:08:39.821] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:08:39.821] INFO: running: highrate
[16:08:39.821] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:08:40.042] INFO: ----------------------------------------------------------------------
[16:08:40.042] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:08:40.042] INFO: ----------------------------------------------------------------------
[16:08:40.042] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:08:40.042] INFO: edge/corner pixel THR is adjusted
[16:08:40.042] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:08:40.001] INFO: Collecting data for 5 seconds...
[16:08:46.018] INFO: Done with hot pixel readout
[16:08:57.572] INFO: PixTest:: pg_setup set to default.
[16:08:57.572] INFO: 12 hot pixels found in step 0
[16:08:58.585] INFO: Collecting data for 5 seconds...
[16:09:03.602] INFO: Done with hot pixel readout
[16:09:14.044] INFO: PixTest:: pg_setup set to default.
[16:09:14.045] INFO: 14 hot pixels found in step 1
[16:09:15.031] INFO: Collecting data for 5 seconds...
[16:09:20.048] INFO: Done with hot pixel readout
[16:09:31.432] INFO: PixTest:: pg_setup set to default.
[16:09:31.433] INFO: 14 hot pixels found in step 2
[16:09:32.420] INFO: Collecting data for 5 seconds...
[16:09:37.436] INFO: Done with hot pixel readout
[16:09:48.962] INFO: PixTest:: pg_setup set to default.
[16:09:48.963] INFO: 13 hot pixels found in step 3
[16:09:49.950] INFO: Collecting data for 5 seconds...
[16:09:54.966] INFO: Done with hot pixel readout
[16:10:06.371] INFO: PixTest:: pg_setup set to default.

[16:10:06.372] INFO: 9 hot pixels found in step 4
[16:10:07.358] INFO: Collecting data for 5 seconds...
[16:10:12.375] INFO: Done with hot pixel readout
[16:10:23.821] INFO: PixTest:: pg_setup set to default.


[16:10:23.822] INFO: 12 hot pixels found in step 5
[16:10:24.808] INFO: Collecting data for 5 seconds...
[16:10:29.825] INFO: Done with hot pixel readout
[16:10:41.211] INFO: PixTest:: pg_setup set to default.

[16:10:41.212] INFO: 7 hot pixels found in step 6
[16:10:42.198] INFO: Collecting data for 5 seconds...
[16:10:47.215] INFO: Done with hot pixel readout
[16:10:58.703] INFO: PixTest:: pg_setup set to default.

[16:10:58.704] INFO: 7 hot pixels found in step 7
[16:10:59.690] INFO: Collecting data for 5 seconds...
[16:11:04.707] INFO: Done with hot pixel readout
[16:11:16.119] INFO: PixTest:: pg_setup set to default.

[16:11:16.120] INFO: 8 hot pixels found in step 8
[16:11:17.106] INFO: Collecting data for 5 seconds...
[16:11:22.123] INFO: Done with hot pixel readout
[16:11:33.627] INFO: PixTest:: pg_setup set to default.

[16:11:33.627] INFO: 6 hot pixels found in step 9
[16:11:34.613] INFO: Collecting data for 5 seconds...
[16:11:39.630] INFO: Done with hot pixel readout
[16:11:51.179] INFO: PixTest:: pg_setup set to default.

[16:11:51.180] INFO: 4 hot pixels found in step 10
[16:11:52.166] INFO: Collecting data for 5 seconds...
[16:11:57.181] INFO: Done with hot pixel readout
[16:12:06.607] INFO: PixTest:: pg_setup set to default.

[16:12:06.608] INFO: 3 hot pixels found in step 11
[16:12:07.593] INFO: Collecting data for 5 seconds...
[16:12:12.609] INFO: Done with hot pixel readout
[16:12:23.424] INFO: PixTest:: pg_setup set to default.

[16:12:23.425] INFO: 4 hot pixels found in step 12
[16:12:24.412] INFO: Collecting data for 5 seconds...
[16:12:29.428] INFO: Done with hot pixel readout
[16:12:37.861] INFO: PixTest:: pg_setup set to default.

[16:12:37.862] INFO: 4 hot pixels found in step 13
[16:12:38.849] INFO: Collecting data for 5 seconds...
[16:12:43.864] INFO: Done with hot pixel readout
[16:12:55.382] INFO: PixTest:: pg_setup set to default.


[16:12:55.383] INFO: 2 hot pixels found in step 14
[16:12:55.413] INFO: 2 hot pixels could not be trimmed and have been masked.
[16:12:55.417] INFO: PixTest::trimHotPixels() done
[16:12:55.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[16:12:55.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[16:12:55.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[16:12:55.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[16:12:55.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[16:12:55.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[16:12:55.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[16:12:55.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[16:12:55.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[16:12:55.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[16:12:55.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[16:12:55.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[16:12:55.485] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[16:12:55.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[16:12:55.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[16:12:55.501] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[16:12:55.506] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[16:12:55.516] INFO: enter test to run
[16:13:59.658] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:13:59.658] INFO: running: highrate
[16:13:59.663] INFO: ----------------------------------------------------------------------
[16:13:59.663] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:13:59.663] INFO: ----------------------------------------------------------------------
[16:13:59.663] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:13:59.663] INFO: edge/corner pixel THR is adjusted
[16:13:59.663] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:14:00.620] INFO: Collecting data for 1 seconds...
[16:14:01.624] INFO: Done with hot pixel readout
[16:14:05.490] INFO: PixTest:: pg_setup set to default.
[16:14:05.491] INFO: 0 hot pixels found in step 0
[16:14:05.497] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:14:05.590] INFO: PixTest::trimHotPixels() done
[16:14:05.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[16:14:05.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[16:14:05.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[16:14:05.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[16:14:05.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[16:14:05.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[16:14:05.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[16:14:05.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[16:14:05.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[16:14:05.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[16:14:05.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[16:14:05.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[16:14:05.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[16:14:05.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[16:14:05.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[16:14:05.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[16:14:05.680] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-32_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[16:14:05.690] INFO: enter test to run
[16:14:50.866] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:14:50.866] INFO: running: xray
[16:14:50.867] INFO: ----------------------------------------------------------------------
[16:14:50.867] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:14:50.867] INFO: ----------------------------------------------------------------------
[16:14:51.827] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:15:03.670] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:15:31.536] INFO: Resuming triggers.
[16:15:43.381] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:16:11.999] INFO: Resuming triggers.
[16:16:23.840] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:16:54.026] INFO: Resuming triggers.
[16:17:05.873] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:17:35.460] INFO: Resuming triggers.
[16:17:47.314] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:18:16.770] INFO: Resuming triggers.
[16:18:28.626] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:18:57.929] INFO: Resuming triggers.
[16:19:09.779] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:19:38.124] INFO: Resuming triggers.
[16:19:49.973] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:20:18.901] INFO: Resuming triggers.
[16:20:24.466] INFO: data taking finished, elapsed time: 100 seconds.
[16:20:37.556] INFO: PixTest:: pg_setup set to default.
[16:20:37.560] INFO: PixTestXray::doPhRun() done
[16:20:37.694] INFO: enter test to run
[16:21:05.655] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:21:05.656] INFO: running: xray
[16:21:05.657] INFO: ----------------------------------------------------------------------
[16:21:05.657] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:21:05.657] INFO: ----------------------------------------------------------------------
[16:21:06.622] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:21:13.639] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:21:43.768] INFO: Resuming triggers.
[16:21:50.777] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:22:20.848] INFO: Resuming triggers.
[16:22:27.866] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:22:58.075] INFO: Resuming triggers.
[16:23:05.092] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:23:35.105] INFO: Resuming triggers.
[16:23:42.118] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:24:12.491] INFO: Resuming triggers.
[16:24:19.527] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[16:24:49.830] INFO: Resuming triggers.
[16:24:56.865] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:25:27.114] INFO: Resuming triggers.
[16:25:34.145] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:26:04.783] INFO: Resuming triggers.
[16:26:11.816] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:26:41.444] INFO: Resuming triggers.
[16:26:48.473] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:27:18.791] INFO: Resuming triggers.
[16:27:25.812] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[16:27:56.403] INFO: Resuming triggers.
[16:28:03.430] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:28:34.113] INFO: Resuming triggers.
[16:28:41.132] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:29:12.195] INFO: Resuming triggers.
[16:29:19.220] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[16:29:49.339] INFO: Resuming triggers.
[16:29:51.342] INFO: data taking finished, elapsed time: 100 seconds.
[16:30:00.220] INFO: PixTest:: pg_setup set to default.
[16:30:00.223] INFO: PixTestXray::doPhRun() done
[16:30:00.372] INFO: enter test to run
[16:30:21.220] INFO: test: HighRate no parameter change
[16:30:21.220] INFO: running: highrate
[16:30:21.234] INFO: ----------------------------------------------------------------------
[16:30:21.234] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:30:21.234] INFO: ----------------------------------------------------------------------
[16:30:21.398] INFO: Expecting 768 events.
[16:30:22.532] INFO: 768 events read in total (419ms).
[16:30:22.532] INFO: Test took 1269ms.
[16:30:23.335] INFO: Expecting 41600 events.
[16:30:26.406] INFO: 41600 events read in total (2544ms).
[16:30:26.407] INFO: Test took 3867ms.
[16:30:26.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:27.172] INFO: Expecting 41600 events.
[16:30:30.320] INFO: 41600 events read in total (2621ms).
[16:30:30.321] INFO: Test took 3869ms.
[16:30:30.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:31.084] INFO: Expecting 41600 events.
[16:30:34.282] INFO: 41600 events read in total (2671ms).
[16:30:34.283] INFO: Test took 3916ms.
[16:30:34.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:35.046] INFO: Expecting 41600 events.
[16:30:38.254] INFO: 41600 events read in total (2681ms).
[16:30:38.255] INFO: Test took 3925ms.
[16:30:38.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:39.018] INFO: Expecting 41600 events.
[16:30:42.223] INFO: 41600 events read in total (2678ms).
[16:30:42.223] INFO: Test took 3921ms.
[16:30:42.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:42.982] INFO: Expecting 41600 events.
[16:30:46.185] INFO: 41600 events read in total (2676ms).
[16:30:46.186] INFO: Test took 3917ms.
[16:30:46.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:46.947] INFO: Expecting 41600 events.
[16:30:50.147] INFO: 41600 events read in total (2673ms).
[16:30:50.148] INFO: Test took 3915ms.
[16:30:50.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:50.912] INFO: Expecting 41600 events.
[16:30:54.114] INFO: 41600 events read in total (2675ms).
[16:30:54.115] INFO: Test took 3920ms.
[16:30:54.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:54.873] INFO: Expecting 41600 events.
[16:30:58.055] INFO: 41600 events read in total (2655ms).
[16:30:58.056] INFO: Test took 3894ms.
[16:30:58.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:58.818] INFO: Expecting 41600 events.
[16:31:02.024] INFO: 41600 events read in total (2679ms).
[16:31:02.025] INFO: Test took 3922ms.
[16:31:02.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:02.786] INFO: Expecting 41600 events.
[16:31:05.976] INFO: 41600 events read in total (2663ms).
[16:31:05.977] INFO: Test took 3904ms.
[16:31:06.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:06.740] INFO: Expecting 41600 events.
[16:31:09.921] INFO: 41600 events read in total (2654ms).
[16:31:09.922] INFO: Test took 3896ms.
[16:31:09.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:10.685] INFO: Expecting 41600 events.
[16:31:13.890] INFO: 41600 events read in total (2679ms).
[16:31:13.891] INFO: Test took 3921ms.
[16:31:13.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:14.650] INFO: Expecting 41600 events.
[16:31:17.839] INFO: 41600 events read in total (2663ms).
[16:31:17.840] INFO: Test took 3903ms.
[16:31:17.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:18.599] INFO: Expecting 41600 events.
[16:31:21.799] INFO: 41600 events read in total (2673ms).
[16:31:21.800] INFO: Test took 3912ms.
[16:31:21.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:22.559] INFO: Expecting 41600 events.
[16:31:25.774] INFO: 41600 events read in total (2688ms).
[16:31:25.775] INFO: Test took 3928ms.
[16:31:25.806] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:26.537] INFO: Expecting 41600 events.
[16:31:29.744] INFO: 41600 events read in total (2680ms).
[16:31:29.745] INFO: Test took 3921ms.
[16:31:29.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:30.504] INFO: Expecting 41600 events.
[16:31:33.693] INFO: 41600 events read in total (2662ms).
[16:31:33.694] INFO: Test took 3902ms.
[16:31:33.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:34.457] INFO: Expecting 41600 events.
[16:31:37.643] INFO: 41600 events read in total (2659ms).
[16:31:37.644] INFO: Test took 3903ms.
[16:31:37.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:38.407] INFO: Expecting 41600 events.
[16:31:41.466] INFO: 41600 events read in total (2532ms).
[16:31:41.467] INFO: Test took 3776ms.
[16:31:41.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:41.867] INFO: enter test to run
[16:31:57.243] INFO: test: HighRate no parameter change
[16:31:57.243] INFO: running: highrate
[16:31:57.244] INFO: ----------------------------------------------------------------------
[16:31:57.244] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:31:57.244] INFO: ----------------------------------------------------------------------
[16:31:57.859] INFO: Expecting 208000 events.
[16:32:09.519] INFO: 208000 events read in total (11133ms).
[16:32:09.522] INFO: Test took 12269ms.
[16:32:09.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:09.892] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:32:09.892] INFO: number of red-efficiency pixels: 50 37 66 80 93 118 114 88 78 104 111 80 88 45 15 36
[16:32:09.892] INFO: number of X-ray hits detected: 48703 33444 56224 88138 91718 96687 97620 69799 64914 93123 91052 75749 78155 45754 17962 21129
[16:32:09.892] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:32:09.892] INFO: number of Vcal hits detected: 207940 207963 207933 207920 207906 207882 207883 207912 207921 207893 207887 207917 207912 207955 207985 207964
[16:32:09.892] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[16:32:09.892] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[16:32:09.892] INFO: X-ray hit rate [MHz/cm2]: 14.3 9.8 16.5 25.8 26.9 28.3 28.6 20.5 19.0 27.3 26.7 22.2 22.9 13.4 5.3 6.2
[16:32:09.892] INFO: PixTestHighRate::doXPixelAlive() done
[16:32:09.941] INFO: PixTest:: pg_setup set to default.
[16:32:09.954] INFO: enter test to run
[16:32:28.539] INFO: test: HighRate no parameter change
[16:32:28.539] INFO: running: highrate
[16:32:28.540] INFO: ----------------------------------------------------------------------
[16:32:28.540] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:32:28.540] INFO: ----------------------------------------------------------------------
[16:32:29.156] INFO: Expecting 208000 events.
[16:32:42.500] INFO: 208000 events read in total (12817ms).
[16:32:42.505] INFO: Test took 13956ms.
[16:32:42.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:43.066] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:32:43.066] INFO: number of red-efficiency pixels: 147 80 210 293 412 437 353 267 168 418 313 284 295 143 32 51
[16:32:43.066] INFO: number of X-ray hits detected: 109947 74657 125674 197235 204697 214976 216868 156116 144368 206619 201990 169223 173104 101680 40018 46685
[16:32:43.066] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:32:43.066] INFO: number of Vcal hits detected: 207831 207918 207774 207698 207560 207527 207622 207720 207826 207546 207676 207702 207692 207851 207966 207948
[16:32:43.066] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:32:43.066] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:32:43.066] INFO: X-ray hit rate [MHz/cm2]: 32.2 21.9 36.8 57.8 60.0 63.0 63.6 45.8 42.3 60.6 59.2 49.6 50.7 29.8 11.7 13.7
[16:32:43.066] INFO: PixTestHighRate::doXPixelAlive() done
[16:32:43.117] INFO: PixTest:: pg_setup set to default.
[16:32:43.133] INFO: enter test to run
[16:33:02.331] INFO: test: HighRate no parameter change
[16:33:02.331] INFO: running: highrate
[16:33:02.332] INFO: ----------------------------------------------------------------------
[16:33:02.332] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:33:02.332] INFO: ----------------------------------------------------------------------
[16:33:02.948] INFO: Expecting 208000 events.
[16:33:17.954] INFO: 208000 events read in total (14479ms).
[16:33:17.960] INFO: Test took 15619ms.
[16:33:18.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:18.707] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:33:18.707] INFO: number of red-efficiency pixels: 265 191 452 654 865 1090 869 641 413 994 705 658 683 350 77 90
[16:33:18.707] INFO: number of X-ray hits detected: 165570 113333 190448 298059 308686 322942 325738 236020 218368 312011 304756 255008 261848 153968 60292 70841
[16:33:18.707] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:33:18.707] INFO: number of Vcal hits detected: 207693 207794 207459 207255 206982 206615 206939 207209 207542 206795 207197 207209 207244 207607 207923 207907
[16:33:18.707] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.4 99.5 99.7 99.8 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[16:33:18.707] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.6 99.5 99.3 99.5 99.6 99.8 99.4 99.6 99.6 99.6 99.8 100.0 100.0
[16:33:18.707] INFO: X-ray hit rate [MHz/cm2]: 48.5 33.2 55.8 87.4 90.5 94.7 95.5 69.2 64.0 91.5 89.3 74.7 76.7 45.1 17.7 20.8
[16:33:18.707] INFO: PixTestHighRate::doXPixelAlive() done
[16:33:18.754] INFO: PixTest:: pg_setup set to default.
[16:33:18.772] INFO: enter test to run
[16:33:38.250] INFO: test: exit no parameter change
[16:33:38.519] QUIET: Connection to board 33 closed.
[16:33:38.530] INFO: pXar: this is the end, my friend