[10:39:34.246] INFO: *** Welcome to pxar ***
[10:39:34.246] INFO: *** Today: 2016/06/09
[10:39:34.265] INFO: *** Version: v1.9.0-814-g7497
[10:39:34.265] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//dacParameters35_C15.dat
[10:39:34.297] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:39:34.298] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//defaultMaskFile.dat
[10:39:34.305] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C15.dat
[10:39:34.418] INFO: clk: 4
[10:39:34.418] INFO: ctr: 4
[10:39:34.418] INFO: sda: 19
[10:39:34.418] INFO: tin: 9
[10:39:34.418] INFO: level: 15
[10:39:34.418] INFO: triggerdelay: 0
[10:39:34.418] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:39:34.418] INFO: Log level: INFO
[10:39:34.434] QUIET: Connection to board DTB_WREKRL opened.
[10:39:34.437] 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:39:34.440] INFO: RPC call hashes of host and DTB match: 398089610
[10:39:35.976] INFO: DUT info:
[10:39:35.977] INFO: The DUT currently contains the following objects:
[10:39:35.977] INFO: 2 TBM Cores tbm08c (2 ON)
[10:39:35.977] INFO: TBM Core alpha (0): 7 registers set
[10:39:35.977] INFO: TBM Core beta (1): 7 registers set
[10:39:35.977] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:39:35.977] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.977] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.978] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:35.978] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:39:36.381] INFO: enter 'restricted' command line mode
[10:39:36.381] INFO: enter test to run
[10:40:47.592] INFO: test: PixelAlive no parameter change
[10:40:47.592] INFO: running: pixelalive
[10:40:47.669] INFO: ----------------------------------------------------------------------
[10:40:47.669] 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:40:47.669] INFO: ----------------------------------------------------------------------
[10:40:47.988] INFO: Expecting 41600 events.
[10:40:52.340] INFO: 41600 events read in total (3633ms).
[10:40:52.505] INFO: Test took 4832ms.
[10:40:52.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:52.834] INFO: PixTestAlive::aliveTest() done
[10:40:52.834] INFO: number of dead pixels (per ROC): 0 3 0 0 0 1 0 1 0 0 0 0 0 0 0 0
[10:40:52.949] INFO: enter test to run
[10:41:48.568] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:41:48.568] INFO: running: highrate
[10:41:48.568] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:41:48.796] INFO: ----------------------------------------------------------------------
[10:41:48.796] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:41:48.796] INFO: ----------------------------------------------------------------------
[10:41:48.796] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:41:48.796] INFO: edge/corner pixel THR is adjusted
[10:41:48.796] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:41:49.756] INFO: Collecting data for 5 seconds...
[10:41:54.773] INFO: Done with hot pixel readout
[10:42:06.298] INFO: PixTest:: pg_setup set to default.
[10:42:06.299] INFO: 13 hot pixels found in step 0
[10:42:07.289] INFO: Collecting data for 5 seconds...
[10:42:12.305] INFO: Done with hot pixel readout
[10:42:23.838] INFO: PixTest:: pg_setup set to default.
[10:42:23.839] INFO: 13 hot pixels found in step 1
[10:42:24.833] INFO: Collecting data for 5 seconds...
[10:42:29.849] INFO: Done with hot pixel readout
[10:42:41.441] INFO: PixTest:: pg_setup set to default.
[10:42:41.442] INFO: 11 hot pixels found in step 2
[10:42:42.433] INFO: Collecting data for 5 seconds...
[10:42:47.449] INFO: Done with hot pixel readout
[10:42:58.976] INFO: PixTest:: pg_setup set to default.
[10:42:58.977] INFO: 11 hot pixels found in step 3
[10:42:59.969] INFO: Collecting data for 5 seconds...
[10:43:04.986] INFO: Done with hot pixel readout
[10:43:16.521] INFO: PixTest:: pg_setup set to default.
[10:43:16.522] INFO: 13 hot pixels found in step 4
[10:43:17.513] INFO: Collecting data for 5 seconds...
[10:43:22.529] INFO: Done with hot pixel readout
[10:43:34.086] INFO: PixTest:: pg_setup set to default.
[10:43:34.086] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:43:34.087] INFO: 10 hot pixels found in step 5
[10:43:35.079] INFO: Collecting data for 5 seconds...
[10:43:40.094] INFO: Done with hot pixel readout
[10:43:51.619] INFO: PixTest:: pg_setup set to default.
[10:43:51.619] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:43:51.620] INFO: 10 hot pixels found in step 6
[10:43:52.612] INFO: Collecting data for 5 seconds...
[10:43:57.627] INFO: Done with hot pixel readout
[10:44:09.161] INFO: PixTest:: pg_setup set to default.
[10:44:09.161] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:44:09.162] INFO: 6 hot pixels found in step 7
[10:44:10.154] INFO: Collecting data for 5 seconds...
[10:44:15.169] INFO: Done with hot pixel readout
[10:44:26.684] INFO: PixTest:: pg_setup set to default.
[10:44:26.684] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:44:26.685] INFO: 5 hot pixels found in step 8
[10:44:27.677] INFO: Collecting data for 5 seconds...
[10:44:32.693] INFO: Done with hot pixel readout
[10:44:44.227] INFO: PixTest:: pg_setup set to default.
[10:44:44.227] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:44:44.228] INFO: 2 hot pixels found in step 9
[10:44:45.218] INFO: Collecting data for 5 seconds...
[10:44:50.235] INFO: Done with hot pixel readout
[10:45:01.831] INFO: PixTest:: pg_setup set to default.
[10:45:01.831] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:45:01.832] INFO: 2 hot pixels found in step 10
[10:45:02.824] INFO: Collecting data for 5 seconds...
[10:45:07.840] INFO: Done with hot pixel readout
[10:45:19.373] INFO: PixTest:: pg_setup set to default.
[10:45:19.373] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:45:19.374] INFO: 3 hot pixels found in step 11
[10:45:20.366] INFO: Collecting data for 5 seconds...
[10:45:25.381] INFO: Done with hot pixel readout
[10:45:36.906] INFO: PixTest:: pg_setup set to default.
[10:45:36.906] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:45:36.907] INFO: 4 hot pixels found in step 12
[10:45:37.899] INFO: Collecting data for 5 seconds...
[10:45:42.915] INFO: Done with hot pixel readout
[10:45:54.452] INFO: PixTest:: pg_setup set to default.
[10:45:54.452] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:45:54.453] INFO: 5 hot pixels found in step 13
[10:45:55.444] INFO: Collecting data for 5 seconds...
[10:46:00.460] INFO: Done with hot pixel readout
[10:46:12.032] INFO: PixTest:: pg_setup set to default.
[10:46:12.032] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:46:12.033] INFO: 4 hot pixels found in step 14
[10:46:12.068] INFO: 4 hot pixels could not be trimmed and have been masked.
[10:46:12.071] INFO: PixTest::trimHotPixels() done
[10:46:12.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C0.dat
[10:46:12.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C1.dat
[10:46:12.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C2.dat
[10:46:12.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C3.dat
[10:46:12.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C4.dat
[10:46:12.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C5.dat
[10:46:12.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C6.dat
[10:46:12.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C7.dat
[10:46:12.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C8.dat
[10:46:12.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C9.dat
[10:46:12.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C10.dat
[10:46:12.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C11.dat
[10:46:12.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C12.dat
[10:46:12.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C13.dat
[10:46:12.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C14.dat
[10:46:12.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C15.dat
[10:46:12.155] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//defaultMaskFile.dat
[10:46:12.165] INFO: enter test to run
[10:46:48.454] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:46:48.454] INFO: running: highrate
[10:46:48.458] INFO: ----------------------------------------------------------------------
[10:46:48.458] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:46:48.458] INFO: ----------------------------------------------------------------------
[10:46:48.458] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:46:48.458] INFO: edge/corner pixel THR is adjusted
[10:46:48.458] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:46:49.416] INFO: Collecting data for 1 seconds...
[10:46:50.419] INFO: Done with hot pixel readout
[10:46:54.330] INFO: PixTest:: pg_setup set to default.
[10:46:54.331] INFO: 0 hot pixels found in step 0
[10:46:54.336] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:46:54.427] INFO: PixTest::trimHotPixels() done
[10:46:54.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C0.dat
[10:46:54.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C1.dat
[10:46:54.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C2.dat
[10:46:54.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C3.dat
[10:46:54.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C4.dat
[10:46:54.461] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C5.dat
[10:46:54.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C6.dat
[10:46:54.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C7.dat
[10:46:54.477] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C8.dat
[10:46:54.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C9.dat
[10:46:54.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C10.dat
[10:46:54.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C11.dat
[10:46:54.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C12.dat
[10:46:54.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C13.dat
[10:46:54.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C14.dat
[10:46:54.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//trimParameters35_C15.dat
[10:46:54.521] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-30_FPIXTest-17C-FNAL-160602-1223_2016-06-02_12h23m_1464888229/000_FPIXTest_p17//defaultMaskFile.dat
[10:46:54.531] INFO: enter test to run
[10:47:25.589] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:47:25.589] INFO: running: xray
[10:47:25.591] INFO: ----------------------------------------------------------------------
[10:47:25.591] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:47:25.591] INFO: ----------------------------------------------------------------------
[10:47:26.553] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:47:38.196] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:48:07.603] INFO: Resuming triggers.
[10:48:19.249] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:48:49.104] INFO: Resuming triggers.
[10:49:00.747] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:49:29.771] INFO: Resuming triggers.
[10:49:41.411] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:50:10.599] INFO: Resuming triggers.
[10:50:22.244] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:50:52.026] INFO: Resuming triggers.
[10:51:03.667] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:51:33.352] INFO: Resuming triggers.
[10:51:44.987] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:52:14.343] INFO: Resuming triggers.
[10:52:25.981] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:52:55.347] INFO: Resuming triggers.
[10:53:02.567] INFO: data taking finished, elapsed time: 100 seconds.
[10:53:21.111] INFO: PixTest:: pg_setup set to default.
[10:53:21.114] INFO: PixTestXray::doPhRun() done
[10:53:21.281] INFO: enter test to run
[10:53:57.026] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:53:57.026] INFO: running: xray
[10:53:57.027] INFO: ----------------------------------------------------------------------
[10:53:57.028] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:53:57.028] INFO: ----------------------------------------------------------------------
[10:53:57.991] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:54:04.886] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:54:35.130] INFO: Resuming triggers.
[10:54:42.031] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:55:12.189] INFO: Resuming triggers.
[10:55:19.090] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:55:49.290] INFO: Resuming triggers.
[10:55:56.190] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[10:56:26.301] INFO: Resuming triggers.
[10:56:33.201] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:57:03.447] INFO: Resuming triggers.
[10:57:10.349] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[10:57:40.708] INFO: Resuming triggers.
[10:57:47.610] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:58:17.887] INFO: Resuming triggers.
[10:58:24.793] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:58:55.071] INFO: Resuming triggers.
[10:59:01.974] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[10:59:32.275] INFO: Resuming triggers.
[10:59:39.180] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:00:09.561] INFO: Resuming triggers.
[11:00:16.462] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:00:47.229] INFO: Resuming triggers.
[11:00:54.132] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[11:01:24.996] INFO: Resuming triggers.
[11:01:31.893] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[11:02:03.409] INFO: Resuming triggers.
[11:02:10.305] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[11:02:41.799] INFO: Resuming triggers.
[11:02:45.531] INFO: data taking finished, elapsed time: 100 seconds.
[11:03:02.844] INFO: PixTest:: pg_setup set to default.
[11:03:02.847] INFO: PixTestXray::doPhRun() done
[11:03:02.000] INFO: enter test to run
[11:03:32.486] INFO: test: HighRate no parameter change
[11:03:32.486] INFO: running: highrate
[11:03:32.508] INFO: ----------------------------------------------------------------------
[11:03:32.508] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:03:32.508] INFO: ----------------------------------------------------------------------
[11:03:32.649] INFO: Expecting 768 events.
[11:03:33.783] INFO: 768 events read in total (419ms).
[11:03:33.783] INFO: Test took 1269ms.
[11:03:34.586] INFO: Expecting 41600 events.
[11:03:37.587] INFO: 41600 events read in total (2474ms).
[11:03:37.588] INFO: Test took 3797ms.
[11:03:37.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:38.353] INFO: Expecting 41600 events.
[11:03:41.496] INFO: 41600 events read in total (2616ms).
[11:03:41.497] INFO: Test took 3857ms.
[11:03:41.530] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:42.259] INFO: Expecting 41600 events.
[11:03:45.462] INFO: 41600 events read in total (2677ms).
[11:03:45.463] INFO: Test took 3915ms.
[11:03:45.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:46.223] INFO: Expecting 41600 events.
[11:03:49.432] INFO: 41600 events read in total (2682ms).
[11:03:49.433] INFO: Test took 3921ms.
[11:03:49.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:50.190] INFO: Expecting 41600 events.
[11:03:53.396] INFO: 41600 events read in total (2679ms).
[11:03:53.397] INFO: Test took 3915ms.
[11:03:53.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:54.158] INFO: Expecting 41600 events.
[11:03:57.389] INFO: 41600 events read in total (2704ms).
[11:03:57.390] INFO: Test took 3944ms.
[11:03:57.423] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:58.149] INFO: Expecting 41600 events.
[11:04:01.372] INFO: 41600 events read in total (2697ms).
[11:04:01.373] INFO: Test took 3932ms.
[11:04:01.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:02.129] INFO: Expecting 41600 events.
[11:04:05.343] INFO: 41600 events read in total (2687ms).
[11:04:05.344] INFO: Test took 3922ms.
[11:04:05.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:06.101] INFO: Expecting 41600 events.
[11:04:09.316] INFO: 41600 events read in total (2688ms).
[11:04:09.317] INFO: Test took 3923ms.
[11:04:09.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:10.074] INFO: Expecting 41600 events.
[11:04:13.301] INFO: 41600 events read in total (2700ms).
[11:04:13.302] INFO: Test took 3935ms.
[11:04:13.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:14.060] INFO: Expecting 41600 events.
[11:04:17.286] INFO: 41600 events read in total (2699ms).
[11:04:17.287] INFO: Test took 3936ms.
[11:04:17.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:18.048] INFO: Expecting 41600 events.
[11:04:21.260] INFO: 41600 events read in total (2685ms).
[11:04:21.261] INFO: Test took 3923ms.
[11:04:21.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:22.023] INFO: Expecting 41600 events.
[11:04:25.252] INFO: 41600 events read in total (2702ms).
[11:04:25.253] INFO: Test took 3941ms.
[11:04:25.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:26.011] INFO: Expecting 41600 events.
[11:04:29.226] INFO: 41600 events read in total (2688ms).
[11:04:29.227] INFO: Test took 3924ms.
[11:04:29.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:29.987] INFO: Expecting 41600 events.
[11:04:33.197] INFO: 41600 events read in total (2684ms).
[11:04:33.198] INFO: Test took 3923ms.
[11:04:33.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:33.957] INFO: Expecting 41600 events.
[11:04:37.182] INFO: 41600 events read in total (2698ms).
[11:04:37.183] INFO: Test took 3935ms.
[11:04:37.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:37.942] INFO: Expecting 41600 events.
[11:04:41.164] INFO: 41600 events read in total (2695ms).
[11:04:41.165] INFO: Test took 3931ms.
[11:04:41.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:41.921] INFO: Expecting 41600 events.
[11:04:45.125] INFO: 41600 events read in total (2677ms).
[11:04:45.126] INFO: Test took 3912ms.
[11:04:45.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:45.883] INFO: Expecting 41600 events.
[11:04:49.072] INFO: 41600 events read in total (2662ms).
[11:04:49.072] INFO: Test took 3896ms.
[11:04:49.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:49.830] INFO: Expecting 41600 events.
[11:04:52.958] INFO: 41600 events read in total (2601ms).
[11:04:52.959] INFO: Test took 3838ms.
[11:04:52.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:53.350] INFO: enter test to run
[11:05:15.165] INFO: test: HighRate no parameter change
[11:05:15.165] INFO: running: highrate
[11:05:15.166] INFO: ----------------------------------------------------------------------
[11:05:15.166] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:05:15.167] INFO: ----------------------------------------------------------------------
[11:05:15.783] INFO: Expecting 208000 events.
[11:05:27.522] INFO: 208000 events read in total (11212ms).
[11:05:27.525] INFO: Test took 12350ms.
[11:05:27.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:27.911] INFO: number of dead pixels (per ROC): 0 3 160 0 0 1 0 1 0 0 0 0 0 0 0 0
[11:05:27.911] INFO: number of red-efficiency pixels: 80 54 238 118 127 125 146 111 109 113 109 99 87 51 18 28
[11:05:27.911] INFO: number of X-ray hits detected: 60642 40506 65021 105381 106676 113294 108735 74567 76459 91491 89260 75093 79053 48259 21857 26149
[11:05:27.911] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:05:27.911] INFO: number of Vcal hits detected: 207919 207798 199919 207879 207873 207810 207854 207840 207888 207883 207887 207900 207911 207948 207982 207971
[11:05:27.911] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[11:05:27.911] INFO: Vcal hit overall efficiency (%): 100.0 99.9 96.1 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:05:27.911] INFO: X-ray hit rate [MHz/cm2]: 17.8 11.9 19.1 30.9 31.3 33.2 31.9 21.9 22.4 26.8 26.2 22.0 23.2 14.1 6.4 7.7
[11:05:27.911] INFO: PixTestHighRate::doXPixelAlive() done
[11:05:27.959] INFO: PixTest:: pg_setup set to default.
[11:05:27.972] INFO: enter test to run
[11:05:47.173] INFO: test: HighRate no parameter change
[11:05:47.173] INFO: running: highrate
[11:05:47.174] INFO: ----------------------------------------------------------------------
[11:05:47.174] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:05:47.174] INFO: ----------------------------------------------------------------------
[11:05:47.788] INFO: Expecting 208000 events.
[11:06:01.183] INFO: 208000 events read in total (12869ms).
[11:06:01.188] INFO: Test took 14003ms.
[11:06:01.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:01.760] INFO: number of dead pixels (per ROC): 0 3 160 0 0 1 0 1 0 0 0 0 0 0 0 0
[11:06:01.760] INFO: number of red-efficiency pixels: 166 105 343 352 446 445 433 306 270 360 317 240 251 128 55 65
[11:06:01.760] INFO: number of X-ray hits detected: 124734 84343 133626 216108 219721 233077 223360 153884 157138 187674 182939 154344 162228 99024 45158 54056
[11:06:01.760] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:06:01.760] INFO: number of Vcal hits detected: 207827 207744 199807 207620 207532 207437 207534 207616 207710 207619 207670 207750 207735 207869 207945 207933
[11:06:01.760] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[11:06:01.760] INFO: Vcal hit overall efficiency (%): 99.9 99.9 96.1 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:06:01.760] INFO: X-ray hit rate [MHz/cm2]: 36.6 24.7 39.2 63.3 64.4 68.3 65.5 45.1 46.1 55.0 53.6 45.2 47.6 29.0 13.2 15.8
[11:06:01.760] INFO: PixTestHighRate::doXPixelAlive() done
[11:06:01.815] INFO: PixTest:: pg_setup set to default.
[11:06:01.825] INFO: enter test to run
[11:06:22.485] INFO: test: HighRate no parameter change
[11:06:22.485] INFO: running: highrate
[11:06:22.486] INFO: ----------------------------------------------------------------------
[11:06:22.486] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:06:22.486] INFO: ----------------------------------------------------------------------
[11:06:23.101] INFO: Expecting 208000 events.
[11:06:38.283] INFO: 208000 events read in total (14655ms).
[11:06:38.290] INFO: Test took 15795ms.
[11:06:38.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:39.048] INFO: number of dead pixels (per ROC): 0 3 160 0 0 1 0 1 0 0 0 0 0 0 0 0
[11:06:39.048] INFO: number of red-efficiency pixels: 349 191 618 827 1136 1057 905 687 612 827 792 559 615 264 117 122
[11:06:39.048] INFO: number of X-ray hits detected: 191343 128437 204164 330197 335809 356111 341525 236653 242373 286961 280542 236458 247653 152127 69454 82257
[11:06:39.048] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:06:39.048] INFO: number of Vcal hits detected: 207611 207652 199447 207045 206588 206538 206896 207079 207276 207022 207064 207373 207303 207715 207879 207875
[11:06:39.048] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.4 99.4 99.5 99.6 99.7 99.6 99.6 99.7 99.7 99.9 99.9 99.9
[11:06:39.048] INFO: Vcal hit overall efficiency (%): 99.8 99.8 95.9 99.5 99.3 99.3 99.5 99.6 99.7 99.5 99.6 99.7 99.7 99.9 99.9 99.9
[11:06:39.048] INFO: X-ray hit rate [MHz/cm2]: 56.1 37.6 59.8 96.8 98.4 104.4 100.1 69.4 71.0 84.1 82.2 69.3 72.6 44.6 20.4 24.1
[11:06:39.048] INFO: PixTestHighRate::doXPixelAlive() done
[11:06:39.094] INFO: PixTest:: pg_setup set to default.
[11:06:39.108] INFO: enter test to run
[11:06:50.021] INFO: test: exit no parameter change
[11:06:50.412] QUIET: Connection to board 33 closed.
[11:06:50.413] INFO: pXar: this is the end, my friend