[13:32:12.723] INFO: *** Welcome to pxar ***
[13:32:12.723] INFO: *** Today: 2016/06/15
[13:32:12.740] INFO: *** Version: v1.9.0-814-g7497
[13:32:12.741] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//dacParameters35_C15.dat
[13:32:12.775] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:32:12.775] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//defaultMaskFile.dat
[13:32:12.775] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C15.dat
[13:32:12.855] INFO: clk: 4
[13:32:12.855] INFO: ctr: 4
[13:32:12.855] INFO: sda: 19
[13:32:12.855] INFO: tin: 9
[13:32:12.855] INFO: level: 15
[13:32:12.855] INFO: triggerdelay: 0
[13:32:12.855] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:32:12.855] INFO: Log level: INFO
[13:32:12.872] QUIET: Connection to board DTB_WREKRL opened.
[13:32:12.875] 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:
------------------------------------------------------
[13:32:12.878] INFO: RPC call hashes of host and DTB match: 398089610
[13:32:14.403] INFO: DUT info:
[13:32:14.403] INFO: The DUT currently contains the following objects:
[13:32:14.403] INFO: 2 TBM Cores tbm08c (2 ON)
[13:32:14.403] INFO: TBM Core alpha (0): 7 registers set
[13:32:14.403] INFO: TBM Core beta (1): 7 registers set
[13:32:14.403] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:32:14.403] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.403] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.403] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.404] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:14.807] INFO: enter 'restricted' command line mode
[13:32:14.807] INFO: enter test to run
[13:32:18.898] INFO: test: PixelAlive no parameter change
[13:32:18.898] INFO: running: pixelalive
[13:32:18.907] INFO: ----------------------------------------------------------------------
[13:32:18.907] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:32:18.907] INFO: ----------------------------------------------------------------------
[13:32:19.222] INFO: Expecting 41600 events.
[13:32:23.557] INFO: 41600 events read in total (3617ms).
[13:32:23.724] INFO: Test took 4815ms.
[13:32:23.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:24.002] INFO: PixTestAlive::aliveTest() done
[13:32:24.002] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[13:32:24.033] INFO: enter test to run
[13:33:10.610] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:33:10.610] INFO: running: highrate
[13:33:10.610] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:33:10.827] INFO: ----------------------------------------------------------------------
[13:33:10.827] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:33:10.827] INFO: ----------------------------------------------------------------------
[13:33:10.827] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:33:10.827] INFO: edge/corner pixel THR is adjusted
[13:33:10.827] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:33:11.786] INFO: Collecting data for 5 seconds...
[13:33:16.802] INFO: Done with hot pixel readout
[13:33:28.582] INFO: PixTest:: pg_setup set to default.
[13:33:28.582] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:28.583] INFO: 18 hot pixels found in step 0
[13:33:29.572] INFO: Collecting data for 5 seconds...
[13:33:34.588] INFO: Done with hot pixel readout
[13:33:46.347] INFO: PixTest:: pg_setup set to default.
[13:33:46.348] INFO: 14 hot pixels found in step 1
[13:33:47.342] INFO: Collecting data for 5 seconds...
[13:33:52.358] INFO: Done with hot pixel readout
[13:34:04.134] INFO: PixTest:: pg_setup set to default.
[13:34:04.134] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:04.135] INFO: 11 hot pixels found in step 2
[13:34:05.127] INFO: Collecting data for 5 seconds...
[13:34:10.143] INFO: Done with hot pixel readout
[13:34:21.907] INFO: PixTest:: pg_setup set to default.
[13:34:21.908] INFO: 15 hot pixels found in step 3
[13:34:22.900] INFO: Collecting data for 5 seconds...
[13:34:27.916] INFO: Done with hot pixel readout
[13:34:39.669] INFO: PixTest:: pg_setup set to default.
[13:34:39.669] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:39.669] INFO: 9 hot pixels found in step 4
[13:34:40.660] INFO: Collecting data for 5 seconds...
[13:34:45.676] INFO: Done with hot pixel readout
[13:34:57.473] INFO: PixTest:: pg_setup set to default.
[13:34:57.473] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:57.474] INFO: 16 hot pixels found in step 5
[13:34:58.465] INFO: Collecting data for 5 seconds...
[13:35:03.481] INFO: Done with hot pixel readout
[13:35:15.236] INFO: PixTest:: pg_setup set to default.
[13:35:15.236] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:15.236] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:15.236] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:15.237] INFO: 7 hot pixels found in step 6
[13:35:16.229] INFO: Collecting data for 5 seconds...
[13:35:21.245] INFO: Done with hot pixel readout
[13:35:32.994] INFO: PixTest:: pg_setup set to default.
[13:35:32.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:32.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:32.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:32.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:32.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:32.995] INFO: 11 hot pixels found in step 7
[13:35:33.986] INFO: Collecting data for 5 seconds...
[13:35:39.002] INFO: Done with hot pixel readout
[13:35:50.742] INFO: PixTest:: pg_setup set to default.
[13:35:50.742] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:50.742] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:50.742] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:50.742] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:50.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:50.743] INFO: 9 hot pixels found in step 8
[13:35:51.734] INFO: Collecting data for 5 seconds...
[13:35:56.751] INFO: Done with hot pixel readout
[13:36:08.504] INFO: PixTest:: pg_setup set to default.
[13:36:08.504] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:08.504] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:08.504] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:08.505] INFO: 13 hot pixels found in step 9
[13:36:09.496] INFO: Collecting data for 5 seconds...
[13:36:14.512] INFO: Done with hot pixel readout
[13:36:26.242] INFO: PixTest:: pg_setup set to default.
[13:36:26.242] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:26.242] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:26.242] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:26.242] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:26.243] INFO: 10 hot pixels found in step 10
[13:36:27.235] INFO: Collecting data for 5 seconds...
[13:36:32.252] INFO: Done with hot pixel readout
[13:36:44.012] INFO: PixTest:: pg_setup set to default.
[13:36:44.012] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:44.013] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:44.013] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:44.014] INFO: 8 hot pixels found in step 11
[13:36:45.006] INFO: Collecting data for 5 seconds...
[13:36:50.022] INFO: Done with hot pixel readout
[13:37:01.809] INFO: PixTest:: pg_setup set to default.
[13:37:01.809] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:01.810] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:01.810] INFO: 7 hot pixels found in step 12
[13:37:02.802] INFO: Collecting data for 5 seconds...
[13:37:07.819] INFO: Done with hot pixel readout
[13:37:19.583] INFO: PixTest:: pg_setup set to default.
[13:37:19.583] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:19.583] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:19.583] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:19.584] INFO: 7 hot pixels found in step 13
[13:37:20.576] INFO: Collecting data for 5 seconds...
[13:37:25.592] INFO: Done with hot pixel readout
[13:37:37.339] INFO: PixTest:: pg_setup set to default.
[13:37:37.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:37.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:37.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:37.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:37.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:37:37.340] INFO: 8 hot pixels found in step 14
[13:37:37.375] INFO: 8 hot pixels could not be trimmed and have been masked.
[13:37:37.378] INFO: PixTest::trimHotPixels() done
[13:37:37.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C0.dat
[13:37:37.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C1.dat
[13:37:37.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C2.dat
[13:37:37.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C3.dat
[13:37:37.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C4.dat
[13:37:37.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C5.dat
[13:37:37.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C6.dat
[13:37:37.417] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C7.dat
[13:37:37.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C8.dat
[13:37:37.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C9.dat
[13:37:37.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C10.dat
[13:37:37.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C11.dat
[13:37:37.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C12.dat
[13:37:37.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C13.dat
[13:37:37.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C14.dat
[13:37:37.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C15.dat
[13:37:37.464] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//defaultMaskFile.dat
[13:37:37.474] INFO: enter test to run
[13:38:32.631] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:38:32.631] INFO: running: highrate
[13:38:32.636] INFO: ----------------------------------------------------------------------
[13:38:32.636] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:38:32.636] INFO: ----------------------------------------------------------------------
[13:38:32.636] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:38:32.636] INFO: edge/corner pixel THR is adjusted
[13:38:32.636] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:38:33.593] INFO: Collecting data for 1 seconds...
[13:38:34.596] INFO: Done with hot pixel readout
[13:38:38.581] INFO: PixTest:: pg_setup set to default.
[13:38:38.582] INFO: 0 hot pixels found in step 0
[13:38:38.587] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:38:38.678] INFO: PixTest::trimHotPixels() done
[13:38:38.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C0.dat
[13:38:38.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C1.dat
[13:38:38.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C2.dat
[13:38:38.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C3.dat
[13:38:38.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C4.dat
[13:38:38.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C5.dat
[13:38:38.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C6.dat
[13:38:38.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C7.dat
[13:38:38.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C8.dat
[13:38:38.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C9.dat
[13:38:38.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C10.dat
[13:38:38.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C11.dat
[13:38:38.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C12.dat
[13:38:38.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C13.dat
[13:38:38.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C14.dat
[13:38:38.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//trimParameters35_C15.dat
[13:38:38.767] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-30_FPIXTest-17C-FNAL-160610-1447_2016-06-10_14h47m_1465588044/000_FPIXTest_p17//defaultMaskFile.dat
[13:38:38.777] INFO: enter test to run
[13:41:54.454] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:41:54.454] INFO: running: xray
[13:41:54.455] INFO: ----------------------------------------------------------------------
[13:41:54.455] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:41:54.455] INFO: ----------------------------------------------------------------------
[13:41:55.419] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:42:06.839] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:42:36.194] INFO: Resuming triggers.
[13:42:47.614] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:43:16.967] INFO: Resuming triggers.
[13:43:28.389] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:43:57.500] INFO: Resuming triggers.
[13:44:08.919] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:44:38.225] INFO: Resuming triggers.
[13:44:49.644] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:45:18.955] INFO: Resuming triggers.
[13:45:30.377] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:45:59.796] INFO: Resuming triggers.
[13:46:11.219] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:46:40.585] INFO: Resuming triggers.
[13:46:52.003] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:47:21.447] INFO: Resuming triggers.
[13:47:30.407] INFO: data taking finished, elapsed time: 100 seconds.
[13:47:53.601] INFO: PixTest:: pg_setup set to default.
[13:47:53.604] INFO: PixTestXray::doPhRun() done
[13:47:53.740] INFO: enter test to run
[13:48:33.563] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:48:33.563] INFO: running: xray
[13:48:33.564] INFO: ----------------------------------------------------------------------
[13:48:33.564] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:48:33.564] INFO: ----------------------------------------------------------------------
[13:48:34.532] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:48:41.157] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:49:11.213] INFO: Resuming triggers.
[13:49:17.842] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:49:47.836] INFO: Resuming triggers.
[13:49:54.463] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:50:24.532] INFO: Resuming triggers.
[13:50:31.160] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:51:01.153] INFO: Resuming triggers.
[13:51:07.785] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:51:37.783] INFO: Resuming triggers.
[13:51:44.412] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:52:14.404] INFO: Resuming triggers.
[13:52:21.036] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:52:50.957] INFO: Resuming triggers.
[13:52:57.582] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[13:53:27.540] INFO: Resuming triggers.
[13:53:34.165] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:54:04.030] INFO: Resuming triggers.
[13:54:10.660] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:54:40.603] INFO: Resuming triggers.
[13:54:47.229] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:55:17.169] INFO: Resuming triggers.
[13:55:23.795] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:55:53.832] INFO: Resuming triggers.
[13:56:00.462] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:56:30.417] INFO: Resuming triggers.
[13:56:37.045] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:57:07.084] INFO: Resuming triggers.
[13:57:13.713] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:57:43.700] INFO: Resuming triggers.
[13:57:44.605] INFO: data taking finished, elapsed time: 100 seconds.
[13:57:49.034] INFO: PixTest:: pg_setup set to default.
[13:57:49.037] INFO: PixTestXray::doPhRun() done
[13:57:49.187] INFO: enter test to run
[13:58:29.751] INFO: test: HighRate no parameter change
[13:58:29.751] INFO: running: highrate
[13:58:29.753] INFO: ----------------------------------------------------------------------
[13:58:29.753] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:58:29.753] INFO: ----------------------------------------------------------------------
[13:58:29.893] INFO: Expecting 768 events.
[13:58:31.026] INFO: 768 events read in total (417ms).
[13:58:31.027] INFO: Test took 1268ms.
[13:58:31.830] INFO: Expecting 41600 events.
[13:58:34.889] INFO: 41600 events read in total (2532ms).
[13:58:34.891] INFO: Test took 3856ms.
[13:58:34.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:35.649] INFO: Expecting 41600 events.
[13:58:38.842] INFO: 41600 events read in total (2666ms).
[13:58:38.843] INFO: Test took 3901ms.
[13:58:38.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:39.600] INFO: Expecting 41600 events.
[13:58:42.850] INFO: 41600 events read in total (2723ms).
[13:58:42.851] INFO: Test took 3955ms.
[13:58:42.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:43.605] INFO: Expecting 41600 events.
[13:58:46.848] INFO: 41600 events read in total (2716ms).
[13:58:46.849] INFO: Test took 3947ms.
[13:58:46.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:47.606] INFO: Expecting 41600 events.
[13:58:50.847] INFO: 41600 events read in total (2715ms).
[13:58:50.848] INFO: Test took 3947ms.
[13:58:50.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:51.608] INFO: Expecting 41600 events.
[13:58:54.866] INFO: 41600 events read in total (2732ms).
[13:58:54.867] INFO: Test took 3966ms.
[13:58:54.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:55.626] INFO: Expecting 41600 events.
[13:58:58.885] INFO: 41600 events read in total (2732ms).
[13:58:58.886] INFO: Test took 3968ms.
[13:58:58.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:59.645] INFO: Expecting 41600 events.
[13:59:02.902] INFO: 41600 events read in total (2730ms).
[13:59:02.903] INFO: Test took 3965ms.
[13:59:02.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:03.656] INFO: Expecting 41600 events.
[13:59:06.900] INFO: 41600 events read in total (2717ms).
[13:59:06.900] INFO: Test took 3944ms.
[13:59:06.935] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:07.657] INFO: Expecting 41600 events.
[13:59:10.919] INFO: 41600 events read in total (2735ms).
[13:59:10.920] INFO: Test took 3966ms.
[13:59:10.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:11.677] INFO: Expecting 41600 events.
[13:59:14.939] INFO: 41600 events read in total (2735ms).
[13:59:14.940] INFO: Test took 3966ms.
[13:59:14.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:15.697] INFO: Expecting 41600 events.
[13:59:18.939] INFO: 41600 events read in total (2715ms).
[13:59:18.940] INFO: Test took 3948ms.
[13:59:18.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:19.699] INFO: Expecting 41600 events.
[13:59:22.966] INFO: 41600 events read in total (2740ms).
[13:59:22.967] INFO: Test took 3974ms.
[13:59:23.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:23.721] INFO: Expecting 41600 events.
[13:59:26.975] INFO: 41600 events read in total (2727ms).
[13:59:26.976] INFO: Test took 3955ms.
[13:59:27.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:27.732] INFO: Expecting 41600 events.
[13:59:30.974] INFO: 41600 events read in total (2715ms).
[13:59:30.975] INFO: Test took 3946ms.
[13:59:31.009] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:31.733] INFO: Expecting 41600 events.
[13:59:34.983] INFO: 41600 events read in total (2723ms).
[13:59:34.984] INFO: Test took 3957ms.
[13:59:35.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:35.744] INFO: Expecting 41600 events.
[13:59:38.999] INFO: 41600 events read in total (2728ms).
[13:59:38.000] INFO: Test took 3964ms.
[13:59:39.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:39.756] INFO: Expecting 41600 events.
[13:59:42.999] INFO: 41600 events read in total (2717ms).
[13:59:42.000] INFO: Test took 3948ms.
[13:59:43.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:43.761] INFO: Expecting 41600 events.
[13:59:47.002] INFO: 41600 events read in total (2715ms).
[13:59:47.003] INFO: Test took 3951ms.
[13:59:47.038] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:47.757] INFO: Expecting 41600 events.
[13:59:50.887] INFO: 41600 events read in total (2603ms).
[13:59:50.888] INFO: Test took 3833ms.
[13:59:50.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:51.278] INFO: enter test to run
[14:01:00.294] INFO: test: HighRate no parameter change
[14:01:00.294] INFO: running: highrate
[14:01:00.295] INFO: ----------------------------------------------------------------------
[14:01:00.296] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:01:00.296] INFO: ----------------------------------------------------------------------
[14:01:00.914] INFO: Expecting 208000 events.
[14:01:12.878] INFO: 208000 events read in total (11437ms).
[14:01:12.881] INFO: Test took 12577ms.
[14:01:13.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:13.282] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:01:13.282] INFO: number of red-efficiency pixels: 69 68 71 131 166 154 159 124 109 118 113 99 107 56 27 40
[14:01:13.282] INFO: number of X-ray hits detected: 68613 44661 65457 109897 118617 118564 122271 87469 79579 100458 95933 81093 83830 50655 22662 26286
[14:01:13.282] 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:01:13.282] INFO: number of Vcal hits detected: 207929 207929 207925 207866 207829 207845 207839 207870 207890 207882 207884 207848 207890 207941 207973 207960
[14:01:13.282] 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:01:13.282] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:01:13.282] INFO: X-ray hit rate [MHz/cm2]: 20.1 13.1 19.2 32.2 34.8 34.8 35.8 25.6 23.3 29.4 28.1 23.8 24.6 14.8 6.6 7.7
[14:01:13.282] INFO: PixTestHighRate::doXPixelAlive() done
[14:01:13.327] INFO: PixTest:: pg_setup set to default.
[14:01:13.344] INFO: enter test to run
[14:07:19.660] INFO: test: HighRate no parameter change
[14:07:19.660] INFO: running: highrate
[14:07:19.661] INFO: ----------------------------------------------------------------------
[14:07:19.661] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:07:19.661] INFO: ----------------------------------------------------------------------
[14:07:20.276] INFO: Expecting 208000 events.
[14:07:33.995] INFO: 208000 events read in total (13192ms).
[14:07:33.001] INFO: Test took 14330ms.
[14:07:34.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:34.606] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:07:34.606] INFO: number of red-efficiency pixels: 205 139 275 381 500 429 519 385 206 340 268 312 293 172 59 77
[14:07:34.606] INFO: number of X-ray hits detected: 140395 93264 134087 224733 241439 243607 250131 179129 164087 206622 195851 167206 172394 104707 46677 53872
[14:07:34.606] 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:07:34.606] INFO: number of Vcal hits detected: 207788 207851 207697 207590 207444 207538 207428 207578 207783 207642 207713 207621 207698 207816 207937 207920
[14:07:34.606] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:07:34.606] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.9 99.8 99.9 99.9 100.0 100.0
[14:07:34.606] INFO: X-ray hit rate [MHz/cm2]: 41.2 27.3 39.3 65.9 70.8 71.4 73.3 52.5 48.1 60.6 57.4 49.0 50.5 30.7 13.7 15.8
[14:07:34.607] INFO: PixTestHighRate::doXPixelAlive() done
[14:07:34.651] INFO: PixTest:: pg_setup set to default.
[14:07:34.670] INFO: enter test to run
[14:11:05.042] INFO: test: HighRate no parameter change
[14:11:05.042] INFO: running: highrate
[14:11:05.043] INFO: ----------------------------------------------------------------------
[14:11:05.043] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:11:05.043] INFO: ----------------------------------------------------------------------
[14:11:05.659] INFO: Expecting 208000 events.
[14:11:21.256] INFO: 208000 events read in total (15070ms).
[14:11:21.264] INFO: Test took 16211ms.
[14:11:21.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:22.057] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[14:11:22.057] INFO: number of red-efficiency pixels: 432 313 633 820 1113 1060 1158 815 512 702 635 616 647 392 97 129
[14:11:22.057] INFO: number of X-ray hits detected: 209791 138868 199717 336205 360091 365306 374968 267186 245053 309061 293109 249504 257386 155609 70094 81167
[14:11:22.057] 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:11:22.057] INFO: number of Vcal hits detected: 207508 207655 207179 207037 206634 206675 206481 206926 207427 207196 207281 207235 207266 207554 207902 207868
[14:11:22.057] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.6 99.4 99.4 99.4 99.5 99.7 99.7 99.7 99.7 99.7 99.8 100.0 99.9
[14:11:22.057] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.6 99.5 99.3 99.4 99.3 99.5 99.7 99.6 99.7 99.6 99.6 99.8 100.0 99.9
[14:11:22.057] INFO: X-ray hit rate [MHz/cm2]: 61.5 40.7 58.5 98.5 105.5 107.1 109.9 78.3 71.8 90.6 85.9 73.1 75.4 45.6 20.5 23.8
[14:11:22.057] INFO: PixTestHighRate::doXPixelAlive() done
[14:11:22.109] INFO: PixTest:: pg_setup set to default.
[14:11:22.124] INFO: enter test to run
[14:11:42.938] INFO: test: exit no parameter change
[14:11:43.297] QUIET: Connection to board 33 closed.
[14:11:43.298] INFO: pXar: this is the end, my friend