[10:10:40.861] INFO: *** Welcome to pxar ***
[10:10:40.861] INFO: *** Today: 2016/05/17
[10:10:41.286] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:10:41.286] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C15.dat
[10:10:41.347] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:10:41.347] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[10:10:41.355] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[10:10:41.463] INFO: clk: 4
[10:10:41.463] INFO: ctr: 4
[10:10:41.463] INFO: sda: 19
[10:10:41.463] INFO: tin: 9
[10:10:41.463] INFO: level: 15
[10:10:41.463] INFO: triggerdelay: 0
[10:10:41.463] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:10:41.463] INFO: Log level: INFO
[10:10:41.480] QUIET: Connection to board DTB_WREKRL opened.
[10:10:41.483] 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:
------------------------------------------------------
[10:10:41.486] INFO: RPC call hashes of host and DTB match: 398089610
[10:10:43.031] INFO: DUT info:
[10:10:43.031] INFO: The DUT currently contains the following objects:
[10:10:43.031] INFO: 2 TBM Cores tbm08c (2 ON)
[10:10:43.045] INFO: TBM Core alpha (0): 7 registers set
[10:10:43.045] INFO: TBM Core beta (1): 7 registers set
[10:10:43.045] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:10:43.045] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.045] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.046] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:43.492] INFO: enter 'restricted' command line mode
[10:10:43.492] INFO: enter test to run
[10:11:02.988] INFO: test: PixelAlive no parameter change
[10:11:02.988] INFO: running: pixelalive
[10:11:03.051] INFO: ----------------------------------------------------------------------
[10:11:03.051] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:11:03.051] INFO: ----------------------------------------------------------------------
[10:11:03.371] INFO: Expecting 41600 events.
[10:11:07.769] INFO: 41600 events read in total (3680ms).
[10:11:07.927] INFO: Test took 4872ms.
[10:11:07.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:08.394] INFO: PixTestAlive::aliveTest() done
[10:11:08.394] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:11:08.526] INFO: enter test to run
[10:11:36.211] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:11:36.212] INFO: running: highrate
[10:11:36.212] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:11:36.465] INFO: ----------------------------------------------------------------------
[10:11:36.465] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:11:36.465] INFO: ----------------------------------------------------------------------
[10:11:36.465] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:11:36.465] INFO: edge/corner pixel THR is adjusted
[10:11:36.465] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:11:37.423] INFO: Collecting data for 5 seconds...
[10:11:42.445] INFO: Done with hot pixel readout
[10:11:54.411] INFO: PixTest:: pg_setup set to default.
[10:11:54.412] INFO: 14 hot pixels found in step 0
[10:11:55.423] INFO: Collecting data for 5 seconds...
[10:12:00.441] INFO: Done with hot pixel readout
[10:12:12.178] INFO: PixTest:: pg_setup set to default.
[10:12:12.179] INFO: 15 hot pixels found in step 1
[10:12:13.167] INFO: Collecting data for 5 seconds...
[10:12:18.186] INFO: Done with hot pixel readout
[10:12:30.036] INFO: PixTest:: pg_setup set to default.
[10:12:30.037] INFO: 6 hot pixels found in step 2
[10:12:31.026] INFO: Collecting data for 5 seconds...
[10:12:36.045] INFO: Done with hot pixel readout
[10:12:47.425] INFO: PixTest:: pg_setup set to default.
[10:12:47.426] INFO: 12 hot pixels found in step 3
[10:12:48.414] INFO: Collecting data for 5 seconds...
[10:12:53.430] INFO: Done with hot pixel readout
[10:13:05.081] INFO: PixTest:: pg_setup set to default.
[10:13:05.082] INFO: 11 hot pixels found in step 4
[10:13:06.069] INFO: Collecting data for 5 seconds...
[10:13:11.084] INFO: Done with hot pixel readout
[10:13:22.725] INFO: PixTest:: pg_setup set to default.
[10:13:22.726] INFO: 5 hot pixels found in step 5
[10:13:23.715] INFO: Collecting data for 5 seconds...
[10:13:28.732] INFO: Done with hot pixel readout
[10:13:40.372] INFO: PixTest:: pg_setup set to default.
[10:13:40.373] INFO: 7 hot pixels found in step 6
[10:13:41.360] INFO: Collecting data for 5 seconds...
[10:13:46.377] INFO: Done with hot pixel readout
[10:13:58.026] INFO: PixTest:: pg_setup set to default.

[10:13:58.027] INFO: 3 hot pixels found in step 7
[10:13:59.014] INFO: Collecting data for 5 seconds...
[10:14:04.030] INFO: Done with hot pixel readout
[10:14:15.683] INFO: PixTest:: pg_setup set to default.
[10:14:15.683] INFO: 5 hot pixels found in step 8
[10:14:16.671] INFO: Collecting data for 5 seconds...
[10:14:21.687] INFO: Done with hot pixel readout
[10:14:33.299] INFO: PixTest:: pg_setup set to default.
[10:14:33.300] INFO: 1 hot pixels found in step 9
[10:14:34.287] INFO: Collecting data for 5 seconds...
[10:14:39.303] INFO: Done with hot pixel readout
[10:14:50.936] INFO: PixTest:: pg_setup set to default.
[10:14:50.937] INFO: 4 hot pixels found in step 10
[10:14:51.925] INFO: Collecting data for 5 seconds...
[10:14:56.942] INFO: Done with hot pixel readout
[10:15:08.560] INFO: PixTest:: pg_setup set to default.
[10:15:08.561] INFO: 0 hot pixels found in step 11
[10:15:08.592] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:15:08.610] INFO: PixTest::trimHotPixels() done
[10:15:08.614] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[10:15:08.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[10:15:08.626] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[10:15:08.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[10:15:08.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[10:15:08.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[10:15:08.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[10:15:08.657] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[10:15:08.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[10:15:08.667] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[10:15:08.672] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[10:15:08.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[10:15:08.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[10:15:08.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[10:15:08.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[10:15:08.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[10:15:08.704] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[10:15:08.714] INFO: enter test to run
[10:15:49.994] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:15:49.994] INFO: running: highrate
[10:15:49.998] INFO: ----------------------------------------------------------------------
[10:15:49.998] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:15:49.998] INFO: ----------------------------------------------------------------------
[10:15:49.998] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:15:49.998] INFO: edge/corner pixel THR is adjusted
[10:15:49.998] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:15:50.962] INFO: Collecting data for 1 seconds...
[10:15:51.966] INFO: Done with hot pixel readout
[10:15:55.971] INFO: PixTest:: pg_setup set to default.
[10:15:55.972] INFO: 0 hot pixels found in step 0
[10:15:55.977] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:15:56.071] INFO: PixTest::trimHotPixels() done
[10:15:56.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[10:15:56.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[10:15:56.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[10:15:56.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[10:15:56.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[10:15:56.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[10:15:56.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[10:15:56.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[10:15:56.117] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[10:15:56.122] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[10:15:56.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[10:15:56.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[10:15:56.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[10:15:56.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[10:15:56.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[10:15:56.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[10:15:56.159] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-26_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[10:15:56.169] INFO: enter test to run
[10:16:26.569] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:16:26.569] INFO: running: xray
[10:16:26.571] INFO: ----------------------------------------------------------------------
[10:16:26.571] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:16:26.571] INFO: ----------------------------------------------------------------------
[10:16:27.544] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:16:39.145] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:17:08.478] INFO: Resuming triggers.
[10:17:20.078] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:17:49.474] INFO: Resuming triggers.
[10:18:01.078] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:18:30.329] INFO: Resuming triggers.
[10:18:41.930] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:19:11.280] INFO: Resuming triggers.
[10:19:22.880] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:19:52.209] INFO: Resuming triggers.
[10:20:03.809] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:20:33.214] INFO: Resuming triggers.
[10:20:44.814] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:21:14.238] INFO: Resuming triggers.
[10:21:25.835] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:21:54.836] INFO: Resuming triggers.
[10:22:02.363] INFO: data taking finished, elapsed time: 100 seconds.
[10:22:21.643] INFO: PixTest:: pg_setup set to default.
[10:22:21.646] INFO: PixTestXray::doPhRun() done
[10:22:21.820] INFO: enter test to run
[10:23:11.558] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:23:11.559] INFO: running: xray
[10:23:11.560] INFO: ----------------------------------------------------------------------
[10:23:11.560] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:23:11.560] INFO: ----------------------------------------------------------------------
[10:23:12.528] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:23:19.245] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:23:49.957] INFO: Resuming triggers.
[10:23:56.676] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:24:26.705] INFO: Resuming triggers.
[10:24:33.421] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:25:03.491] INFO: Resuming triggers.
[10:25:10.205] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:25:40.247] INFO: Resuming triggers.
[10:25:46.967] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:26:17.061] INFO: Resuming triggers.
[10:26:23.781] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:26:53.623] INFO: Resuming triggers.
[10:27:00.343] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:27:30.375] INFO: Resuming triggers.
[10:27:37.094] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[10:28:07.115] INFO: Resuming triggers.
[10:28:13.834] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:28:43.821] INFO: Resuming triggers.
[10:28:50.540] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:29:20.566] INFO: Resuming triggers.
[10:29:27.290] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:29:57.306] INFO: Resuming triggers.
[10:30:04.025] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:30:34.081] INFO: Resuming triggers.
[10:30:40.799] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[10:31:10.780] INFO: Resuming triggers.
[10:31:17.496] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:31:47.445] INFO: Resuming triggers.
[10:31:53.712] INFO: data taking finished, elapsed time: 100 seconds.
[10:32:22.461] INFO: PixTest:: pg_setup set to default.
[10:32:22.464] INFO: PixTestXray::doPhRun() done
[10:32:22.617] INFO: enter test to run
[10:33:03.426] INFO: test: HighRate no parameter change
[10:33:03.426] INFO: running: highrate
[10:33:03.427] INFO: ----------------------------------------------------------------------
[10:33:03.427] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:33:03.427] INFO: ----------------------------------------------------------------------
[10:33:03.568] INFO: Expecting 768 events.
[10:33:04.708] INFO: 768 events read in total (419ms).
[10:33:04.708] INFO: Test took 1274ms.
[10:33:05.512] INFO: Expecting 41600 events.
[10:33:08.650] INFO: 41600 events read in total (2612ms).
[10:33:08.651] INFO: Test took 3936ms.
[10:33:08.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:09.412] INFO: Expecting 41600 events.
[10:33:12.695] INFO: 41600 events read in total (2756ms).
[10:33:12.696] INFO: Test took 3993ms.
[10:33:12.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:13.453] INFO: Expecting 41600 events.
[10:33:16.720] INFO: 41600 events read in total (2740ms).
[10:33:16.721] INFO: Test took 3974ms.
[10:33:16.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:17.480] INFO: Expecting 41600 events.
[10:33:20.711] INFO: 41600 events read in total (2704ms).
[10:33:20.712] INFO: Test took 3940ms.
[10:33:20.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:21.470] INFO: Expecting 41600 events.
[10:33:24.729] INFO: 41600 events read in total (2732ms).
[10:33:24.730] INFO: Test took 3965ms.
[10:33:24.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:25.471] INFO: Expecting 41600 events.
[10:33:28.729] INFO: 41600 events read in total (2731ms).
[10:33:28.730] INFO: Test took 3931ms.
[10:33:28.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:29.489] INFO: Expecting 41600 events.
[10:33:32.828] INFO: 41600 events read in total (2812ms).
[10:33:32.829] INFO: Test took 4045ms.
[10:33:32.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:33.577] INFO: Expecting 41600 events.
[10:33:36.829] INFO: 41600 events read in total (2725ms).
[10:33:36.830] INFO: Test took 3950ms.
[10:33:36.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:37.588] INFO: Expecting 41600 events.
[10:33:40.905] INFO: 41600 events read in total (2790ms).
[10:33:40.906] INFO: Test took 4024ms.
[10:33:40.940] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:41.661] INFO: Expecting 41600 events.
[10:33:44.943] INFO: 41600 events read in total (2756ms).
[10:33:44.944] INFO: Test took 3986ms.
[10:33:44.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:45.703] INFO: Expecting 41600 events.
[10:33:48.950] INFO: 41600 events read in total (2720ms).
[10:33:48.951] INFO: Test took 3955ms.
[10:33:48.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:49.710] INFO: Expecting 41600 events.
[10:33:52.976] INFO: 41600 events read in total (2739ms).
[10:33:52.976] INFO: Test took 3972ms.
[10:33:53.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:53.727] INFO: Expecting 41600 events.
[10:33:57.081] INFO: 41600 events read in total (2827ms).
[10:33:57.082] INFO: Test took 4053ms.
[10:33:57.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:57.837] INFO: Expecting 41600 events.
[10:34:01.140] INFO: 41600 events read in total (2776ms).
[10:34:01.141] INFO: Test took 4006ms.
[10:34:01.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:01.897] INFO: Expecting 41600 events.
[10:34:05.255] INFO: 41600 events read in total (2831ms).
[10:34:05.256] INFO: Test took 4062ms.
[10:34:05.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:06.014] INFO: Expecting 41600 events.
[10:34:09.419] INFO: 41600 events read in total (2879ms).
[10:34:09.420] INFO: Test took 4112ms.
[10:34:09.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:10.175] INFO: Expecting 41600 events.
[10:34:13.450] INFO: 41600 events read in total (2748ms).
[10:34:13.451] INFO: Test took 3978ms.
[10:34:13.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:14.206] INFO: Expecting 41600 events.
[10:34:17.568] INFO: 41600 events read in total (2835ms).
[10:34:17.569] INFO: Test took 4065ms.
[10:34:17.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:18.327] INFO: Expecting 41600 events.
[10:34:21.598] INFO: 41600 events read in total (2744ms).
[10:34:21.599] INFO: Test took 3978ms.
[10:34:21.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:22.353] INFO: Expecting 41600 events.
[10:34:25.558] INFO: 41600 events read in total (2678ms).
[10:34:25.559] INFO: Test took 3909ms.
[10:34:25.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:25.943] INFO: enter test to run
[10:34:55.217] INFO: test: HighRate no parameter change
[10:34:55.217] INFO: running: highrate
[10:34:55.219] INFO: ----------------------------------------------------------------------
[10:34:55.219] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:34:55.219] INFO: ----------------------------------------------------------------------
[10:34:55.844] INFO: Expecting 208000 events.
[10:35:07.685] INFO: 208000 events read in total (11314ms).
[10:35:07.688] INFO: Test took 12460ms.
[10:35:07.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:08.079] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:35:08.079] INFO: number of red-efficiency pixels: 92 54 87 134 180 130 127 83 73 110 88 93 92 65 21 20
[10:35:08.079] INFO: number of X-ray hits detected: 66535 45460 64054 108382 112786 114814 112878 76823 71504 89981 91304 77886 82958 48581 23321 23439
[10:35:08.079] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:35:08.079] INFO: number of Vcal hits detected: 207907 207946 207913 207862 207810 207866 207873 207917 207926 207888 207912 207905 207907 207935 207979 207980
[10:35:08.079] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[10:35:08.079] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:35:08.079] INFO: X-ray hit rate [MHz/cm2]: 19.5 13.3 18.8 31.8 33.1 33.7 33.1 22.5 21.0 26.4 26.8 22.8 24.3 14.2 6.8 6.9
[10:35:08.079] INFO: PixTestHighRate::doXPixelAlive() done
[10:35:08.123] INFO: PixTest:: pg_setup set to default.
[10:35:08.139] INFO: enter test to run
[10:35:29.505] INFO: test: HighRate no parameter change
[10:35:29.505] INFO: running: highrate
[10:35:29.506] INFO: ----------------------------------------------------------------------
[10:35:29.506] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:35:29.506] INFO: ----------------------------------------------------------------------
[10:35:30.118] INFO: Expecting 208000 events.
[10:35:43.708] INFO: 208000 events read in total (13063ms).
[10:35:43.713] INFO: Test took 14197ms.
[10:35:44.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:44.314] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:35:44.314] INFO: number of red-efficiency pixels: 254 147 288 546 607 446 533 283 221 404 293 290 316 169 57 45
[10:35:44.314] INFO: number of X-ray hits detected: 140381 94784 134506 227319 237598 240225 238132 161126 150620 189471 192755 163478 174129 102763 49682 49354
[10:35:44.314] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:35:44.314] INFO: number of Vcal hits detected: 207734 207842 207694 207391 207333 207512 207418 207701 207773 207561 207688 207690 207667 207823 207942 207955
[10:35:44.314] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.7 99.9 99.9 99.8 99.9 99.9 99.8 99.9 100.0 100.0
[10:35:44.315] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.7 99.9 99.9 99.8 99.9 99.9 99.8 99.9 100.0 100.0
[10:35:44.315] INFO: X-ray hit rate [MHz/cm2]: 41.1 27.8 39.4 66.6 69.6 70.4 69.8 47.2 44.1 55.5 56.5 47.9 51.0 30.1 14.6 14.5
[10:35:44.315] INFO: PixTestHighRate::doXPixelAlive() done
[10:35:44.365] INFO: PixTest:: pg_setup set to default.
[10:35:44.380] INFO: enter test to run
[10:36:08.569] INFO: test: HighRate no parameter change
[10:36:08.569] INFO: running: highrate
[10:36:08.570] INFO: ----------------------------------------------------------------------
[10:36:08.570] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:36:08.570] INFO: ----------------------------------------------------------------------
[10:36:09.188] INFO: Expecting 208000 events.
[10:36:24.622] INFO: 208000 events read in total (14907ms).
[10:36:24.629] INFO: Test took 16049ms.
[10:36:25.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:25.428] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:36:25.428] INFO: number of red-efficiency pixels: 579 287 619 1261 1377 973 1360 648 489 881 632 631 715 379 112 71
[10:36:25.428] INFO: number of X-ray hits detected: 212782 145160 204004 346560 361994 366868 363514 245025 230494 289228 293874 249627 266010 156924 76473 75568
[10:36:25.428] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:36:25.428] INFO: number of Vcal hits detected: 207301 207675 207210 206386 206160 206777 206214 207180 207475 206972 207278 207269 207181 207566 207886 207926
[10:36:25.428] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.3 99.2 99.5 99.2 99.7 99.8 99.5 99.7 99.7 99.6 99.8 99.9 100.0
[10:36:25.428] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.2 99.1 99.4 99.1 99.6 99.7 99.5 99.7 99.6 99.6 99.8 99.9 100.0
[10:36:25.428] INFO: X-ray hit rate [MHz/cm2]: 62.4 42.5 59.8 101.6 106.1 107.5 106.5 71.8 67.6 84.8 86.1 73.2 78.0 46.0 22.4 22.1
[10:36:25.428] INFO: PixTestHighRate::doXPixelAlive() done
[10:36:25.475] INFO: PixTest:: pg_setup set to default.
[10:36:25.493] INFO: enter test to run
[10:36:47.136] INFO: test: exit no parameter change
[10:36:47.467] QUIET: Connection to board 33 closed.
[10:36:47.469] INFO: pXar: this is the end, my friend