[14:21:57.512] INFO: *** Welcome to pxar ***
[14:21:57.512] INFO: *** Today: 2016/06/09
[14:21:57.544] INFO: *** Version: v1.9.0-814-g7497
[14:21:57.544] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C15.dat
[14:21:57.600] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:21:57.600] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[14:21:57.601] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[14:21:57.703] INFO: clk: 4
[14:21:57.703] INFO: ctr: 4
[14:21:57.703] INFO: sda: 19
[14:21:57.703] INFO: tin: 9
[14:21:57.703] INFO: level: 15
[14:21:57.703] INFO: triggerdelay: 0
[14:21:57.703] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:21:57.703] INFO: Log level: INFO
[14:21:57.721] QUIET: Connection to board DTB_WREKRL opened.
[14:21:57.724] 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:21:57.727] INFO: RPC call hashes of host and DTB match: 398089610
[14:21:59.254] INFO: DUT info:
[14:21:59.254] INFO: The DUT currently contains the following objects:
[14:21:59.254] INFO: 2 TBM Cores tbm08c (2 ON)
[14:21:59.254] INFO: TBM Core alpha (0): 7 registers set
[14:21:59.254] INFO: TBM Core beta (1): 7 registers set
[14:21:59.254] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:21:59.254] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.255] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.256] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.256] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:21:59.659] INFO: enter 'restricted' command line mode
[14:21:59.659] INFO: enter test to run
[14:22:07.455] INFO: test: PixelAlive no parameter change
[14:22:07.455] INFO: running: pixelalive
[14:22:07.464] INFO: ----------------------------------------------------------------------
[14:22:07.464] 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:22:07.464] INFO: ----------------------------------------------------------------------
[14:22:07.785] INFO: Expecting 41600 events.
[14:22:12.140] INFO: 41600 events read in total (3636ms).
[14:22:12.305] INFO: Test took 4838ms.
[14:22:12.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:12.577] INFO: PixTestAlive::aliveTest() done
[14:22:12.577] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0
[14:22:12.614] INFO: enter test to run
[14:22:58.935] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:22:58.935] INFO: running: highrate
[14:22:58.935] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:22:59.178] INFO: ----------------------------------------------------------------------
[14:22:59.178] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:22:59.178] INFO: ----------------------------------------------------------------------
[14:22:59.178] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:22:59.178] INFO: edge/corner pixel THR is adjusted
[14:22:59.178] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:23:00.138] INFO: Collecting data for 5 seconds...
[14:23:05.156] INFO: Done with hot pixel readout
[14:23:17.138] INFO: PixTest:: pg_setup set to default.
[14:23:17.139] INFO: 4 hot pixels found in step 0
[14:23:18.156] INFO: Collecting data for 5 seconds...
[14:23:23.172] INFO: Done with hot pixel readout
[14:23:35.302] INFO: PixTest:: pg_setup set to default.

[14:23:35.303] INFO: 7 hot pixels found in step 1
[14:23:36.298] INFO: Collecting data for 5 seconds...
[14:23:41.313] INFO: Done with hot pixel readout
[14:23:53.428] INFO: PixTest:: pg_setup set to default.
[14:23:53.429] INFO: 5 hot pixels found in step 2
[14:23:54.424] INFO: Collecting data for 5 seconds...
[14:23:59.441] INFO: Done with hot pixel readout
[14:24:11.560] INFO: PixTest:: pg_setup set to default.
[14:24:11.561] INFO: 5 hot pixels found in step 3
[14:24:12.557] INFO: Collecting data for 5 seconds...
[14:24:17.574] INFO: Done with hot pixel readout
[14:24:29.681] INFO: PixTest:: pg_setup set to default.
[14:24:29.681] INFO: 4 hot pixels found in step 4
[14:24:30.677] INFO: Collecting data for 5 seconds...
[14:24:35.694] INFO: Done with hot pixel readout
[14:24:47.816] INFO: PixTest:: pg_setup set to default.
[14:24:47.817] INFO: 5 hot pixels found in step 5
[14:24:48.812] INFO: Collecting data for 5 seconds...
[14:24:53.828] INFO: Done with hot pixel readout
[14:25:05.879] INFO: PixTest:: pg_setup set to default.
[14:25:05.879] INFO: 5 hot pixels found in step 6
[14:25:06.875] INFO: Collecting data for 5 seconds...
[14:25:11.891] INFO: Done with hot pixel readout
[14:25:23.991] INFO: PixTest:: pg_setup set to default.

[14:25:23.992] INFO: 6 hot pixels found in step 7
[14:25:24.988] INFO: Collecting data for 5 seconds...
[14:25:30.004] INFO: Done with hot pixel readout
[14:25:42.189] INFO: PixTest:: pg_setup set to default.
[14:25:42.190] INFO: 4 hot pixels found in step 8
[14:25:43.186] INFO: Collecting data for 5 seconds...
[14:25:48.202] INFO: Done with hot pixel readout
[14:26:00.368] INFO: PixTest:: pg_setup set to default.
[14:26:00.368] INFO: 1 hot pixels found in step 9
[14:26:01.364] INFO: Collecting data for 5 seconds...
[14:26:06.380] INFO: Done with hot pixel readout
[14:26:18.511] INFO: PixTest:: pg_setup set to default.
[14:26:18.511] INFO: 2 hot pixels found in step 10
[14:26:19.506] INFO: Collecting data for 5 seconds...
[14:26:24.522] INFO: Done with hot pixel readout
[14:26:36.642] INFO: PixTest:: pg_setup set to default.
[14:26:36.643] INFO: 7 hot pixels found in step 11
[14:26:37.639] INFO: Collecting data for 5 seconds...
[14:26:42.655] INFO: Done with hot pixel readout
[14:26:54.798] INFO: PixTest:: pg_setup set to default.

[14:26:54.799] INFO: 4 hot pixels found in step 12
[14:26:55.796] INFO: Collecting data for 5 seconds...
[14:27:00.812] INFO: Done with hot pixel readout
[14:27:12.987] INFO: PixTest:: pg_setup set to default.
[14:27:12.988] INFO: 3 hot pixels found in step 13
[14:27:13.983] INFO: Collecting data for 5 seconds...
[14:27:18.999] INFO: Done with hot pixel readout
[14:27:31.124] INFO: PixTest:: pg_setup set to default.
[14:27:31.125] INFO: 3 hot pixels found in step 14
[14:27:31.164] INFO: 3 hot pixels could not be trimmed and have been masked.
[14:27:31.167] INFO: PixTest::trimHotPixels() done
[14:27:31.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[14:27:31.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[14:27:31.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[14:27:31.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[14:27:31.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[14:27:31.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[14:27:31.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[14:27:31.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[14:27:31.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[14:27:31.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[14:27:31.222] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[14:27:31.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[14:27:31.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[14:27:31.238] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[14:27:31.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[14:27:31.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[14:27:31.254] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[14:27:31.270] INFO: enter test to run
[14:28:26.316] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:28:26.316] INFO: running: highrate
[14:28:26.321] INFO: ----------------------------------------------------------------------
[14:28:26.321] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:28:26.321] INFO: ----------------------------------------------------------------------
[14:28:26.321] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:28:26.321] INFO: edge/corner pixel THR is adjusted
[14:28:26.321] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:28:27.278] INFO: Collecting data for 1 seconds...
[14:28:28.282] INFO: Done with hot pixel readout
[14:28:32.612] INFO: PixTest:: pg_setup set to default.
[14:28:32.613] INFO: 0 hot pixels found in step 0
[14:28:32.618] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:28:32.695] INFO: PixTest::trimHotPixels() done
[14:28:32.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[14:28:32.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[14:28:32.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[14:28:32.718] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[14:28:32.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[14:28:32.729] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[14:28:32.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[14:28:32.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[14:28:32.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[14:28:32.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[14:28:32.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[14:28:32.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[14:28:32.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[14:28:32.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[14:28:32.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[14:28:32.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[14:28:32.788] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-13_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[14:28:32.797] INFO: enter test to run
[14:29:03.732] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:29:03.732] INFO: running: xray
[14:29:03.733] INFO: ----------------------------------------------------------------------
[14:29:03.733] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:29:03.733] INFO: ----------------------------------------------------------------------
[14:29:04.696] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:29:15.664] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:29:45.746] INFO: Resuming triggers.
[14:29:56.721] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:30:27.204] INFO: Resuming triggers.
[14:30:38.178] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:31:08.376] INFO: Resuming triggers.
[14:31:19.344] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:31:48.778] INFO: Resuming triggers.
[14:31:59.752] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:32:29.194] INFO: Resuming triggers.
[14:32:40.167] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:33:09.743] INFO: Resuming triggers.
[14:33:20.713] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:33:50.151] INFO: Resuming triggers.
[14:34:01.122] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:34:30.644] INFO: Resuming triggers.
[14:34:41.613] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:35:11.120] INFO: Resuming triggers.
[14:35:12.723] INFO: data taking finished, elapsed time: 100 seconds.
[14:35:17.420] INFO: PixTest:: pg_setup set to default.
[14:35:17.424] INFO: PixTestXray::doPhRun() done
[14:35:17.566] INFO: enter test to run
[14:36:07.249] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:36:07.249] INFO: running: xray
[14:36:07.250] INFO: ----------------------------------------------------------------------
[14:36:07.250] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:36:07.250] INFO: ----------------------------------------------------------------------
[14:36:08.221] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:36:14.408] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:36:44.488] INFO: Resuming triggers.
[14:36:50.671] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:37:20.761] INFO: Resuming triggers.
[14:37:26.945] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:37:57.021] INFO: Resuming triggers.
[14:38:03.206] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:38:33.288] INFO: Resuming triggers.
[14:38:39.477] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:39:09.586] INFO: Resuming triggers.
[14:39:15.774] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:39:46.576] INFO: Resuming triggers.
[14:39:52.758] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:40:23.327] INFO: Resuming triggers.
[14:40:29.509] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:40:59.899] INFO: Resuming triggers.
[14:41:06.082] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:41:37.172] INFO: Resuming triggers.
[14:41:43.358] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:42:14.376] INFO: Resuming triggers.
[14:42:20.563] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:42:50.947] INFO: Resuming triggers.
[14:42:57.134] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:43:27.186] INFO: Resuming triggers.
[14:43:33.372] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:44:03.498] INFO: Resuming triggers.
[14:44:09.686] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:44:39.774] INFO: Resuming triggers.
[14:44:45.957] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:45:16.098] INFO: Resuming triggers.
[14:45:22.281] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:45:52.343] INFO: Resuming triggers.
[14:45:53.716] INFO: data taking finished, elapsed time: 100 seconds.
[14:46:00.720] INFO: PixTest:: pg_setup set to default.
[14:46:00.723] INFO: PixTestXray::doPhRun() done
[14:46:00.871] INFO: enter test to run
[14:47:17.988] INFO: test: HighRate no parameter change
[14:47:17.988] INFO: running: highrate
[14:47:17.989] INFO: ----------------------------------------------------------------------
[14:47:17.989] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:47:17.989] INFO: ----------------------------------------------------------------------
[14:47:18.130] INFO: Expecting 768 events.
[14:47:19.264] INFO: 768 events read in total (419ms).
[14:47:19.264] INFO: Test took 1268ms.
[14:47:20.068] INFO: Expecting 41600 events.
[14:47:23.200] INFO: 41600 events read in total (2605ms).
[14:47:23.201] INFO: Test took 3928ms.
[14:47:23.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:23.961] INFO: Expecting 41600 events.
[14:47:27.117] INFO: 41600 events read in total (2630ms).
[14:47:27.118] INFO: Test took 3858ms.
[14:47:27.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:27.873] INFO: Expecting 41600 events.
[14:47:31.127] INFO: 41600 events read in total (2727ms).
[14:47:31.128] INFO: Test took 3952ms.
[14:47:31.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:31.885] INFO: Expecting 41600 events.
[14:47:35.099] INFO: 41600 events read in total (2687ms).
[14:47:35.101] INFO: Test took 3913ms.
[14:47:35.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:35.849] INFO: Expecting 41600 events.
[14:47:39.057] INFO: 41600 events read in total (2682ms).
[14:47:39.058] INFO: Test took 3900ms.
[14:47:39.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:39.812] INFO: Expecting 41600 events.
[14:47:43.067] INFO: 41600 events read in total (2729ms).
[14:47:43.068] INFO: Test took 3951ms.
[14:47:43.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:43.824] INFO: Expecting 41600 events.
[14:47:47.085] INFO: 41600 events read in total (2734ms).
[14:47:47.086] INFO: Test took 3959ms.
[14:47:47.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:47.841] INFO: Expecting 41600 events.
[14:47:51.104] INFO: 41600 events read in total (2736ms).
[14:47:51.105] INFO: Test took 3961ms.
[14:47:51.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:51.858] INFO: Expecting 41600 events.
[14:47:55.448] INFO: 41600 events read in total (2722ms).
[14:47:55.449] INFO: Test took 4286ms.
[14:47:55.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:56.201] INFO: Expecting 41600 events.
[14:47:59.409] INFO: 41600 events read in total (2681ms).
[14:47:59.410] INFO: Test took 3904ms.
[14:47:59.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:00.165] INFO: Expecting 41600 events.
[14:48:03.382] INFO: 41600 events read in total (2690ms).
[14:48:03.383] INFO: Test took 3918ms.
[14:48:03.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:04.135] INFO: Expecting 41600 events.
[14:48:07.352] INFO: 41600 events read in total (2690ms).
[14:48:07.353] INFO: Test took 3915ms.
[14:48:07.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:08.105] INFO: Expecting 41600 events.
[14:48:11.372] INFO: 41600 events read in total (2740ms).
[14:48:11.374] INFO: Test took 3964ms.
[14:48:11.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:12.126] INFO: Expecting 41600 events.
[14:48:15.394] INFO: 41600 events read in total (2741ms).
[14:48:15.395] INFO: Test took 3964ms.
[14:48:15.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:16.150] INFO: Expecting 41600 events.
[14:48:19.376] INFO: 41600 events read in total (2699ms).
[14:48:19.377] INFO: Test took 3925ms.
[14:48:19.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:20.130] INFO: Expecting 41600 events.
[14:48:23.361] INFO: 41600 events read in total (2704ms).
[14:48:23.362] INFO: Test took 3929ms.
[14:48:23.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:24.115] INFO: Expecting 41600 events.
[14:48:27.382] INFO: 41600 events read in total (2740ms).
[14:48:27.383] INFO: Test took 3965ms.
[14:48:27.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:28.136] INFO: Expecting 41600 events.
[14:48:31.399] INFO: 41600 events read in total (2736ms).
[14:48:31.400] INFO: Test took 3958ms.
[14:48:31.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:32.152] INFO: Expecting 41600 events.
[14:48:35.371] INFO: 41600 events read in total (2692ms).
[14:48:35.372] INFO: Test took 3916ms.
[14:48:35.409] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:36.125] INFO: Expecting 41600 events.
[14:48:39.185] INFO: 41600 events read in total (2534ms).
[14:48:39.187] INFO: Test took 3759ms.
[14:48:39.224] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:39.575] INFO: enter test to run
[14:49:12.211] INFO: test: HighRate no parameter change
[14:49:12.211] INFO: running: highrate
[14:49:12.212] INFO: ----------------------------------------------------------------------
[14:49:12.212] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:49:12.212] INFO: ----------------------------------------------------------------------
[14:49:12.833] INFO: Expecting 208000 events.
[14:49:24.814] INFO: 208000 events read in total (11454ms).
[14:49:24.817] INFO: Test took 12594ms.
[14:49:24.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:25.236] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0
[14:49:25.236] INFO: number of red-efficiency pixels: 78 55 84 184 161 196 226 118 101 164 122 93 108 67 21 20
[14:49:25.236] INFO: number of X-ray hits detected: 67312 49607 70726 125861 135976 133486 132832 102059 82337 108624 102727 88923 93951 56250 25633 27472
[14:49:25.236] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:49:25.236] INFO: number of Vcal hits detected: 207921 207943 207914 207810 207833 207700 207770 207881 207898 207835 207875 207905 207890 207932 207979 207980
[14:49:25.236] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:49:25.236] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:49:25.236] INFO: X-ray hit rate [MHz/cm2]: 19.7 14.5 20.7 36.9 39.9 39.1 38.9 29.9 24.1 31.8 30.1 26.1 27.5 16.5 7.5 8.1
[14:49:25.236] INFO: PixTestHighRate::doXPixelAlive() done
[14:49:25.285] INFO: PixTest:: pg_setup set to default.
[14:49:25.297] INFO: enter test to run
[14:50:17.146] INFO: test: HighRate no parameter change
[14:50:17.146] INFO: running: highrate
[14:50:17.148] INFO: ----------------------------------------------------------------------
[14:50:17.148] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:50:17.148] INFO: ----------------------------------------------------------------------
[14:50:17.765] INFO: Expecting 208000 events.
[14:50:31.395] INFO: 208000 events read in total (13103ms).
[14:50:31.400] INFO: Test took 14243ms.
[14:50:31.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:32.061] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0
[14:50:32.061] INFO: number of red-efficiency pixels: 218 139 269 621 597 634 744 406 241 521 447 342 353 216 65 66
[14:50:32.061] INFO: number of X-ray hits detected: 141177 103096 147438 261710 283241 277937 275936 213914 173134 226723 215554 185391 194540 117396 52853 57881
[14:50:32.061] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:50:32.061] INFO: number of Vcal hits detected: 207772 207856 207703 207292 207337 207178 207171 207543 207744 207437 207523 207641 207617 207769 207933 207932
[14:50:32.061] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.6 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:50:32.061] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.6 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:50:32.061] INFO: X-ray hit rate [MHz/cm2]: 41.4 30.2 43.2 76.7 83.0 81.5 80.9 62.7 50.7 66.5 63.2 54.3 57.0 34.4 15.5 17.0
[14:50:32.061] INFO: PixTestHighRate::doXPixelAlive() done
[14:50:32.108] INFO: PixTest:: pg_setup set to default.
[14:50:32.124] INFO: enter test to run
[14:51:02.626] INFO: test: HighRate no parameter change
[14:51:02.626] INFO: running: highrate
[14:51:02.627] INFO: ----------------------------------------------------------------------
[14:51:02.627] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:51:02.627] INFO: ----------------------------------------------------------------------
[14:51:03.242] INFO: Expecting 208000 events.
[14:51:19.316] INFO: 208000 events read in total (15548ms).
[14:51:19.325] INFO: Test took 16690ms.
[14:51:19.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:20.215] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0
[14:51:20.215] INFO: number of red-efficiency pixels: 406 281 540 1467 1417 1556 1726 916 611 1226 1100 717 816 484 106 98
[14:51:20.215] INFO: number of X-ray hits detected: 213792 155021 221223 392899 425055 416682 414137 321736 260317 340802 324309 279470 293224 177210 79935 86538
[14:51:20.215] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:51:20.215] INFO: number of Vcal hits detected: 207548 207688 207312 205968 206049 205741 205443 206808 207305 206470 206627 207158 207062 207409 207894 207899
[14:51:20.216] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.1 99.2 99.1 98.9 99.5 99.7 99.3 99.4 99.6 99.6 99.7 99.9 100.0
[14:51:20.216] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.0 99.1 98.9 98.8 99.4 99.7 99.3 99.3 99.6 99.5 99.7 99.9 100.0
[14:51:20.216] INFO: X-ray hit rate [MHz/cm2]: 62.7 45.4 64.8 115.2 124.6 122.1 121.4 94.3 76.3 99.9 95.1 81.9 85.9 51.9 23.4 25.4
[14:51:20.216] INFO: PixTestHighRate::doXPixelAlive() done
[14:51:20.262] INFO: PixTest:: pg_setup set to default.
[14:51:20.280] INFO: enter test to run
[14:51:53.546] INFO: test: exit no parameter change
[14:51:53.818] QUIET: Connection to board 33 closed.
[14:51:53.819] INFO: pXar: this is the end, my friend