[18:11:07.775] INFO: *** Welcome to pxar ***
[18:11:07.775] INFO: *** Today: 2016/06/06
[18:11:07.793] INFO: *** Version: v1.9.0-814-g7497
[18:11:07.793] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//dacParameters35_C15.dat
[18:11:07.832] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:11:07.832] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[18:11:07.833] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[18:11:07.942] INFO: clk: 4
[18:11:07.943] INFO: ctr: 4
[18:11:07.943] INFO: sda: 19
[18:11:07.943] INFO: tin: 9
[18:11:07.943] INFO: level: 15
[18:11:07.943] INFO: triggerdelay: 0
[18:11:07.943] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:11:07.943] INFO: Log level: INFO
[18:11:07.961] QUIET: Connection to board DTB_WREK4U opened.
[18:11:07.965] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[18:11:07.967] INFO: RPC call hashes of host and DTB match: 398089610
[18:11:09.497] INFO: DUT info:
[18:11:09.497] INFO: The DUT currently contains the following objects:
[18:11:09.497] INFO: 2 TBM Cores tbm08c (2 ON)
[18:11:09.497] INFO: TBM Core alpha (0): 7 registers set
[18:11:09.497] INFO: TBM Core beta (1): 7 registers set
[18:11:09.497] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:11:09.497] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.497] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.497] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.497] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.497] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.498] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:11:09.919] INFO: enter 'restricted' command line mode
[18:11:09.919] INFO: enter test to run
[18:11:13.660] INFO: test: PixelAlive no parameter change
[18:11:13.660] INFO: running: pixelalive
[18:11:13.670] INFO: ----------------------------------------------------------------------
[18:11:13.670] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:11:13.670] INFO: ----------------------------------------------------------------------
[18:11:13.994] INFO: Expecting 41600 events.
[18:11:18.332] INFO: 41600 events read in total (3619ms).
[18:11:18.497] INFO: Test took 4823ms.
[18:11:18.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:18.769] INFO: PixTestAlive::aliveTest() done
[18:11:18.769] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0
[18:11:18.798] INFO: enter test to run
[18:12:47.260] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:12:47.260] INFO: running: highrate
[18:12:47.260] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:12:47.475] INFO: ----------------------------------------------------------------------
[18:12:47.475] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:12:47.475] INFO: ----------------------------------------------------------------------
[18:12:47.475] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:12:47.475] INFO: edge/corner pixel THR is adjusted
[18:12:47.475] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:12:48.435] INFO: Collecting data for 5 seconds...
[18:12:53.451] INFO: Done with hot pixel readout
[18:13:06.092] INFO: PixTest:: pg_setup set to default.
[18:13:06.092] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:06.093] INFO: 52 hot pixels found in step 0
[18:13:07.113] INFO: Collecting data for 5 seconds...
[18:13:12.129] INFO: Done with hot pixel readout
[18:13:24.709] INFO: PixTest:: pg_setup set to default.
[18:13:24.709] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:24.709] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:24.709] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:24.710] INFO: 42 hot pixels found in step 1
[18:13:25.704] INFO: Collecting data for 5 seconds...
[18:13:30.720] INFO: Done with hot pixel readout
[18:13:43.330] INFO: PixTest:: pg_setup set to default.
[18:13:43.331] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:43.331] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:13:43.331] INFO: 52 hot pixels found in step 2
[18:13:44.326] INFO: Collecting data for 5 seconds...
[18:13:49.342] INFO: Done with hot pixel readout
[18:14:02.049] INFO: PixTest:: pg_setup set to default.
[18:14:02.050] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:02.050] INFO: 53 hot pixels found in step 3
[18:14:03.044] INFO: Collecting data for 5 seconds...
[18:14:08.064] INFO: Done with hot pixel readout
[18:14:20.619] INFO: PixTest:: pg_setup set to default.
[18:14:20.619] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:20.620] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:20.620] INFO: 42 hot pixels found in step 4
[18:14:21.614] INFO: Collecting data for 5 seconds...
[18:14:26.632] INFO: Done with hot pixel readout
[18:14:39.304] INFO: PixTest:: pg_setup set to default.
[18:14:39.305] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:39.305] INFO: 38 hot pixels found in step 5
[18:14:40.299] INFO: Collecting data for 5 seconds...
[18:14:45.318] INFO: Done with hot pixel readout
[18:14:57.862] INFO: PixTest:: pg_setup set to default.
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.862] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:14:57.863] INFO: 44 hot pixels found in step 6
[18:14:58.856] INFO: Collecting data for 5 seconds...
[18:15:03.876] INFO: Done with hot pixel readout
[18:15:16.233] INFO: PixTest:: pg_setup set to default.
[18:15:16.233] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:16.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:16.235] INFO: 32 hot pixels found in step 7
[18:15:17.228] INFO: Collecting data for 5 seconds...
[18:15:22.247] INFO: Done with hot pixel readout
[18:15:34.704] INFO: PixTest:: pg_setup set to default.
[18:15:34.704] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:34.704] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:34.705] INFO: 35 hot pixels found in step 8
[18:15:35.698] INFO: Collecting data for 5 seconds...
[18:15:40.718] INFO: Done with hot pixel readout
[18:15:53.621] INFO: PixTest:: pg_setup set to default.
[18:15:53.622] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:53.622] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:53.622] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:15:53.622] INFO: 34 hot pixels found in step 9
[18:15:54.617] INFO: Collecting data for 5 seconds...
[18:15:59.638] INFO: Done with hot pixel readout
[18:16:12.578] INFO: PixTest:: pg_setup set to default.
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:12.579] INFO: 37 hot pixels found in step 10
[18:16:13.572] INFO: Collecting data for 5 seconds...
[18:16:18.591] INFO: Done with hot pixel readout
[18:16:31.638] INFO: PixTest:: pg_setup set to default.
[18:16:31.638] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.638] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.638] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.638] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.639] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:31.639] INFO: 35 hot pixels found in step 11
[18:16:32.633] INFO: Collecting data for 5 seconds...
[18:16:37.651] INFO: Done with hot pixel readout
[18:16:50.439] INFO: PixTest:: pg_setup set to default.
[18:16:50.439] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:16:50.440] INFO: 27 hot pixels found in step 12
[18:16:51.435] INFO: Collecting data for 5 seconds...
[18:16:56.453] INFO: Done with hot pixel readout
[18:17:09.200] INFO: PixTest:: pg_setup set to default.
[18:17:09.200] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:09.201] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:09.201] INFO: 25 hot pixels found in step 13
[18:17:10.195] INFO: Collecting data for 5 seconds...
[18:17:15.214] INFO: Done with hot pixel readout
[18:17:28.117] INFO: PixTest:: pg_setup set to default.
[18:17:28.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:28.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:28.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:28.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:17:28.118] INFO: 32 hot pixels found in step 14
[18:17:28.156] INFO: 32 hot pixels could not be trimmed and have been masked.
[18:17:28.160] INFO: PixTest::trimHotPixels() done
[18:17:28.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat
[18:17:28.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C1.dat
[18:17:28.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C2.dat
[18:17:28.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C3.dat
[18:17:28.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C4.dat
[18:17:28.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C5.dat
[18:17:28.211] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C6.dat
[18:17:28.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C7.dat
[18:17:28.222] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C8.dat
[18:17:28.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C9.dat
[18:17:28.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C10.dat
[18:17:28.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C11.dat
[18:17:28.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C12.dat
[18:17:28.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C13.dat
[18:17:28.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C14.dat
[18:17:28.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[18:17:28.266] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[18:17:28.278] INFO: enter test to run
[18:18:11.737] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:18:11.737] INFO: running: highrate
[18:18:11.742] INFO: ----------------------------------------------------------------------
[18:18:11.742] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:18:11.742] INFO: ----------------------------------------------------------------------
[18:18:11.742] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:18:11.742] INFO: edge/corner pixel THR is adjusted
[18:18:11.742] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:18:12.706] INFO: Collecting data for 1 seconds...
[18:18:13.709] INFO: Done with hot pixel readout
[18:18:18.207] INFO: PixTest:: pg_setup set to default.
[18:18:18.208] INFO: 0 hot pixels found in step 0
[18:18:18.215] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:18:18.286] INFO: PixTest::trimHotPixels() done
[18:18:18.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat
[18:18:18.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C1.dat
[18:18:18.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C2.dat
[18:18:18.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C3.dat
[18:18:18.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C4.dat
[18:18:18.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C5.dat
[18:18:18.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C6.dat
[18:18:18.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C7.dat
[18:18:18.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C8.dat
[18:18:18.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C9.dat
[18:18:18.345] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C10.dat
[18:18:18.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C11.dat
[18:18:18.355] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C12.dat
[18:18:18.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C13.dat
[18:18:18.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C14.dat
[18:18:18.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[18:18:18.376] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NT_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[18:18:18.386] INFO: enter test to run
[18:18:48.633] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:18:48.633] INFO: running: xray
[18:18:48.634] INFO: ----------------------------------------------------------------------
[18:18:48.634] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:18:48.634] INFO: ----------------------------------------------------------------------
[18:18:49.598] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:18:59.907] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[18:19:29.446] INFO: Resuming triggers.
[18:19:39.755] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[18:20:09.433] INFO: Resuming triggers.
[18:20:19.743] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[18:20:49.417] INFO: Resuming triggers.
[18:20:59.729] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[18:21:29.266] INFO: Resuming triggers.
[18:21:39.579] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[18:22:09.156] INFO: Resuming triggers.
[18:22:19.464] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[18:22:49.098] INFO: Resuming triggers.
[18:22:59.409] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[18:23:29.009] INFO: Resuming triggers.
[18:23:39.317] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[18:24:08.934] INFO: Resuming triggers.
[18:24:19.248] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[18:24:48.864] INFO: Resuming triggers.
[18:24:56.393] INFO: data taking finished, elapsed time: 100 seconds.
[18:25:18.151] INFO: PixTest:: pg_setup set to default.
[18:25:18.155] INFO: PixTestXray::doPhRun() done
[18:25:18.293] INFO: enter test to run
[18:25:43.302] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:25:43.302] INFO: running: xray
[18:25:43.303] INFO: ----------------------------------------------------------------------
[18:25:43.303] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:25:43.303] INFO: ----------------------------------------------------------------------
[18:25:44.268] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:25:50.030] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[18:26:21.340] INFO: Resuming triggers.
[18:26:27.104] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[18:26:57.812] INFO: Resuming triggers.
[18:27:03.580] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[18:27:35.157] INFO: Resuming triggers.
[18:27:40.922] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[18:28:12.710] INFO: Resuming triggers.
[18:28:18.472] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[18:28:49.425] INFO: Resuming triggers.
[18:28:55.187] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[18:29:25.356] INFO: Resuming triggers.
[18:29:31.117] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[18:30:01.348] INFO: Resuming triggers.
[18:30:07.113] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[18:30:37.178] INFO: Resuming triggers.
[18:30:42.945] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[18:31:13.021] INFO: Resuming triggers.
[18:31:18.786] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[18:31:48.885] INFO: Resuming triggers.
[18:31:54.650] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[18:32:24.816] INFO: Resuming triggers.
[18:32:30.585] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[18:33:00.706] INFO: Resuming triggers.
[18:33:06.477] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[18:33:36.652] INFO: Resuming triggers.
[18:33:42.420] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[18:34:12.653] INFO: Resuming triggers.
[18:34:18.424] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[18:34:48.838] INFO: Resuming triggers.
[18:34:54.608] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[18:35:24.996] INFO: Resuming triggers.
[18:35:30.766] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[18:36:00.944] INFO: Resuming triggers.
[18:36:03.257] INFO: data taking finished, elapsed time: 100 seconds.
[18:36:15.609] INFO: PixTest:: pg_setup set to default.
[18:36:15.612] INFO: PixTestXray::doPhRun() done
[18:36:15.760] INFO: enter test to run
[18:36:52.145] INFO: test: HighRate no parameter change
[18:36:52.145] INFO: running: highrate
[18:36:52.147] INFO: ----------------------------------------------------------------------
[18:36:52.147] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:36:52.147] INFO: ----------------------------------------------------------------------
[18:36:52.287] INFO: Expecting 768 events.
[18:36:53.421] INFO: 768 events read in total (418ms).
[18:36:53.422] INFO: Test took 1269ms.
[18:36:54.226] INFO: Expecting 41600 events.
[18:36:57.370] INFO: 41600 events read in total (2618ms).
[18:36:57.371] INFO: Test took 3943ms.
[18:36:57.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:58.127] INFO: Expecting 41600 events.
[18:37:01.455] INFO: 41600 events read in total (2801ms).
[18:37:01.456] INFO: Test took 4024ms.
[18:37:01.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:02.208] INFO: Expecting 41600 events.
[18:37:05.534] INFO: 41600 events read in total (2799ms).
[18:37:05.535] INFO: Test took 4015ms.
[18:37:05.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:06.286] INFO: Expecting 41600 events.
[18:37:09.637] INFO: 41600 events read in total (2824ms).
[18:37:09.638] INFO: Test took 4038ms.
[18:37:09.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:10.386] INFO: Expecting 41600 events.
[18:37:13.760] INFO: 41600 events read in total (2847ms).
[18:37:13.761] INFO: Test took 4057ms.
[18:37:13.804] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:14.508] INFO: Expecting 41600 events.
[18:37:17.820] INFO: 41600 events read in total (2785ms).
[18:37:17.821] INFO: Test took 3996ms.
[18:37:17.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:18.567] INFO: Expecting 41600 events.
[18:37:21.949] INFO: 41600 events read in total (2855ms).
[18:37:21.950] INFO: Test took 4065ms.
[18:37:21.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:22.699] INFO: Expecting 41600 events.
[18:37:26.006] INFO: 41600 events read in total (2781ms).
[18:37:26.007] INFO: Test took 3993ms.
[18:37:26.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:26.753] INFO: Expecting 41600 events.
[18:37:30.087] INFO: 41600 events read in total (2807ms).
[18:37:30.088] INFO: Test took 4018ms.
[18:37:30.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:30.838] INFO: Expecting 41600 events.
[18:37:34.129] INFO: 41600 events read in total (2765ms).
[18:37:34.130] INFO: Test took 3978ms.
[18:37:34.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:34.877] INFO: Expecting 41600 events.
[18:37:38.258] INFO: 41600 events read in total (2854ms).
[18:37:38.259] INFO: Test took 4065ms.
[18:37:38.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:39.007] INFO: Expecting 41600 events.
[18:37:42.300] INFO: 41600 events read in total (2766ms).
[18:37:42.301] INFO: Test took 3976ms.
[18:37:42.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:43.043] INFO: Expecting 41600 events.
[18:37:46.366] INFO: 41600 events read in total (2796ms).
[18:37:46.367] INFO: Test took 4002ms.
[18:37:46.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:47.107] INFO: Expecting 41600 events.
[18:37:50.438] INFO: 41600 events read in total (2805ms).
[18:37:50.439] INFO: Test took 4007ms.
[18:37:50.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:51.188] INFO: Expecting 41600 events.
[18:37:54.498] INFO: 41600 events read in total (2784ms).
[18:37:54.499] INFO: Test took 3996ms.
[18:37:54.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:55.249] INFO: Expecting 41600 events.
[18:37:58.607] INFO: 41600 events read in total (2831ms).
[18:37:58.609] INFO: Test took 4047ms.
[18:37:58.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:59.355] INFO: Expecting 41600 events.
[18:38:02.684] INFO: 41600 events read in total (2803ms).
[18:38:02.685] INFO: Test took 4013ms.
[18:38:02.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:03.436] INFO: Expecting 41600 events.
[18:38:06.809] INFO: 41600 events read in total (2846ms).
[18:38:06.811] INFO: Test took 4061ms.
[18:38:06.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:07.562] INFO: Expecting 41600 events.
[18:38:10.848] INFO: 41600 events read in total (2759ms).
[18:38:10.849] INFO: Test took 3976ms.
[18:38:10.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:11.598] INFO: Expecting 41600 events.
[18:38:14.754] INFO: 41600 events read in total (2629ms).
[18:38:14.755] INFO: Test took 3842ms.
[18:38:14.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:15.140] INFO: enter test to run
[18:38:33.056] INFO: test: HighRate no parameter change
[18:38:33.056] INFO: running: highrate
[18:38:33.058] INFO: ----------------------------------------------------------------------
[18:38:33.058] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:38:33.058] INFO: ----------------------------------------------------------------------
[18:38:33.679] INFO: Expecting 208000 events.
[18:38:46.291] INFO: 208000 events read in total (12086ms).
[18:38:46.295] INFO: Test took 13228ms.
[18:38:46.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:46.751] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0
[18:38:46.751] INFO: number of red-efficiency pixels: 96 66 123 237 209 254 170 117 132 159 148 111 156 81 35 35
[18:38:46.751] INFO: number of X-ray hits detected: 83391 55838 87308 140292 145504 152161 146377 102933 101834 129121 119481 106740 113404 65984 24750 30133
[18:38:46.751] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:38:46.751] INFO: number of Vcal hits detected: 207903 207933 207873 207754 207777 207735 207826 207879 207865 207839 207651 207888 207840 207917 207965 207965
[18:38:46.751] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 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
[18:38:46.751] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.8 99.9 99.9 100.0 100.0 100.0
[18:38:46.751] INFO: X-ray hit rate [MHz/cm2]: 24.4 16.4 25.6 41.1 42.6 44.6 42.9 30.2 29.8 37.8 35.0 31.3 33.2 19.3 7.3 8.8
[18:38:46.752] INFO: PixTestHighRate::doXPixelAlive() done
[18:38:46.796] INFO: PixTest:: pg_setup set to default.
[18:38:46.815] INFO: enter test to run
[18:39:09.784] INFO: test: HighRate no parameter change
[18:39:09.784] INFO: running: highrate
[18:39:09.785] INFO: ----------------------------------------------------------------------
[18:39:09.785] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:39:09.785] INFO: ----------------------------------------------------------------------
[18:39:10.408] INFO: Expecting 208000 events.
[18:39:25.246] INFO: 208000 events read in total (14311ms).
[18:39:25.253] INFO: Test took 15459ms.
[18:39:25.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:25.956] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0
[18:39:25.956] INFO: number of red-efficiency pixels: 253 188 412 834 643 855 617 385 343 506 587 369 507 279 90 75
[18:39:25.956] INFO: number of X-ray hits detected: 168896 113879 179049 284919 294771 306691 297270 210193 206450 262047 242140 216280 230564 134517 50456 62080
[18:39:25.956] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:39:25.956] INFO: number of Vcal hits detected: 207731 207805 207513 207041 207273 206975 207313 207574 207630 207426 207158 207605 207436 207696 207904 207925
[18:39:25.956] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.6 99.7 99.6 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[18:39:25.956] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.5 99.7 99.5 99.7 99.8 99.8 99.7 99.6 99.8 99.7 99.9 100.0 100.0
[18:39:25.956] INFO: X-ray hit rate [MHz/cm2]: 49.5 33.4 52.5 83.5 86.4 89.9 87.1 61.6 60.5 76.8 71.0 63.4 67.6 39.4 14.8 18.2
[18:39:25.956] INFO: PixTestHighRate::doXPixelAlive() done
[18:39:26.004] INFO: PixTest:: pg_setup set to default.
[18:39:26.018] INFO: enter test to run
[18:39:44.688] INFO: test: HighRate no parameter change
[18:39:44.688] INFO: running: highrate
[18:39:44.689] INFO: ----------------------------------------------------------------------
[18:39:44.689] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:39:44.689] INFO: ----------------------------------------------------------------------
[18:39:45.342] INFO: Expecting 208000 events.
[18:40:03.254] INFO: 208000 events read in total (17385ms).
[18:40:03.263] INFO: Test took 18563ms.
[18:40:03.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:04.260] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 4 0 0 0 0 0
[18:40:04.260] INFO: number of red-efficiency pixels: 574 400 927 1939 1558 2126 1450 833 808 1211 1385 916 1275 689 156 140
[18:40:04.260] INFO: number of X-ray hits detected: 256778 174237 272373 435781 450842 470106 453846 320143 316735 400047 370433 330064 352030 206431 77460 95305
[18:40:04.260] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:40:04.260] INFO: number of Vcal hits detected: 207309 207546 206481 204968 205841 204505 205983 206891 207017 206385 205974 206883 206354 207067 207826 207856
[18:40:04.260] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.4 98.7 99.1 98.5 99.1 99.5 99.6 99.3 99.2 99.5 99.3 99.6 99.9 99.9
[18:40:04.260] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.3 98.5 99.0 98.3 99.0 99.5 99.5 99.2 99.0 99.5 99.2 99.6 99.9 99.9
[18:40:04.260] INFO: X-ray hit rate [MHz/cm2]: 75.3 51.1 79.8 127.7 132.1 137.8 133.0 93.8 92.8 117.3 108.6 96.7 103.2 60.5 22.7 27.9
[18:40:04.260] INFO: PixTestHighRate::doXPixelAlive() done
[18:40:04.310] INFO: PixTest:: pg_setup set to default.
[18:40:04.324] INFO: enter test to run
[18:40:12.039] INFO: test: exit no parameter change
[18:40:12.338] QUIET: Connection to board 32 closed.
[18:40:12.339] INFO: pXar: this is the end, my friend