[15:21:00.412] INFO: *** Welcome to pxar ***
[15:21:00.412] INFO: *** Today: 2016/07/01
[15:21:00.748] INFO: *** Version: v1.9.0-814-g7497
[15:21:00.748] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C15.dat
[15:21:00.769] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:21:00.769] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[15:21:00.776] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[15:21:00.897] INFO: clk: 4
[15:21:00.897] INFO: ctr: 4
[15:21:00.897] INFO: sda: 19
[15:21:00.897] INFO: tin: 9
[15:21:00.897] INFO: level: 15
[15:21:00.897] INFO: triggerdelay: 0
[15:21:00.897] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:21:00.897] INFO: Log level: INFO
[15:21:00.915] QUIET: Connection to board DTB_WREKRL opened.
[15:21:00.918] 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:
------------------------------------------------------
[15:21:00.921] INFO: RPC call hashes of host and DTB match: 398089610
[15:21:02.456] INFO: DUT info:
[15:21:02.456] INFO: The DUT currently contains the following objects:
[15:21:02.456] INFO: 2 TBM Cores tbm08c (2 ON)
[15:21:02.456] INFO: TBM Core alpha (0): 7 registers set
[15:21:02.456] INFO: TBM Core beta (1): 7 registers set
[15:21:02.456] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:21:02.456] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.456] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.457] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.457] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.457] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.457] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.457] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:21:02.860] INFO: enter 'restricted' command line mode
[15:21:02.860] INFO: enter test to run
[15:21:04.202] INFO: test: PixelAlive no parameter change
[15:21:04.202] INFO: running: pixelalive
[15:21:04.211] INFO: ----------------------------------------------------------------------
[15:21:04.211] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:21:04.211] INFO: ----------------------------------------------------------------------
[15:21:04.531] INFO: Expecting 41600 events.
[15:21:08.871] INFO: 41600 events read in total (3621ms).
[15:21:09.040] INFO: Test took 4827ms.
[15:21:09.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:09.317] INFO: PixTestAlive::aliveTest() done
[15:21:09.317] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:21:09.347] INFO: enter test to run
[15:21:44.090] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:21:44.090] INFO: running: highrate
[15:21:44.090] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:21:44.305] INFO: ----------------------------------------------------------------------
[15:21:44.305] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:21:44.305] INFO: ----------------------------------------------------------------------
[15:21:44.305] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:21:44.305] INFO: edge/corner pixel THR is adjusted
[15:21:44.305] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:21:45.263] INFO: Collecting data for 5 seconds...
[15:21:50.283] INFO: Done with hot pixel readout
[15:22:02.048] INFO: PixTest:: pg_setup set to default.
[15:22:02.048] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:22:02.049] INFO: 21 hot pixels found in step 0
[15:22:03.037] INFO: Collecting data for 5 seconds...
[15:22:08.055] INFO: Done with hot pixel readout
[15:22:19.618] INFO: PixTest:: pg_setup set to default.
[15:22:19.619] INFO: 20 hot pixels found in step 1
[15:22:20.613] INFO: Collecting data for 5 seconds...
[15:22:25.632] INFO: Done with hot pixel readout
[15:22:37.268] INFO: PixTest:: pg_setup set to default.
[15:22:37.269] INFO: 20 hot pixels found in step 2
[15:22:38.261] INFO: Collecting data for 5 seconds...
[15:22:43.282] INFO: Done with hot pixel readout
[15:22:55.039] INFO: PixTest:: pg_setup set to default.
[15:22:55.040] INFO: 21 hot pixels found in step 3
[15:22:56.034] INFO: Collecting data for 5 seconds...
[15:23:01.053] INFO: Done with hot pixel readout
[15:23:12.802] INFO: PixTest:: pg_setup set to default.
[15:23:12.803] INFO: 16 hot pixels found in step 4
[15:23:13.795] INFO: Collecting data for 5 seconds...
[15:23:18.815] INFO: Done with hot pixel readout
[15:23:30.550] INFO: PixTest:: pg_setup set to default.
[15:23:30.550] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:23:30.551] INFO: 16 hot pixels found in step 5
[15:23:31.543] INFO: Collecting data for 5 seconds...
[15:23:36.562] INFO: Done with hot pixel readout
[15:23:48.435] INFO: PixTest:: pg_setup set to default.
[15:23:48.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:23:48.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:23:48.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:23:48.436] INFO: 14 hot pixels found in step 6
[15:23:49.429] INFO: Collecting data for 5 seconds...
[15:23:54.448] INFO: Done with hot pixel readout
[15:24:06.563] INFO: PixTest:: pg_setup set to default.
[15:24:06.563] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:06.563] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:06.563] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:06.563] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:06.564] INFO: 13 hot pixels found in step 7
[15:24:07.556] INFO: Collecting data for 5 seconds...
[15:24:12.577] INFO: Done with hot pixel readout
[15:24:24.639] INFO: PixTest:: pg_setup set to default.
[15:24:24.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:24.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:24.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:24.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:24.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:24.640] INFO: 13 hot pixels found in step 8
[15:24:25.632] INFO: Collecting data for 5 seconds...
[15:24:30.652] INFO: Done with hot pixel readout
[15:24:42.603] INFO: PixTest:: pg_setup set to default.
[15:24:42.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:42.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:42.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:24:42.604] INFO: 9 hot pixels found in step 9
[15:24:43.597] INFO: Collecting data for 5 seconds...
[15:24:48.617] INFO: Done with hot pixel readout
[15:25:00.604] INFO: PixTest:: pg_setup set to default.
[15:25:00.604] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:00.604] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:00.604] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:00.604] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:00.605] INFO: 11 hot pixels found in step 10
[15:25:01.597] INFO: Collecting data for 5 seconds...
[15:25:06.617] INFO: Done with hot pixel readout
[15:25:18.686] INFO: PixTest:: pg_setup set to default.
[15:25:18.686] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:18.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:18.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:18.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:18.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:18.687] INFO: 14 hot pixels found in step 11
[15:25:19.680] INFO: Collecting data for 5 seconds...
[15:25:24.700] INFO: Done with hot pixel readout
[15:25:36.795] INFO: PixTest:: pg_setup set to default.
[15:25:36.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:36.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:36.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:36.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:36.796] INFO: 9 hot pixels found in step 12
[15:25:37.788] INFO: Collecting data for 5 seconds...
[15:25:42.808] INFO: Done with hot pixel readout
[15:25:54.637] INFO: PixTest:: pg_setup set to default.
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:54.638] INFO: 12 hot pixels found in step 13
[15:25:55.630] INFO: Collecting data for 5 seconds...
[15:26:00.647] INFO: Done with hot pixel readout
[15:26:12.435] INFO: PixTest:: pg_setup set to default.
[15:26:12.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:12.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:12.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:12.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:12.436] INFO: 6 hot pixels found in step 14
[15:26:12.472] INFO: 6 hot pixels could not be trimmed and have been masked.
[15:26:12.476] INFO: PixTest::trimHotPixels() done
[15:26:12.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[15:26:12.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[15:26:12.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[15:26:12.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[15:26:12.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[15:26:12.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[15:26:12.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[15:26:12.514] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[15:26:12.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[15:26:12.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[15:26:12.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[15:26:12.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[15:26:12.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[15:26:12.577] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[15:26:12.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[15:26:12.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[15:26:12.594] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[15:26:12.612] INFO: enter test to run
[15:28:43.479] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:28:43.479] INFO: running: highrate
[15:28:43.484] INFO: ----------------------------------------------------------------------
[15:28:43.484] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:28:43.484] INFO: ----------------------------------------------------------------------
[15:28:43.484] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:28:43.484] INFO: edge/corner pixel THR is adjusted
[15:28:43.484] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:28:44.443] INFO: Collecting data for 1 seconds...
[15:28:45.447] INFO: Done with hot pixel readout
[15:28:49.430] INFO: PixTest:: pg_setup set to default.
[15:28:49.431] INFO: 0 hot pixels found in step 0
[15:28:49.436] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:28:49.531] INFO: PixTest::trimHotPixels() done
[15:28:49.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[15:28:49.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[15:28:49.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[15:28:49.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[15:28:49.555] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[15:28:49.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[15:28:49.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[15:28:49.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[15:28:49.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[15:28:49.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[15:28:49.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[15:28:49.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[15:28:49.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[15:28:49.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[15:28:49.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[15:28:49.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[15:28:49.618] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-09_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[15:28:49.628] INFO: enter test to run
[15:29:10.087] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:29:10.087] INFO: running: xray
[15:29:10.088] INFO: ----------------------------------------------------------------------
[15:29:10.088] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:29:10.088] INFO: ----------------------------------------------------------------------
[15:29:11.051] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:29:22.622] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:29:51.865] INFO: Resuming triggers.
[15:30:03.434] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:30:32.849] INFO: Resuming triggers.
[15:30:44.418] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:31:13.704] INFO: Resuming triggers.
[15:31:25.276] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:31:54.615] INFO: Resuming triggers.
[15:32:06.183] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:32:35.522] INFO: Resuming triggers.
[15:32:47.096] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:33:16.511] INFO: Resuming triggers.
[15:33:28.082] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:33:57.878] INFO: Resuming triggers.
[15:34:09.448] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:34:39.048] INFO: Resuming triggers.
[15:34:46.840] INFO: data taking finished, elapsed time: 100 seconds.
[15:35:07.013] INFO: PixTest:: pg_setup set to default.
[15:35:07.017] INFO: PixTestXray::doPhRun() done
[15:35:07.156] INFO: enter test to run
[15:37:12.459] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:37:12.459] INFO: running: xray
[15:37:12.460] INFO: ----------------------------------------------------------------------
[15:37:12.461] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:37:12.461] INFO: ----------------------------------------------------------------------
[15:37:13.423] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:37:20.300] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:37:50.877] INFO: Resuming triggers.
[15:37:57.758] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:38:27.908] INFO: Resuming triggers.
[15:38:34.789] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:39:04.916] INFO: Resuming triggers.
[15:39:11.797] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:39:41.968] INFO: Resuming triggers.
[15:39:48.852] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:40:18.973] INFO: Resuming triggers.
[15:40:25.855] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:40:55.953] INFO: Resuming triggers.
[15:41:02.836] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:41:32.751] INFO: Resuming triggers.
[15:41:39.634] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[15:42:09.761] INFO: Resuming triggers.
[15:42:16.645] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:42:46.821] INFO: Resuming triggers.
[15:42:53.703] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:43:23.790] INFO: Resuming triggers.
[15:43:30.673] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[15:44:00.838] INFO: Resuming triggers.
[15:44:07.716] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:44:37.894] INFO: Resuming triggers.
[15:44:44.775] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:45:14.929] INFO: Resuming triggers.
[15:45:21.808] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:45:52.819] INFO: Resuming triggers.
[15:45:56.836] INFO: data taking finished, elapsed time: 100 seconds.
[15:46:14.995] INFO: PixTest:: pg_setup set to default.
[15:46:14.998] INFO: PixTestXray::doPhRun() done
[15:46:15.150] INFO: enter test to run
[15:55:23.268] INFO: test: HighRate no parameter change
[15:55:23.268] INFO: running: highrate
[15:55:23.282] INFO: ----------------------------------------------------------------------
[15:55:23.282] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:55:23.282] INFO: ----------------------------------------------------------------------
[15:55:23.437] INFO: Expecting 768 events.
[15:55:24.571] INFO: 768 events read in total (418ms).
[15:55:24.571] INFO: Test took 1268ms.
[15:55:25.374] INFO: Expecting 41600 events.
[15:55:28.433] INFO: 41600 events read in total (2532ms).
[15:55:28.434] INFO: Test took 3802ms.
[15:55:28.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:29.195] INFO: Expecting 41600 events.
[15:55:32.373] INFO: 41600 events read in total (2651ms).
[15:55:32.374] INFO: Test took 3890ms.
[15:55:32.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:33.130] INFO: Expecting 41600 events.
[15:55:36.372] INFO: 41600 events read in total (2715ms).
[15:55:36.373] INFO: Test took 3948ms.
[15:55:36.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:37.132] INFO: Expecting 41600 events.
[15:55:40.380] INFO: 41600 events read in total (2721ms).
[15:55:40.381] INFO: Test took 3955ms.
[15:55:40.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:41.141] INFO: Expecting 41600 events.
[15:55:44.376] INFO: 41600 events read in total (2708ms).
[15:55:44.377] INFO: Test took 3946ms.
[15:55:44.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:45.137] INFO: Expecting 41600 events.
[15:55:48.382] INFO: 41600 events read in total (2719ms).
[15:55:48.383] INFO: Test took 3955ms.
[15:55:48.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:49.141] INFO: Expecting 41600 events.
[15:55:52.394] INFO: 41600 events read in total (2726ms).
[15:55:52.395] INFO: Test took 3959ms.
[15:55:52.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:53.155] INFO: Expecting 41600 events.
[15:55:56.401] INFO: 41600 events read in total (2719ms).
[15:55:56.402] INFO: Test took 3957ms.
[15:55:56.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:57.161] INFO: Expecting 41600 events.
[15:56:00.395] INFO: 41600 events read in total (2707ms).
[15:56:00.396] INFO: Test took 3942ms.
[15:56:00.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:01.155] INFO: Expecting 41600 events.
[15:56:04.404] INFO: 41600 events read in total (2722ms).
[15:56:04.405] INFO: Test took 3958ms.
[15:56:04.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:05.164] INFO: Expecting 41600 events.
[15:56:08.411] INFO: 41600 events read in total (2720ms).
[15:56:08.412] INFO: Test took 3955ms.
[15:56:08.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:09.171] INFO: Expecting 41600 events.
[15:56:12.409] INFO: 41600 events read in total (2711ms).
[15:56:12.410] INFO: Test took 3947ms.
[15:56:12.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:13.169] INFO: Expecting 41600 events.
[15:56:16.428] INFO: 41600 events read in total (2732ms).
[15:56:16.429] INFO: Test took 3969ms.
[15:56:16.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:17.187] INFO: Expecting 41600 events.
[15:56:20.445] INFO: 41600 events read in total (2731ms).
[15:56:20.446] INFO: Test took 3965ms.
[15:56:20.479] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:21.203] INFO: Expecting 41600 events.
[15:56:24.454] INFO: 41600 events read in total (2725ms).
[15:56:24.455] INFO: Test took 3957ms.
[15:56:24.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:25.210] INFO: Expecting 41600 events.
[15:56:28.476] INFO: 41600 events read in total (2739ms).
[15:56:28.477] INFO: Test took 3971ms.
[15:56:28.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:29.237] INFO: Expecting 41600 events.
[15:56:32.485] INFO: 41600 events read in total (2722ms).
[15:56:32.486] INFO: Test took 3957ms.
[15:56:32.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:33.245] INFO: Expecting 41600 events.
[15:56:36.507] INFO: 41600 events read in total (2735ms).
[15:56:36.508] INFO: Test took 3970ms.
[15:56:36.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:37.268] INFO: Expecting 41600 events.
[15:56:40.502] INFO: 41600 events read in total (2707ms).
[15:56:40.504] INFO: Test took 3946ms.
[15:56:40.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:41.265] INFO: Expecting 41600 events.
[15:56:44.432] INFO: 41600 events read in total (2640ms).
[15:56:44.433] INFO: Test took 3872ms.
[15:56:44.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:44.822] INFO: enter test to run
[15:58:26.931] INFO: test: HighRate no parameter change
[15:58:26.931] INFO: running: highrate
[15:58:26.932] INFO: ----------------------------------------------------------------------
[15:58:26.932] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:58:26.932] INFO: ----------------------------------------------------------------------
[15:58:27.550] INFO: Expecting 208000 events.
[15:58:39.306] INFO: 208000 events read in total (11229ms).
[15:58:39.309] INFO: Test took 12367ms.
[15:58:39.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:39.708] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:58:39.708] INFO: number of red-efficiency pixels: 105 47 96 158 149 142 127 92 75 112 122 85 116 85 26 22
[15:58:39.708] INFO: number of X-ray hits detected: 73122 44016 67620 101385 110421 113407 110451 79468 78106 91720 91761 79458 85842 52363 21196 22950
[15:58:39.708] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:58:39.708] INFO: number of Vcal hits detected: 207889 207951 207902 207838 207842 207856 207871 207906 207925 207885 207873 207914 207883 207913 207974 207929
[15:58:39.708] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:58:39.708] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[15:58:39.708] INFO: X-ray hit rate [MHz/cm2]: 21.4 12.9 19.8 29.7 32.4 33.2 32.4 23.3 22.9 26.9 26.9 23.3 25.2 15.3 6.2 6.7
[15:58:39.708] INFO: PixTestHighRate::doXPixelAlive() done
[15:58:39.753] INFO: PixTest:: pg_setup set to default.
[15:58:39.763] INFO: enter test to run
[16:00:04.202] INFO: test: HighRate no parameter change
[16:00:04.202] INFO: running: highrate
[16:00:04.203] INFO: ----------------------------------------------------------------------
[16:00:04.203] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:00:04.203] INFO: ----------------------------------------------------------------------
[16:00:04.825] INFO: Expecting 208000 events.
[16:00:18.688] INFO: 208000 events read in total (13337ms).
[16:00:18.693] INFO: Test took 14478ms.
[16:00:18.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:19.280] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[16:00:19.280] INFO: number of red-efficiency pixels: 283 108 301 418 526 520 501 270 227 329 355 240 305 173 37 55
[16:00:19.280] INFO: number of X-ray hits detected: 147782 89143 136900 204908 224135 231241 223510 161892 156937 188096 186032 162387 174694 107376 43225 45835
[16:00:19.280] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:00:19.280] INFO: number of Vcal hits detected: 207688 207890 207674 207545 207425 207411 207464 207717 207759 207650 207616 207743 207673 207821 207963 207896
[16:00:19.280] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[16:00:19.280] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[16:00:19.280] INFO: X-ray hit rate [MHz/cm2]: 43.3 26.1 40.1 60.1 65.7 67.8 65.5 47.5 46.0 55.1 54.5 47.6 51.2 31.5 12.7 13.4
[16:00:19.280] INFO: PixTestHighRate::doXPixelAlive() done
[16:00:19.324] INFO: PixTest:: pg_setup set to default.
[16:00:19.337] INFO: enter test to run
[16:01:42.401] INFO: test: HighRate no parameter change
[16:01:42.401] INFO: running: highrate
[16:01:42.403] INFO: ----------------------------------------------------------------------
[16:01:42.403] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:01:42.403] INFO: ----------------------------------------------------------------------
[16:01:43.022] INFO: Expecting 208000 events.
[16:01:58.241] INFO: 208000 events read in total (14692ms).
[16:01:58.248] INFO: Test took 15835ms.
[16:01:58.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:59.016] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[16:01:59.016] INFO: number of red-efficiency pixels: 632 245 659 980 1166 1218 1138 573 522 830 799 503 685 428 94 84
[16:01:59.016] INFO: number of X-ray hits detected: 221144 134296 206633 307850 334699 347545 335747 243244 235850 280944 280058 244385 262316 160242 64935 69974
[16:01:59.016] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:01:59.016] INFO: number of Vcal hits detected: 207157 207738 207115 206786 206574 206357 206562 207359 207430 207049 207065 207428 207230 207489 207904 207862
[16:01:59.016] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.5 99.4 99.3 99.4 99.7 99.7 99.6 99.6 99.8 99.7 99.8 100.0 100.0
[16:01:59.016] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.6 99.4 99.3 99.2 99.3 99.7 99.7 99.5 99.6 99.7 99.6 99.8 100.0 99.9
[16:01:59.016] INFO: X-ray hit rate [MHz/cm2]: 64.8 39.4 60.6 90.2 98.1 101.9 98.4 71.3 69.1 82.3 82.1 71.6 76.9 47.0 19.0 20.5
[16:01:59.016] INFO: PixTestHighRate::doXPixelAlive() done
[16:01:59.071] INFO: PixTest:: pg_setup set to default.
[16:01:59.091] INFO: enter test to run
[16:05:38.007] INFO: test: exit no parameter change
[16:05:38.350] QUIET: Connection to board 33 closed.
[16:05:38.352] INFO: pXar: this is the end, my friend