[14:06:27.441] INFO: *** Welcome to pxar ***
[14:06:27.441] INFO: *** Today: 2016/06/03
[14:06:28.974] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:06:28.974] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C15.dat
[14:06:29.044] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:06:29.044] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[14:06:29.044] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[14:06:29.619] INFO: clk: 4
[14:06:29.619] INFO: ctr: 4
[14:06:29.619] INFO: sda: 19
[14:06:29.619] INFO: tin: 9
[14:06:29.619] INFO: level: 15
[14:06:29.619] INFO: triggerdelay: 0
[14:06:29.619] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:06:29.619] INFO: Log level: INFO
[14:06:29.638] QUIET: Connection to board DTB_WREK4U opened.
[14:06:29.642] 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:
------------------------------------------------------
[14:06:29.645] INFO: RPC call hashes of host and DTB match: 398089610
[14:06:31.188] INFO: DUT info:
[14:06:31.188] INFO: The DUT currently contains the following objects:
[14:06:31.188] INFO: 2 TBM Cores tbm08c (2 ON)
[14:06:31.188] INFO: TBM Core alpha (0): 7 registers set
[14:06:31.188] INFO: TBM Core beta (1): 7 registers set
[14:06:31.188] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:06:31.188] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.188] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:06:31.706] INFO: enter 'restricted' command line mode
[14:06:31.706] INFO: enter test to run
[14:07:22.441] INFO: test: PixelAlive no parameter change
[14:07:22.441] INFO: running: pixelalive
[14:07:22.465] INFO: ----------------------------------------------------------------------
[14:07:22.465] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:07:22.465] INFO: ----------------------------------------------------------------------
[14:07:22.788] INFO: Expecting 41600 events.
[14:07:27.096] INFO: 41600 events read in total (3590ms).
[14:07:27.267] INFO: Test took 4800ms.
[14:07:27.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:27.592] INFO: PixTestAlive::aliveTest() done
[14:07:27.592] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[14:07:27.726] INFO: enter test to run
[14:07:44.913] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:07:44.913] INFO: running: highrate
[14:07:44.914] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:07:45.221] INFO: ----------------------------------------------------------------------
[14:07:45.221] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:07:45.221] INFO: ----------------------------------------------------------------------
[14:07:45.221] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:07:45.221] INFO: edge/corner pixel THR is adjusted
[14:07:45.221] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:07:46.190] INFO: Collecting data for 5 seconds...
[14:07:51.206] INFO: Done with hot pixel readout
[14:08:03.868] INFO: PixTest:: pg_setup set to default.
[14:08:03.868] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:03.869] INFO: 74 hot pixels found in step 0
[14:08:04.866] INFO: Collecting data for 5 seconds...
[14:08:09.883] INFO: Done with hot pixel readout
[14:08:22.410] INFO: PixTest:: pg_setup set to default.
[14:08:22.411] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.411] INFO: 69 hot pixels found in step 1
[14:08:23.409] INFO: Collecting data for 5 seconds...
[14:08:28.425] INFO: Done with hot pixel readout
[14:08:41.021] INFO: PixTest:: pg_setup set to default.
[14:08:41.022] INFO: 83 hot pixels found in step 2
[14:08:42.020] INFO: Collecting data for 5 seconds...
[14:08:47.036] INFO: Done with hot pixel readout
[14:08:59.564] INFO: PixTest:: pg_setup set to default.
[14:08:59.564] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:59.564] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:59.565] INFO: 59 hot pixels found in step 3
[14:09:00.564] INFO: Collecting data for 5 seconds...
[14:09:05.580] INFO: Done with hot pixel readout
[14:09:18.397] INFO: PixTest:: pg_setup set to default.
[14:09:18.397] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:18.398] INFO: 64 hot pixels found in step 4
[14:09:19.398] INFO: Collecting data for 5 seconds...
[14:09:24.418] INFO: Done with hot pixel readout
[14:09:37.378] INFO: PixTest:: pg_setup set to default.
[14:09:37.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:37.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:37.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:37.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:37.380] INFO: 71 hot pixels found in step 5
[14:09:38.378] INFO: Collecting data for 5 seconds...
[14:09:43.396] INFO: Done with hot pixel readout
[14:09:56.380] INFO: PixTest:: pg_setup set to default.
[14:09:56.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:56.381] INFO: 58 hot pixels found in step 6
[14:09:57.380] INFO: Collecting data for 5 seconds...
[14:10:02.401] INFO: Done with hot pixel readout
[14:10:15.156] INFO: PixTest:: pg_setup set to default.
[14:10:15.156] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.156] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.156] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.156] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.157] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.157] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:15.157] INFO: 59 hot pixels found in step 7
[14:10:16.156] INFO: Collecting data for 5 seconds...
[14:10:21.172] INFO: Done with hot pixel readout
[14:10:33.764] INFO: PixTest:: pg_setup set to default.
[14:10:33.764] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:33.764] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:33.764] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:33.765] INFO: 53 hot pixels found in step 8
[14:10:34.763] INFO: Collecting data for 5 seconds...
[14:10:39.779] INFO: Done with hot pixel readout
[14:10:52.385] INFO: PixTest:: pg_setup set to default.
[14:10:52.385] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:52.385] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:52.385] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:52.386] INFO: 53 hot pixels found in step 9
[14:10:53.385] INFO: Collecting data for 5 seconds...
[14:10:58.400] INFO: Done with hot pixel readout
[14:11:10.969] INFO: PixTest:: pg_setup set to default.
[14:11:10.969] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:10.969] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:10.969] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:10.969] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:10.970] INFO: 66 hot pixels found in step 10
[14:11:11.968] INFO: Collecting data for 5 seconds...
[14:11:16.984] INFO: Done with hot pixel readout
[14:11:29.558] INFO: PixTest:: pg_setup set to default.
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.558] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:29.559] INFO: 42 hot pixels found in step 11
[14:11:30.557] INFO: Collecting data for 5 seconds...
[14:11:35.572] INFO: Done with hot pixel readout
[14:11:48.171] INFO: PixTest:: pg_setup set to default.
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.171] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:11:48.172] INFO: 39 hot pixels found in step 12
[14:11:49.170] INFO: Collecting data for 5 seconds...
[14:11:54.187] INFO: Done with hot pixel readout
[14:12:06.771] INFO: PixTest:: pg_setup set to default.
[14:12:06.771] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:06.772] INFO: 41 hot pixels found in step 13
[14:12:07.770] INFO: Collecting data for 5 seconds...
[14:12:12.788] INFO: Done with hot pixel readout
[14:12:25.535] INFO: PixTest:: pg_setup set to default.
[14:12:25.536] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:12:25.536] INFO: 37 hot pixels found in step 14
[14:12:25.580] INFO: 37 hot pixels could not be trimmed and have been masked.
[14:12:25.584] INFO: PixTest::trimHotPixels() done
[14:12:25.584] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[14:12:25.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[14:12:25.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[14:12:25.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[14:12:25.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[14:12:25.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[14:12:25.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[14:12:25.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[14:12:25.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[14:12:25.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[14:12:25.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[14:12:25.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[14:12:25.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[14:12:25.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[14:12:25.661] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[14:12:25.666] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[14:12:25.671] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[14:12:25.682] INFO: enter test to run
[14:12:44.127] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:12:44.127] INFO: running: highrate
[14:12:44.132] INFO: ----------------------------------------------------------------------
[14:12:44.132] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:12:44.132] INFO: ----------------------------------------------------------------------
[14:12:44.132] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:12:44.132] INFO: edge/corner pixel THR is adjusted
[14:12:44.132] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:12:45.089] INFO: Collecting data for 1 seconds...
[14:12:46.093] INFO: Done with hot pixel readout
[14:12:50.767] INFO: PixTest:: pg_setup set to default.
[14:12:50.768] INFO: 0 hot pixels found in step 0
[14:12:50.773] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:12:50.842] INFO: PixTest::trimHotPixels() done
[14:12:50.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[14:12:50.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[14:12:50.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[14:12:50.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[14:12:50.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[14:12:50.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[14:12:50.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[14:12:50.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[14:12:50.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[14:12:50.896] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[14:12:50.901] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[14:12:50.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[14:12:50.912] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[14:12:50.917] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[14:12:50.922] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[14:12:50.928] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[14:12:50.933] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NV_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[14:12:50.943] INFO: enter test to run
[14:15:09.350] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:15:09.350] INFO: running: xray
[14:15:09.351] INFO: ----------------------------------------------------------------------
[14:15:09.351] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:15:09.351] INFO: ----------------------------------------------------------------------
[14:15:10.331] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:15:20.837] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:15:50.539] INFO: Resuming triggers.
[14:16:01.048] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:16:30.771] INFO: Resuming triggers.
[14:16:41.279] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[14:17:10.842] INFO: Resuming triggers.
[14:17:21.348] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:17:51.679] INFO: Resuming triggers.
[14:18:02.191] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:18:31.860] INFO: Resuming triggers.
[14:18:42.372] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:19:11.723] INFO: Resuming triggers.
[14:19:22.227] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:19:51.844] INFO: Resuming triggers.
[14:20:02.356] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:20:32.473] INFO: Resuming triggers.
[14:20:42.984] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:21:12.919] INFO: Resuming triggers.
[14:21:18.678] INFO: data taking finished, elapsed time: 100 seconds.
[14:21:35.297] INFO: PixTest:: pg_setup set to default.
[14:21:35.300] INFO: PixTestXray::doPhRun() done
[14:21:35.439] INFO: enter test to run
[14:22:35.059] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:22:35.059] INFO: running: xray
[14:22:35.060] INFO: ----------------------------------------------------------------------
[14:22:35.060] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:22:35.060] INFO: ----------------------------------------------------------------------
[14:22:36.024] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:22:41.788] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[14:23:11.954] INFO: Resuming triggers.
[14:23:17.720] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:23:47.794] INFO: Resuming triggers.
[14:23:53.561] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[14:24:23.762] INFO: Resuming triggers.
[14:24:29.528] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:25:01.730] INFO: Resuming triggers.
[14:25:07.498] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:25:37.524] INFO: Resuming triggers.
[14:25:43.292] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:26:12.474] INFO: Resuming triggers.
[14:26:18.240] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:26:48.349] INFO: Resuming triggers.
[14:26:54.115] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:27:24.281] INFO: Resuming triggers.
[14:27:30.048] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:28:00.258] INFO: Resuming triggers.
[14:28:06.024] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:28:36.233] INFO: Resuming triggers.
[14:28:41.998] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:29:12.949] INFO: Resuming triggers.
[14:29:18.715] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:29:48.401] INFO: Resuming triggers.
[14:29:54.167] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:30:22.653] INFO: Resuming triggers.
[14:30:28.419] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:30:57.809] INFO: Resuming triggers.
[14:31:03.574] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:31:34.694] INFO: Resuming triggers.
[14:31:40.460] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:32:10.669] INFO: Resuming triggers.
[14:32:16.433] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:32:46.524] INFO: Resuming triggers.
[14:32:48.844] INFO: data taking finished, elapsed time: 100 seconds.
[14:33:01.255] INFO: PixTest:: pg_setup set to default.
[14:33:01.258] INFO: PixTestXray::doPhRun() done
[14:33:01.410] INFO: enter test to run
[14:33:13.878] INFO: test: HighRate no parameter change
[14:33:13.878] INFO: running: highrate
[14:33:13.895] INFO: ----------------------------------------------------------------------
[14:33:13.895] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:33:13.895] INFO: ----------------------------------------------------------------------
[14:33:14.059] INFO: Expecting 768 events.
[14:33:15.193] INFO: 768 events read in total (419ms).
[14:33:15.193] INFO: Test took 1269ms.
[14:33:15.996] INFO: Expecting 41600 events.
[14:33:19.103] INFO: 41600 events read in total (2580ms).
[14:33:19.104] INFO: Test took 3905ms.
[14:33:19.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:19.864] INFO: Expecting 41600 events.
[14:33:23.126] INFO: 41600 events read in total (2735ms).
[14:33:23.127] INFO: Test took 3964ms.
[14:33:23.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:23.883] INFO: Expecting 41600 events.
[14:33:27.182] INFO: 41600 events read in total (2772ms).
[14:33:27.183] INFO: Test took 3995ms.
[14:33:27.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:27.936] INFO: Expecting 41600 events.
[14:33:31.238] INFO: 41600 events read in total (2775ms).
[14:33:31.239] INFO: Test took 3995ms.
[14:33:31.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:31.992] INFO: Expecting 41600 events.
[14:33:35.259] INFO: 41600 events read in total (2740ms).
[14:33:35.261] INFO: Test took 3962ms.
[14:33:35.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:36.015] INFO: Expecting 41600 events.
[14:33:39.313] INFO: 41600 events read in total (2771ms).
[14:33:39.314] INFO: Test took 3993ms.
[14:33:39.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:40.066] INFO: Expecting 41600 events.
[14:33:43.359] INFO: 41600 events read in total (2766ms).
[14:33:43.360] INFO: Test took 3985ms.
[14:33:43.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:44.112] INFO: Expecting 41600 events.
[14:33:47.413] INFO: 41600 events read in total (2774ms).
[14:33:47.414] INFO: Test took 3993ms.
[14:33:47.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:48.167] INFO: Expecting 41600 events.
[14:33:51.444] INFO: 41600 events read in total (2750ms).
[14:33:51.446] INFO: Test took 3972ms.
[14:33:51.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:52.195] INFO: Expecting 41600 events.
[14:33:55.485] INFO: 41600 events read in total (2763ms).
[14:33:55.486] INFO: Test took 3980ms.
[14:33:55.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:56.238] INFO: Expecting 41600 events.
[14:33:59.519] INFO: 41600 events read in total (2754ms).
[14:33:59.520] INFO: Test took 3973ms.
[14:33:59.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:00.269] INFO: Expecting 41600 events.
[14:34:03.575] INFO: 41600 events read in total (2779ms).
[14:34:03.576] INFO: Test took 3995ms.
[14:34:03.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:04.325] INFO: Expecting 41600 events.
[14:34:07.631] INFO: 41600 events read in total (2779ms).
[14:34:07.632] INFO: Test took 3995ms.
[14:34:07.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:08.382] INFO: Expecting 41600 events.
[14:34:11.690] INFO: 41600 events read in total (2781ms).
[14:34:11.691] INFO: Test took 3998ms.
[14:34:11.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:12.444] INFO: Expecting 41600 events.
[14:34:15.733] INFO: 41600 events read in total (2762ms).
[14:34:15.734] INFO: Test took 3982ms.
[14:34:15.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:16.487] INFO: Expecting 41600 events.
[14:34:19.765] INFO: 41600 events read in total (2751ms).
[14:34:19.766] INFO: Test took 3970ms.
[14:34:19.806] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:20.518] INFO: Expecting 41600 events.
[14:34:23.807] INFO: 41600 events read in total (2762ms).
[14:34:23.808] INFO: Test took 3982ms.
[14:34:23.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:24.557] INFO: Expecting 41600 events.
[14:34:27.862] INFO: 41600 events read in total (2778ms).
[14:34:27.863] INFO: Test took 3994ms.
[14:34:27.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:28.613] INFO: Expecting 41600 events.
[14:34:31.887] INFO: 41600 events read in total (2747ms).
[14:34:31.888] INFO: Test took 3963ms.
[14:34:31.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:32.643] INFO: Expecting 41600 events.
[14:34:35.779] INFO: 41600 events read in total (2609ms).
[14:34:35.781] INFO: Test took 3831ms.
[14:34:35.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:36.173] INFO: enter test to run
[14:34:54.589] INFO: test: HighRate no parameter change
[14:34:54.589] INFO: running: highrate
[14:34:54.590] INFO: ----------------------------------------------------------------------
[14:34:54.591] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:34:54.591] INFO: ----------------------------------------------------------------------
[14:34:55.210] INFO: Expecting 208000 events.
[14:35:07.410] INFO: 208000 events read in total (11673ms).
[14:35:07.413] INFO: Test took 12814ms.
[14:35:07.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:07.853] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[14:35:07.854] INFO: number of red-efficiency pixels: 122 71 118 189 181 252 214 121 102 162 172 120 134 43 25 28
[14:35:07.854] INFO: number of X-ray hits detected: 85940 54943 84717 144700 142960 144655 149723 106379 91198 111373 118967 98645 101702 60387 28310 30613
[14:35:07.854] 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:35:07.854] INFO: number of Vcal hits detected: 207875 207927 207878 207804 207813 207664 207779 207876 207892 207833 207729 207863 207862 207956 207974 207972
[14:35:07.854] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:35:07.854] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:35:07.854] INFO: X-ray hit rate [MHz/cm2]: 25.2 16.1 24.8 42.4 41.9 42.4 43.9 31.2 26.7 32.6 34.9 28.9 29.8 17.7 8.3 9.0
[14:35:07.854] INFO: PixTestHighRate::doXPixelAlive() done
[14:35:07.904] INFO: PixTest:: pg_setup set to default.
[14:35:07.919] INFO: enter test to run
[14:35:31.165] INFO: test: HighRate no parameter change
[14:35:31.165] INFO: running: highrate
[14:35:31.166] INFO: ----------------------------------------------------------------------
[14:35:31.166] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:35:31.166] INFO: ----------------------------------------------------------------------
[14:35:31.780] INFO: Expecting 208000 events.
[14:35:47.156] INFO: 208000 events read in total (14849ms).
[14:35:47.162] INFO: Test took 15986ms.
[14:35:47.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:47.865] INFO: number of dead pixels (per ROC): 0 0 0 0 0 12 0 0 0 0 2 0 0 0 0 0
[14:35:47.865] INFO: number of red-efficiency pixels: 339 204 507 849 694 1000 925 408 327 596 600 397 483 236 75 71
[14:35:47.865] INFO: number of X-ray hits detected: 179602 115917 177262 301676 298728 303983 314279 222271 190784 233203 249056 207008 214757 127112 58903 63770
[14:35:47.865] 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:35:47.865] INFO: number of Vcal hits detected: 207611 207788 207407 207016 207203 204582 206892 207553 207653 207341 207232 207541 207476 207741 207924 207925
[14:35:47.865] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.7 98.6 99.5 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[14:35:47.865] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.6 98.4 99.5 99.8 99.8 99.7 99.6 99.8 99.7 99.9 100.0 100.0
[14:35:47.865] INFO: X-ray hit rate [MHz/cm2]: 52.6 34.0 52.0 88.4 87.6 89.1 92.1 65.1 55.9 68.4 73.0 60.7 62.9 37.3 17.3 18.7
[14:35:47.865] INFO: PixTestHighRate::doXPixelAlive() done
[14:35:47.912] INFO: PixTest:: pg_setup set to default.
[14:35:47.927] INFO: enter test to run
[14:36:05.245] INFO: test: HighRate no parameter change
[14:36:05.245] INFO: running: highrate
[14:36:05.246] INFO: ----------------------------------------------------------------------
[14:36:05.246] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:36:05.247] INFO: ----------------------------------------------------------------------
[14:36:05.872] INFO: Expecting 208000 events.
[14:36:23.950] INFO: 208000 events read in total (17551ms).
[14:36:23.959] INFO: Test took 18703ms.
[14:36:24.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:24.915] INFO: number of dead pixels (per ROC): 0 0 0 0 0 12 0 0 0 0 2 0 0 0 0 0
[14:36:24.915] INFO: number of red-efficiency pixels: 874 432 1062 1922 1613 2174 2016 963 686 1320 1345 759 1104 485 121 125
[14:36:24.915] INFO: number of X-ray hits detected: 269241 172729 266630 451653 447630 451335 468824 334041 287280 349628 373887 309810 320824 191007 88738 96021
[14:36:24.915] 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:36:24.915] INFO: number of Vcal hits detected: 206814 207500 206271 205100 205681 201465 204731 206768 207176 206308 206110 207041 206640 207429 207872 207872
[14:36:24.915] INFO: Vcal hit fiducial efficiency (%): 99.5 99.8 99.2 98.7 99.0 97.2 98.6 99.5 99.6 99.3 99.2 99.6 99.4 99.8 99.9 99.9
[14:36:24.915] INFO: Vcal hit overall efficiency (%): 99.4 99.8 99.2 98.6 98.9 96.9 98.4 99.4 99.6 99.2 99.1 99.5 99.3 99.7 99.9 99.9
[14:36:24.915] INFO: X-ray hit rate [MHz/cm2]: 78.9 50.6 78.2 132.4 131.2 132.3 137.4 97.9 84.2 102.5 109.6 90.8 94.0 56.0 26.0 28.1
[14:36:24.915] INFO: PixTestHighRate::doXPixelAlive() done
[14:36:24.964] INFO: PixTest:: pg_setup set to default.
[14:36:24.977] INFO: enter test to run
[14:36:29.157] INFO: test: exit no parameter change
[14:36:29.567] QUIET: Connection to board 32 closed.
[14:36:29.574] INFO: pXar: this is the end, my friend