[14:42:43.731] INFO: *** Welcome to pxar ***
[14:42:43.731] INFO: *** Today: 2016/07/21
[14:42:43.989] INFO: *** Version: v1.9.0-814-g7497
[14:42:43.989] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//dacParameters35_C15.dat
[14:42:44.040] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:42:44.040] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:42:44.042] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:42:44.191] INFO: clk: 4
[14:42:44.192] INFO: ctr: 4
[14:42:44.192] INFO: sda: 19
[14:42:44.192] INFO: tin: 9
[14:42:44.192] INFO: level: 15
[14:42:44.192] INFO: triggerdelay: 0
[14:42:44.192] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:42:44.192] INFO: Log level: INFO
[14:42:44.209] QUIET: Connection to board DTB_WREKRL opened.
[14:42:44.213] 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:
------------------------------------------------------
[14:42:44.216] INFO: RPC call hashes of host and DTB match: 398089610
[14:42:45.743] INFO: DUT info:
[14:42:45.743] INFO: The DUT currently contains the following objects:
[14:42:45.743] INFO: 2 TBM Cores tbm08c (2 ON)
[14:42:45.743] INFO: TBM Core alpha (0): 7 registers set
[14:42:45.743] INFO: TBM Core beta (1): 7 registers set
[14:42:45.743] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:42:45.743] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:45.744] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:42:46.147] INFO: enter 'restricted' command line mode
[14:42:46.147] INFO: enter test to run
[14:42:54.587] INFO: test: PixelAlive no parameter change
[14:42:54.587] INFO: running: pixelalive
[14:42:54.596] INFO: ----------------------------------------------------------------------
[14:42:54.596] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:42:54.596] INFO: ----------------------------------------------------------------------
[14:42:54.919] INFO: Expecting 41600 events.
[14:42:59.235] INFO: 41600 events read in total (3598ms).
[14:42:59.402] INFO: Test took 4803ms.
[14:42:59.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:59.684] INFO: PixTestAlive::aliveTest() done
[14:42:59.684] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 5 0 0
[14:42:59.712] INFO: enter test to run
[14:44:10.179] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:44:10.179] INFO: running: highrate
[14:44:10.179] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:44:10.413] INFO: ----------------------------------------------------------------------
[14:44:10.413] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:44:10.413] INFO: ----------------------------------------------------------------------
[14:44:10.413] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:44:10.413] INFO: edge/corner pixel THR is adjusted
[14:44:10.413] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:44:11.372] INFO: Collecting data for 5 seconds...
[14:44:16.390] INFO: Done with hot pixel readout
[14:44:28.285] INFO: PixTest:: pg_setup set to default.
[14:44:28.286] INFO: 19 hot pixels found in step 0
[14:44:29.300] INFO: Collecting data for 5 seconds...
[14:44:34.317] INFO: Done with hot pixel readout
[14:44:46.215] INFO: PixTest:: pg_setup set to default.


[14:44:46.216] INFO: 21 hot pixels found in step 1
[14:44:47.206] INFO: Collecting data for 5 seconds...
[14:44:52.224] INFO: Done with hot pixel readout
[14:45:03.823] INFO: PixTest:: pg_setup set to default.
[14:45:03.824] INFO: 11 hot pixels found in step 2
[14:45:04.814] INFO: Collecting data for 5 seconds...
[14:45:09.830] INFO: Done with hot pixel readout
[14:45:21.314] INFO: PixTest:: pg_setup set to default.
[14:45:21.315] INFO: 21 hot pixels found in step 3
[14:45:22.307] INFO: Collecting data for 5 seconds...
[14:45:27.323] INFO: Done with hot pixel readout
[14:45:39.102] INFO: PixTest:: pg_setup set to default.
[14:45:39.103] INFO: 13 hot pixels found in step 4
[14:45:40.092] INFO: Collecting data for 5 seconds...
[14:45:45.109] INFO: Done with hot pixel readout
[14:45:56.886] INFO: PixTest:: pg_setup set to default.
[14:45:56.886] INFO: 17 hot pixels found in step 5
[14:45:57.874] INFO: Collecting data for 5 seconds...
[14:46:02.891] INFO: Done with hot pixel readout
[14:46:14.766] INFO: PixTest:: pg_setup set to default.
[14:46:14.767] INFO: 15 hot pixels found in step 6
[14:46:15.756] INFO: Collecting data for 5 seconds...
[14:46:20.772] INFO: Done with hot pixel readout
[14:46:32.634] INFO: PixTest:: pg_setup set to default.

[14:46:32.635] INFO: 12 hot pixels found in step 7
[14:46:33.624] INFO: Collecting data for 5 seconds...
[14:46:38.642] INFO: Done with hot pixel readout
[14:46:50.485] INFO: PixTest:: pg_setup set to default.
[14:46:50.486] INFO: 8 hot pixels found in step 8
[14:46:51.475] INFO: Collecting data for 5 seconds...
[14:46:56.491] INFO: Done with hot pixel readout
[14:47:08.320] INFO: PixTest:: pg_setup set to default.


[14:47:08.321] INFO: 12 hot pixels found in step 9
[14:47:09.310] INFO: Collecting data for 5 seconds...
[14:47:14.327] INFO: Done with hot pixel readout
[14:47:26.062] INFO: PixTest:: pg_setup set to default.

[14:47:26.063] INFO: 14 hot pixels found in step 10
[14:47:27.053] INFO: Collecting data for 5 seconds...
[14:47:32.070] INFO: Done with hot pixel readout
[14:47:43.761] INFO: PixTest:: pg_setup set to default.

[14:47:43.762] INFO: 9 hot pixels found in step 11
[14:47:44.752] INFO: Collecting data for 5 seconds...
[14:47:49.771] INFO: Done with hot pixel readout
[14:48:01.446] INFO: PixTest:: pg_setup set to default.
[14:48:01.447] INFO: 6 hot pixels found in step 12
[14:48:02.436] INFO: Collecting data for 5 seconds...
[14:48:07.456] INFO: Done with hot pixel readout
[14:48:19.049] INFO: PixTest:: pg_setup set to default.

[14:48:19.050] INFO: 9 hot pixels found in step 13
[14:48:20.040] INFO: Collecting data for 5 seconds...
[14:48:25.058] INFO: Done with hot pixel readout
[14:48:36.682] INFO: PixTest:: pg_setup set to default.
[14:48:36.683] INFO: 11 hot pixels found in step 14
[14:48:36.717] INFO: 11 hot pixels could not be trimmed and have been masked.
[14:48:36.720] INFO: PixTest::trimHotPixels() done
[14:48:36.725] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat
[14:48:36.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C1.dat
[14:48:36.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C2.dat
[14:48:36.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C3.dat
[14:48:36.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C4.dat
[14:48:36.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C5.dat
[14:48:36.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C6.dat
[14:48:36.810] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C7.dat
[14:48:36.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C8.dat
[14:48:36.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C9.dat
[14:48:36.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C10.dat
[14:48:36.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C11.dat
[14:48:36.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C12.dat
[14:48:36.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C13.dat
[14:48:36.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C14.dat
[14:48:36.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:48:36.860] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:48:36.870] INFO: enter test to run
[14:49:53.592] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:49:53.592] INFO: running: highrate
[14:49:53.597] INFO: ----------------------------------------------------------------------
[14:49:53.597] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:49:53.597] INFO: ----------------------------------------------------------------------
[14:49:53.597] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:49:53.597] INFO: edge/corner pixel THR is adjusted
[14:49:53.597] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:49:54.554] INFO: Collecting data for 1 seconds...
[14:49:55.558] INFO: Done with hot pixel readout
[14:49:59.575] INFO: PixTest:: pg_setup set to default.
[14:49:59.576] INFO: 0 hot pixels found in step 0
[14:49:59.581] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:49:59.672] INFO: PixTest::trimHotPixels() done
[14:49:59.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C0.dat
[14:49:59.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C1.dat
[14:49:59.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C2.dat
[14:49:59.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C3.dat
[14:49:59.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C4.dat
[14:49:59.710] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C5.dat
[14:49:59.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C6.dat
[14:49:59.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C7.dat
[14:49:59.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C8.dat
[14:49:59.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C9.dat
[14:49:59.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C10.dat
[14:49:59.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C11.dat
[14:49:59.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C12.dat
[14:49:59.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C13.dat
[14:49:59.759] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C14.dat
[14:49:59.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//trimParameters35_C15.dat
[14:49:59.771] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-18_FPIXTest-17C-FNAL-160628-1356_2016-06-28_13h56m_1467140179/000_FPIXTest_p17//defaultMaskFile.dat
[14:49:59.780] INFO: enter test to run
[14:50:37.400] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:50:37.400] INFO: running: xray
[14:50:37.401] INFO: ----------------------------------------------------------------------
[14:50:37.401] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:50:37.401] INFO: ----------------------------------------------------------------------
[14:50:38.366] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:50:49.650] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:51:19.802] INFO: Resuming triggers.
[14:51:31.085] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:52:00.752] INFO: Resuming triggers.
[14:52:12.038] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:52:41.529] INFO: Resuming triggers.
[14:52:52.815] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:53:22.361] INFO: Resuming triggers.
[14:53:33.652] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:54:03.178] INFO: Resuming triggers.
[14:54:14.464] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:54:44.062] INFO: Resuming triggers.
[14:54:55.348] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:55:24.804] INFO: Resuming triggers.
[14:55:36.089] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:56:05.659] INFO: Resuming triggers.
[14:56:15.717] INFO: data taking finished, elapsed time: 100 seconds.
[14:56:42.239] INFO: PixTest:: pg_setup set to default.
[14:56:42.242] INFO: PixTestXray::doPhRun() done
[14:56:42.383] INFO: enter test to run
[14:57:15.149] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:57:15.149] INFO: running: xray
[14:57:15.150] INFO: ----------------------------------------------------------------------
[14:57:15.150] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:57:15.150] INFO: ----------------------------------------------------------------------
[14:57:16.115] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:57:22.786] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:57:52.893] INFO: Resuming triggers.
[14:57:59.564] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:58:29.791] INFO: Resuming triggers.
[14:58:36.462] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:59:06.649] INFO: Resuming triggers.
[14:59:13.323] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:59:44.217] INFO: Resuming triggers.
[14:59:50.887] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:00:21.563] INFO: Resuming triggers.
[15:00:28.234] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:00:58.062] INFO: Resuming triggers.
[15:01:04.731] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:01:35.457] INFO: Resuming triggers.
[15:01:42.130] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:02:13.545] INFO: Resuming triggers.
[15:02:20.217] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:02:51.729] INFO: Resuming triggers.
[15:02:58.398] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:03:28.844] INFO: Resuming triggers.
[15:03:35.515] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:04:05.766] INFO: Resuming triggers.
[15:04:12.437] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:04:42.644] INFO: Resuming triggers.
[15:04:49.312] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:05:19.520] INFO: Resuming triggers.
[15:05:26.188] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:05:56.357] INFO: Resuming triggers.
[15:06:03.027] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:06:33.415] INFO: Resuming triggers.
[15:06:33.712] INFO: data taking finished, elapsed time: 100 seconds.
[15:06:35.434] INFO: PixTest:: pg_setup set to default.
[15:06:35.437] INFO: PixTestXray::doPhRun() done
[15:06:35.588] INFO: enter test to run
[15:07:19.337] INFO: test: HighRate no parameter change
[15:07:19.337] INFO: running: highrate
[15:07:19.338] INFO: ----------------------------------------------------------------------
[15:07:19.338] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:07:19.338] INFO: ----------------------------------------------------------------------
[15:07:19.480] INFO: Expecting 768 events.
[15:07:20.614] INFO: 768 events read in total (418ms).
[15:07:20.614] INFO: Test took 1268ms.
[15:07:21.418] INFO: Expecting 41600 events.
[15:07:24.549] INFO: 41600 events read in total (2604ms).
[15:07:24.550] INFO: Test took 3927ms.
[15:07:24.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:25.311] INFO: Expecting 41600 events.
[15:07:28.548] INFO: 41600 events read in total (2710ms).
[15:07:28.549] INFO: Test took 3947ms.
[15:07:28.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:29.306] INFO: Expecting 41600 events.
[15:07:32.548] INFO: 41600 events read in total (2715ms).
[15:07:32.549] INFO: Test took 3947ms.
[15:07:32.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:33.309] INFO: Expecting 41600 events.
[15:07:36.550] INFO: 41600 events read in total (2714ms).
[15:07:36.551] INFO: Test took 3950ms.
[15:07:36.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:37.306] INFO: Expecting 41600 events.
[15:07:40.559] INFO: 41600 events read in total (2727ms).
[15:07:40.560] INFO: Test took 3956ms.
[15:07:40.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:41.317] INFO: Expecting 41600 events.
[15:07:44.569] INFO: 41600 events read in total (2725ms).
[15:07:44.570] INFO: Test took 3956ms.
[15:07:44.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:45.329] INFO: Expecting 41600 events.
[15:07:48.588] INFO: 41600 events read in total (2733ms).
[15:07:48.589] INFO: Test took 3966ms.
[15:07:48.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:49.347] INFO: Expecting 41600 events.
[15:07:52.619] INFO: 41600 events read in total (2745ms).
[15:07:52.620] INFO: Test took 3977ms.
[15:07:52.655] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:53.376] INFO: Expecting 41600 events.
[15:07:56.630] INFO: 41600 events read in total (2728ms).
[15:07:56.631] INFO: Test took 3957ms.
[15:07:56.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:57.389] INFO: Expecting 41600 events.
[15:08:00.649] INFO: 41600 events read in total (2733ms).
[15:08:00.650] INFO: Test took 3966ms.
[15:08:00.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:01.406] INFO: Expecting 41600 events.
[15:08:04.669] INFO: 41600 events read in total (2736ms).
[15:08:04.670] INFO: Test took 3967ms.
[15:08:04.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:05.428] INFO: Expecting 41600 events.
[15:08:08.689] INFO: 41600 events read in total (2734ms).
[15:08:08.690] INFO: Test took 3967ms.
[15:08:08.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:09.448] INFO: Expecting 41600 events.
[15:08:12.710] INFO: 41600 events read in total (2736ms).
[15:08:12.711] INFO: Test took 3967ms.
[15:08:12.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:13.468] INFO: Expecting 41600 events.
[15:08:16.727] INFO: 41600 events read in total (2732ms).
[15:08:16.728] INFO: Test took 3964ms.
[15:08:16.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:17.484] INFO: Expecting 41600 events.
[15:08:20.739] INFO: 41600 events read in total (2729ms).
[15:08:20.740] INFO: Test took 3957ms.
[15:08:20.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:21.498] INFO: Expecting 41600 events.
[15:08:24.760] INFO: 41600 events read in total (2735ms).
[15:08:24.761] INFO: Test took 3969ms.
[15:08:24.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:25.520] INFO: Expecting 41600 events.
[15:08:28.788] INFO: 41600 events read in total (2741ms).
[15:08:28.788] INFO: Test took 3975ms.
[15:08:28.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:29.543] INFO: Expecting 41600 events.
[15:08:32.789] INFO: 41600 events read in total (2719ms).
[15:08:32.790] INFO: Test took 3947ms.
[15:08:32.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:33.549] INFO: Expecting 41600 events.
[15:08:36.769] INFO: 41600 events read in total (2693ms).
[15:08:36.770] INFO: Test took 3926ms.
[15:08:36.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:37.529] INFO: Expecting 41600 events.
[15:08:40.632] INFO: 41600 events read in total (2576ms).
[15:08:40.633] INFO: Test took 3810ms.
[15:08:40.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:41.030] INFO: enter test to run
[15:09:18.512] INFO: test: HighRate no parameter change
[15:09:18.512] INFO: running: highrate
[15:09:18.513] INFO: ----------------------------------------------------------------------
[15:09:18.513] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:18.513] INFO: ----------------------------------------------------------------------
[15:09:19.132] INFO: Expecting 208000 events.
[15:09:30.998] INFO: 208000 events read in total (11339ms).
[15:09:30.002] INFO: Test took 12480ms.
[15:09:31.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:31.402] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 5 0 0
[15:09:31.403] INFO: number of red-efficiency pixels: 97 61 90 161 150 176 136 107 82 130 126 106 131 87 27 35
[15:09:31.403] INFO: number of X-ray hits detected: 64738 43442 68897 112084 120435 123980 121873 83070 74603 102974 99109 83258 89170 53577 21699 27267
[15:09:31.403] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:09:31.403] INFO: number of Vcal hits detected: 207903 207936 207909 207831 207795 207820 207857 207890 207918 207869 207872 207892 207866 207668 207973 207965
[15:09:31.403] 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
[15:09:31.403] 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 99.9 99.9 99.8 100.0 100.0
[15:09:31.403] INFO: X-ray hit rate [MHz/cm2]: 19.0 12.7 20.2 32.9 35.3 36.3 35.7 24.3 21.9 30.2 29.0 24.4 26.1 15.7 6.4 8.0
[15:09:31.403] INFO: PixTestHighRate::doXPixelAlive() done
[15:09:31.454] INFO: PixTest:: pg_setup set to default.
[15:09:31.469] INFO: enter test to run
[15:09:57.480] INFO: test: HighRate no parameter change
[15:09:57.480] INFO: running: highrate
[15:09:57.481] INFO: ----------------------------------------------------------------------
[15:09:57.481] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:57.481] INFO: ----------------------------------------------------------------------
[15:09:58.098] INFO: Expecting 208000 events.
[15:10:10.767] INFO: 208000 events read in total (12142ms).
[15:10:10.773] INFO: Test took 13282ms.
[15:10:11.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:11.367] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 5 0 0
[15:10:11.367] INFO: number of red-efficiency pixels: 176 111 282 381 478 663 406 288 235 430 422 337 404 213 51 51
[15:10:11.367] INFO: number of X-ray hits detected: 131945 87519 139719 226892 245000 251539 246099 168841 151966 207682 200010 169909 181223 109185 44337 55711
[15:10:11.367] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:10:11.367] INFO: number of Vcal hits detected: 207812 207885 207685 207585 207438 207250 207564 207691 207757 207542 207554 207646 207571 207532 207949 207949
[15:10:11.367] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:10:11.367] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.8 100.0 100.0
[15:10:11.367] INFO: X-ray hit rate [MHz/cm2]: 38.7 25.7 41.0 66.5 71.8 73.7 72.1 49.5 44.5 60.9 58.6 49.8 53.1 32.0 13.0 16.3
[15:10:11.367] INFO: PixTestHighRate::doXPixelAlive() done
[15:10:11.417] INFO: PixTest:: pg_setup set to default.
[15:10:11.431] INFO: enter test to run
[15:10:34.216] INFO: test: HighRate no parameter change
[15:10:34.216] INFO: running: highrate
[15:10:34.217] INFO: ----------------------------------------------------------------------
[15:10:34.217] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:10:34.217] INFO: ----------------------------------------------------------------------
[15:10:34.831] INFO: Expecting 208000 events.
[15:10:49.636] INFO: 208000 events read in total (14279ms).
[15:10:49.643] INFO: Test took 15417ms.
[15:10:50.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:50.438] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 5 0 0
[15:10:50.438] INFO: number of red-efficiency pixels: 393 213 700 915 1071 1464 1083 617 455 1075 1011 680 758 475 88 117
[15:10:50.438] INFO: number of X-ray hits detected: 198376 131269 210423 341039 368315 378375 370700 254095 229370 312218 302249 255408 271987 163744 66857 84078
[15:10:50.438] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:10:50.438] INFO: number of Vcal hits detected: 207529 207769 207057 206879 206589 206014 206620 207250 207492 206682 206755 207221 207125 207220 207909 207880
[15:10:50.438] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.4 99.1 99.4 99.7 99.8 99.4 99.5 99.7 99.6 99.8 100.0 99.9
[15:10:50.438] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.5 99.5 99.3 99.0 99.3 99.6 99.8 99.4 99.4 99.6 99.6 99.6 100.0 99.9
[15:10:50.438] INFO: X-ray hit rate [MHz/cm2]: 58.1 38.5 61.7 100.0 108.0 110.9 108.7 74.5 67.2 91.5 88.6 74.9 79.7 48.0 19.6 24.6
[15:10:50.438] INFO: PixTestHighRate::doXPixelAlive() done
[15:10:50.488] INFO: PixTest:: pg_setup set to default.
[15:10:50.503] INFO: enter test to run
[15:11:21.559] INFO: test: exit no parameter change
[15:11:21.853] QUIET: Connection to board 33 closed.
[15:11:21.855] INFO: pXar: this is the end, my friend