[09:28:23.372] INFO: *** Welcome to pxar ***
[09:28:23.372] INFO: *** Today: 2016/04/06
[09:28:23.389] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:28:23.389] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//dacParameters35_C15.dat
[09:28:23.390] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:28:23.390] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//defaultMaskFile.dat
[09:28:23.391] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C15.dat
[09:28:23.465] INFO: clk: 4
[09:28:23.465] INFO: ctr: 4
[09:28:23.465] INFO: sda: 19
[09:28:23.466] INFO: tin: 9
[09:28:23.466] INFO: level: 15
[09:28:23.466] INFO: triggerdelay: 0
[09:28:23.466] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:28:23.466] INFO: Log level: INFO
[09:28:23.480] QUIET: Connection to board DTB_WREKRL opened.
[09:28:23.483] 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:
------------------------------------------------------
[09:28:23.486] INFO: RPC call hashes of host and DTB match: 398089610
[09:28:25.015] INFO: DUT info:
[09:28:25.015] INFO: The DUT currently contains the following objects:
[09:28:25.016] INFO: 2 TBM Cores tbm08c (2 ON)
[09:28:25.016] INFO: TBM Core alpha (0): 7 registers set
[09:28:25.016] INFO: TBM Core beta (1): 7 registers set
[09:28:25.016] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:28:25.016] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.016] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:28:25.419] INFO: enter 'restricted' command line mode
[09:28:25.420] INFO: enter test to run
[09:28:36.754] INFO: test: PixelAlive no parameter change
[09:28:36.755] INFO: running: pixelalive
[09:28:36.794] INFO: ----------------------------------------------------------------------
[09:28:36.794] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:28:36.795] INFO: ----------------------------------------------------------------------
[09:28:37.113] INFO: Expecting 41600 events.
[09:28:41.478] INFO: 41600 events read in total (3646ms).
[09:28:41.646] INFO: Test took 4847ms.
[09:28:41.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:41.949] INFO: PixTestAlive::aliveTest() done
[09:28:41.949] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 5 0 0
[09:28:41.980] INFO: enter test to run
[09:29:18.362] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:29:18.362] INFO: running: highrate
[09:29:18.362] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:29:18.638] INFO: ----------------------------------------------------------------------
[09:29:18.638] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:29:18.638] INFO: ----------------------------------------------------------------------
[09:29:18.638] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:29:18.638] INFO: edge/corner pixel THR is adjusted
[09:29:18.638] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:29:19.620] INFO: Collecting data for 5 seconds...
[09:29:24.636] INFO: Done with hot pixel readout
[09:29:37.387] INFO: PixTest:: pg_setup set to default.
[09:29:37.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:29:37.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:29:37.388] INFO: 68 hot pixels found in step 0
[09:29:38.384] INFO: Collecting data for 5 seconds...
[09:29:43.401] INFO: Done with hot pixel readout
[09:29:56.118] INFO: PixTest:: pg_setup set to default.
[09:29:56.118] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:29:56.118] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:29:56.119] INFO: 66 hot pixels found in step 1
[09:29:57.116] INFO: Collecting data for 5 seconds...
[09:30:02.132] INFO: Done with hot pixel readout
[09:30:14.900] INFO: PixTest:: pg_setup set to default.
[09:30:14.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:14.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:14.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:14.901] INFO: 68 hot pixels found in step 2
[09:30:15.901] INFO: Collecting data for 5 seconds...
[09:30:20.917] INFO: Done with hot pixel readout
[09:30:33.584] INFO: PixTest:: pg_setup set to default.
[09:30:33.584] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:33.584] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:33.585] INFO: 58 hot pixels found in step 3
[09:30:34.585] INFO: Collecting data for 5 seconds...
[09:30:39.601] INFO: Done with hot pixel readout
[09:30:52.320] INFO: PixTest:: pg_setup set to default.
[09:30:52.320] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:52.321] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:30:52.321] INFO: 67 hot pixels found in step 4
[09:30:53.321] INFO: Collecting data for 5 seconds...
[09:30:58.337] INFO: Done with hot pixel readout
[09:31:11.095] INFO: PixTest:: pg_setup set to default.
[09:31:11.095] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:11.095] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:11.095] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:11.096] INFO: 62 hot pixels found in step 5
[09:31:12.095] INFO: Collecting data for 5 seconds...
[09:31:17.111] INFO: Done with hot pixel readout
[09:31:29.794] INFO: PixTest:: pg_setup set to default.
[09:31:29.794] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:29.794] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:29.794] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:29.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:29.795] INFO: 53 hot pixels found in step 6
[09:31:30.795] INFO: Collecting data for 5 seconds...
[09:31:35.811] INFO: Done with hot pixel readout
[09:31:48.552] INFO: PixTest:: pg_setup set to default.
[09:31:48.552] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:48.552] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:31:48.553] INFO: 40 hot pixels found in step 7
[09:31:49.552] INFO: Collecting data for 5 seconds...
[09:31:54.570] INFO: Done with hot pixel readout
[09:32:07.236] INFO: PixTest:: pg_setup set to default.
[09:32:07.236] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:07.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:07.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:07.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:07.237] INFO: 39 hot pixels found in step 8
[09:32:08.237] INFO: Collecting data for 5 seconds...
[09:32:13.254] INFO: Done with hot pixel readout
[09:32:25.991] INFO: PixTest:: pg_setup set to default.
[09:32:25.991] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:25.992] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:25.992] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:25.992] INFO: 44 hot pixels found in step 9
[09:32:26.992] INFO: Collecting data for 5 seconds...
[09:32:32.009] INFO: Done with hot pixel readout
[09:32:42.357] INFO: PixTest:: pg_setup set to default.
[09:32:42.357] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:42.358] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:42.358] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:42.358] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:32:42.358] INFO: 46 hot pixels found in step 10
[09:32:43.358] INFO: Collecting data for 5 seconds...
[09:32:48.368] INFO: Done with hot pixel readout
[09:33:00.708] INFO: PixTest:: pg_setup set to default.
[09:33:00.708] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:00.708] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:00.708] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:00.709] INFO: 44 hot pixels found in step 11
[09:33:01.707] INFO: Collecting data for 5 seconds...
[09:33:06.724] INFO: Done with hot pixel readout
[09:33:19.426] INFO: PixTest:: pg_setup set to default.
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:19.427] INFO: 60 hot pixels found in step 12
[09:33:20.427] INFO: Collecting data for 5 seconds...
[09:33:25.443] INFO: Done with hot pixel readout
[09:33:38.142] INFO: PixTest:: pg_setup set to default.
[09:33:38.142] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:38.142] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:38.143] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:38.143] INFO: 44 hot pixels found in step 13
[09:33:39.142] INFO: Collecting data for 5 seconds...
[09:33:44.159] INFO: Done with hot pixel readout
[09:33:56.855] INFO: PixTest:: pg_setup set to default.
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.855] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:33:56.856] INFO: 37 hot pixels found in step 14
[09:33:56.899] INFO: 37 hot pixels could not be trimmed and have been masked.
[09:33:56.903] INFO: PixTest::trimHotPixels() done
[09:33:56.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C0.dat
[09:33:56.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C1.dat
[09:33:56.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C2.dat
[09:33:56.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C3.dat
[09:33:56.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C4.dat
[09:33:56.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C5.dat
[09:33:56.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C6.dat
[09:33:56.954] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C7.dat
[09:33:56.961] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C8.dat
[09:33:56.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C9.dat
[09:33:56.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C10.dat
[09:33:56.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C11.dat
[09:33:56.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C12.dat
[09:33:56.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C13.dat
[09:33:56.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C14.dat
[09:33:57.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C15.dat
[09:33:57.018] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//defaultMaskFile.dat
[09:33:57.029] INFO: enter test to run
[09:34:47.200] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:34:47.200] INFO: running: highrate
[09:34:47.204] INFO: ----------------------------------------------------------------------
[09:34:47.204] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:34:47.204] INFO: ----------------------------------------------------------------------
[09:34:47.204] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:34:47.204] INFO: edge/corner pixel THR is adjusted
[09:34:47.204] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:34:48.163] INFO: Collecting data for 1 seconds...
[09:34:49.166] INFO: Done with hot pixel readout
[09:34:53.728] INFO: PixTest:: pg_setup set to default.
[09:34:53.728] INFO: 1 hot pixels found in step 0
[09:34:54.756] INFO: Collecting data for 1 seconds...
[09:34:55.760] INFO: Done with hot pixel readout
[09:35:00.346] INFO: PixTest:: pg_setup set to default.
[09:35:00.347] INFO: 1 hot pixels found in step 1
[09:35:01.374] INFO: Collecting data for 1 seconds...
[09:35:02.378] INFO: Done with hot pixel readout
[09:35:06.937] INFO: PixTest:: pg_setup set to default.
[09:35:06.938] INFO: 1 hot pixels found in step 2
[09:35:07.969] INFO: Collecting data for 1 seconds...
[09:35:08.973] INFO: Done with hot pixel readout
[09:35:13.559] INFO: PixTest:: pg_setup set to default.
[09:35:13.560] INFO: 1 hot pixels found in step 3
[09:35:14.588] INFO: Collecting data for 1 seconds...
[09:35:15.592] INFO: Done with hot pixel readout
[09:35:20.160] INFO: PixTest:: pg_setup set to default.
[09:35:20.161] INFO: 1 hot pixels found in step 4
[09:35:21.190] INFO: Collecting data for 1 seconds...
[09:35:22.194] INFO: Done with hot pixel readout
[09:35:26.750] INFO: PixTest:: pg_setup set to default.
[09:35:26.751] INFO: 1 hot pixels found in step 5
[09:35:27.785] INFO: Collecting data for 1 seconds...
[09:35:28.789] INFO: Done with hot pixel readout
[09:35:33.351] INFO: PixTest:: pg_setup set to default.
[09:35:33.352] INFO: 1 hot pixels found in step 6
[09:35:34.386] INFO: Collecting data for 1 seconds...
[09:35:35.389] INFO: Done with hot pixel readout
[09:35:39.960] INFO: PixTest:: pg_setup set to default.
[09:35:39.961] INFO: 1 hot pixels found in step 7
[09:35:40.995] INFO: Collecting data for 1 seconds...
[09:35:41.999] INFO: Done with hot pixel readout
[09:35:46.545] INFO: PixTest:: pg_setup set to default.
[09:35:46.546] INFO: 1 hot pixels found in step 8
[09:35:47.575] INFO: Collecting data for 1 seconds...
[09:35:48.578] INFO: Done with hot pixel readout
[09:35:53.160] INFO: PixTest:: pg_setup set to default.
[09:35:53.161] INFO: 1 hot pixels found in step 9
[09:35:54.191] INFO: Collecting data for 1 seconds...
[09:35:55.194] INFO: Done with hot pixel readout
[09:35:59.751] INFO: PixTest:: pg_setup set to default.
[09:35:59.751] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:35:59.752] INFO: 1 hot pixels found in step 10
[09:35:59.757] INFO: 1 hot pixels could not be trimmed and have been masked.
[09:35:59.832] INFO: PixTest::trimHotPixels() done
[09:35:59.832] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C0.dat
[09:35:59.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C1.dat
[09:35:59.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C2.dat
[09:35:59.856] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C3.dat
[09:35:59.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C4.dat
[09:35:59.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C5.dat
[09:35:59.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C6.dat
[09:35:59.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C7.dat
[09:35:59.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C8.dat
[09:35:59.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C9.dat
[09:35:59.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C10.dat
[09:35:59.913] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C11.dat
[09:35:59.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C12.dat
[09:35:59.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C13.dat
[09:35:59.955] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C14.dat
[09:35:59.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//trimParameters35_C15.dat
[09:35:59.969] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-48_FPIXTest-17C-FNAL-160121-1017_2016-01-21_10h17m_1453393031/000_FPIXTest_p17//defaultMaskFile.dat
[09:35:59.979] INFO: enter test to run
[09:36:40.199] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:36:40.199] INFO: running: xray
[09:36:40.200] INFO: ----------------------------------------------------------------------
[09:36:40.200] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:36:40.200] INFO: ----------------------------------------------------------------------
[09:36:41.164] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:36:51.653] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:37:20.936] INFO: Resuming triggers.
[09:37:31.426] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[09:38:00.977] INFO: Resuming triggers.
[09:38:11.462] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:38:40.864] INFO: Resuming triggers.
[09:38:51.339] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[09:39:20.651] INFO: Resuming triggers.
[09:39:31.138] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[09:40:00.571] INFO: Resuming triggers.
[09:40:11.052] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:40:40.528] INFO: Resuming triggers.
[09:40:51.007] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[09:41:20.486] INFO: Resuming triggers.
[09:41:30.971] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[09:42:00.435] INFO: Resuming triggers.
[09:42:10.916] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:42:40.462] INFO: Resuming triggers.
[09:42:46.441] INFO: data taking finished, elapsed time: 100 seconds.
[09:43:00.473] INFO: PixTest:: pg_setup set to default.
[09:43:00.477] INFO: PixTestXray::doPhRun() done
[09:43:00.616] INFO: enter test to run
[09:43:29.284] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:43:29.284] INFO: running: xray
[09:43:29.285] INFO: ----------------------------------------------------------------------
[09:43:29.285] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:43:29.285] INFO: ----------------------------------------------------------------------
[09:43:30.249] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:43:35.938] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[09:44:05.000] INFO: Resuming triggers.
[09:44:11.689] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:44:41.842] INFO: Resuming triggers.
[09:44:47.537] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[09:45:17.646] INFO: Resuming triggers.
[09:45:23.337] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[09:45:53.413] INFO: Resuming triggers.
[09:45:59.109] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[09:46:29.266] INFO: Resuming triggers.
[09:46:34.958] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:47:05.109] INFO: Resuming triggers.
[09:47:10.803] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[09:47:40.927] INFO: Resuming triggers.
[09:47:46.621] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[09:48:16.743] INFO: Resuming triggers.
[09:48:22.439] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[09:48:52.549] INFO: Resuming triggers.
[09:48:58.238] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:49:28.378] INFO: Resuming triggers.
[09:49:34.073] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:50:04.204] INFO: Resuming triggers.
[09:50:09.894] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:50:40.020] INFO: Resuming triggers.
[09:50:45.708] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[09:51:15.854] INFO: Resuming triggers.
[09:51:21.547] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[09:51:51.588] INFO: Resuming triggers.
[09:51:57.277] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[09:52:27.313] INFO: Resuming triggers.
[09:52:32.001] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[09:53:01.547] INFO: Resuming triggers.
[09:53:07.237] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[09:53:37.257] INFO: Resuming triggers.
[09:53:40.832] INFO: data taking finished, elapsed time: 100 seconds.
[09:53:59.973] INFO: PixTest:: pg_setup set to default.
[09:53:59.977] INFO: PixTestXray::doPhRun() done
[09:54:00.128] INFO: enter test to run
[09:54:42.839] INFO: test: HighRate no parameter change
[09:54:42.839] INFO: running: highrate
[09:54:42.840] INFO: ----------------------------------------------------------------------
[09:54:42.840] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:54:42.840] INFO: ----------------------------------------------------------------------
[09:54:42.982] INFO: Expecting 768 events.
[09:54:44.124] INFO: 768 events read in total (418ms).
[09:54:44.125] INFO: Test took 1277ms.
[09:54:44.928] INFO: Expecting 41600 events.
[09:54:48.094] INFO: 41600 events read in total (2639ms).
[09:54:48.095] INFO: Test took 3965ms.
[09:54:48.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:48.849] INFO: Expecting 41600 events.
[09:54:52.127] INFO: 41600 events read in total (2751ms).
[09:54:52.128] INFO: Test took 3970ms.
[09:54:52.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:52.879] INFO: Expecting 41600 events.
[09:54:56.192] INFO: 41600 events read in total (2786ms).
[09:54:56.193] INFO: Test took 4000ms.
[09:54:56.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:56.941] INFO: Expecting 41600 events.
[09:55:00.262] INFO: 41600 events read in total (2794ms).
[09:55:00.263] INFO: Test took 4006ms.
[09:55:00.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:01.014] INFO: Expecting 41600 events.
[09:55:04.341] INFO: 41600 events read in total (2800ms).
[09:55:04.342] INFO: Test took 4014ms.
[09:55:04.385] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:05.089] INFO: Expecting 41600 events.
[09:55:08.412] INFO: 41600 events read in total (2796ms).
[09:55:08.413] INFO: Test took 4006ms.
[09:55:08.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:09.163] INFO: Expecting 41600 events.
[09:55:12.489] INFO: 41600 events read in total (2799ms).
[09:55:12.490] INFO: Test took 4014ms.
[09:55:12.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:13.237] INFO: Expecting 41600 events.
[09:55:16.562] INFO: 41600 events read in total (2798ms).
[09:55:16.563] INFO: Test took 4010ms.
[09:55:16.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:17.316] INFO: Expecting 41600 events.
[09:55:20.651] INFO: 41600 events read in total (2808ms).
[09:55:20.653] INFO: Test took 4026ms.
[09:55:20.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:21.402] INFO: Expecting 41600 events.
[09:55:24.722] INFO: 41600 events read in total (2793ms).
[09:55:24.723] INFO: Test took 4006ms.
[09:55:24.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:25.476] INFO: Expecting 41600 events.
[09:55:28.802] INFO: 41600 events read in total (2799ms).
[09:55:28.803] INFO: Test took 4015ms.
[09:55:28.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:29.555] INFO: Expecting 41600 events.
[09:55:32.881] INFO: 41600 events read in total (2799ms).
[09:55:32.882] INFO: Test took 4015ms.
[09:55:32.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:33.633] INFO: Expecting 41600 events.
[09:55:36.962] INFO: 41600 events read in total (2802ms).
[09:55:36.964] INFO: Test took 4018ms.
[09:55:37.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:37.716] INFO: Expecting 41600 events.
[09:55:41.043] INFO: 41600 events read in total (2800ms).
[09:55:41.044] INFO: Test took 4016ms.
[09:55:41.087] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:41.797] INFO: Expecting 41600 events.
[09:55:45.131] INFO: 41600 events read in total (2807ms).
[09:55:45.132] INFO: Test took 4023ms.
[09:55:45.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:45.882] INFO: Expecting 41600 events.
[09:55:49.212] INFO: 41600 events read in total (2803ms).
[09:55:49.213] INFO: Test took 4016ms.
[09:55:49.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:49.965] INFO: Expecting 41600 events.
[09:55:53.277] INFO: 41600 events read in total (2785ms).
[09:55:53.278] INFO: Test took 4002ms.
[09:55:53.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:54.026] INFO: Expecting 41600 events.
[09:55:57.345] INFO: 41600 events read in total (2792ms).
[09:55:57.346] INFO: Test took 4003ms.
[09:55:57.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:58.094] INFO: Expecting 41600 events.
[09:56:01.381] INFO: 41600 events read in total (2760ms).
[09:56:01.382] INFO: Test took 3970ms.
[09:56:01.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:02.135] INFO: Expecting 41600 events.
[09:56:05.249] INFO: 41600 events read in total (2587ms).
[09:56:05.250] INFO: Test took 3804ms.
[09:56:05.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:05.647] INFO: enter test to run
[09:59:02.789] INFO: test: HighRate no parameter change
[09:59:02.789] INFO: running: highrate
[09:59:02.790] INFO: ----------------------------------------------------------------------
[09:59:02.790] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:59:02.790] INFO: ----------------------------------------------------------------------
[09:59:03.406] INFO: Expecting 208000 events.
[09:59:15.794] INFO: 208000 events read in total (11861ms).
[09:59:15.798] INFO: Test took 12999ms.
[09:59:15.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:16.252] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 5 0 0
[09:59:16.252] INFO: number of red-efficiency pixels: 106 78 130 186 226 211 216 109 121 208 164 161 146 112 34 32
[09:59:16.252] INFO: number of X-ray hits detected: 81929 51004 90503 138937 147598 155026 156592 106198 100458 135955 135977 115087 116843 70181 27853 28871
[09:59:16.252] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:59:16.252] INFO: number of Vcal hits detected: 207889 207922 207771 207792 207764 207781 207780 207889 207878 207788 207828 207832 207849 207639 207966 207968
[09:59:16.252] INFO: Vcal hit fiducial efficiency (%): 99.9 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
[09:59:16.252] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.8 100.0 100.0
[09:59:16.252] INFO: X-ray hit rate [MHz/cm2]: 24.0 14.9 26.5 40.7 43.3 45.4 45.9 31.1 29.4 39.8 39.9 33.7 34.2 20.6 8.2 8.5
[09:59:16.253] INFO: PixTestHighRate::doXPixelAlive() done
[09:59:16.302] INFO: PixTest:: pg_setup set to default.
[09:59:16.317] INFO: enter test to run
[10:00:42.628] INFO: test: HighRate no parameter change
[10:00:42.629] INFO: running: highrate
[10:00:42.630] INFO: ----------------------------------------------------------------------
[10:00:42.630] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:00:42.630] INFO: ----------------------------------------------------------------------
[10:00:43.247] INFO: Expecting 208000 events.
[10:00:58.018] INFO: 208000 events read in total (14244ms).
[10:00:58.025] INFO: Test took 15385ms.
[10:00:58.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:58.741] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 5 0 0
[10:00:58.741] INFO: number of red-efficiency pixels: 257 183 402 608 916 822 766 456 358 835 605 595 472 363 88 75
[10:00:58.741] INFO: number of X-ray hits detected: 168340 105249 186251 284462 301890 318913 320962 218142 208761 278251 279067 237572 241717 145787 58776 59828
[10:00:58.741] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:00:58.741] INFO: number of Vcal hits detected: 207726 207807 207447 207303 206925 207030 207091 207504 207614 207017 207311 207338 207482 207352 207908 207925
[10:00:58.741] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.5 99.6 99.6 99.8 99.8 99.6 99.7 99.7 99.8 99.8 100.0 100.0
[10:00:58.741] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.7 99.5 99.5 99.6 99.8 99.8 99.5 99.7 99.7 99.8 99.7 100.0 100.0
[10:00:58.741] INFO: X-ray hit rate [MHz/cm2]: 49.3 30.8 54.6 83.4 88.5 93.5 94.1 63.9 61.2 81.6 81.8 69.6 70.8 42.7 17.2 17.5
[10:00:58.741] INFO: PixTestHighRate::doXPixelAlive() done
[10:00:58.791] INFO: PixTest:: pg_setup set to default.
[10:00:58.809] INFO: enter test to run
[10:02:58.324] INFO: test: HighRate no parameter change
[10:02:58.324] INFO: running: highrate
[10:02:58.325] INFO: ----------------------------------------------------------------------
[10:02:58.325] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:02:58.325] INFO: ----------------------------------------------------------------------
[10:02:58.943] INFO: Expecting 208000 events.
[10:03:14.880] INFO: 208000 events read in total (15411ms).
[10:03:14.889] INFO: Test took 16554ms.
[10:03:15.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:15.842] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 5 0 0
[10:03:15.842] INFO: number of red-efficiency pixels: 590 345 835 1442 2034 1778 1707 920 745 1751 1338 1283 1027 742 147 122
[10:03:15.843] INFO: number of X-ray hits detected: 248842 154882 275728 421297 445917 470871 474625 323242 310461 410709 412108 350215 356026 215081 86571 88387
[10:03:15.843] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:03:15.843] INFO: number of Vcal hits detected: 207314 207612 206647 206082 204958 205259 205470 206753 207126 205385 206209 206223 206755 206724 207845 207874
[10:03:15.843] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.2 98.6 98.8 98.9 99.5 99.6 98.9 99.2 99.3 99.5 99.6 99.9 99.9
[10:03:15.843] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.3 99.1 98.5 98.7 98.8 99.4 99.6 98.7 99.1 99.1 99.4 99.4 99.9 99.9
[10:03:15.843] INFO: X-ray hit rate [MHz/cm2]: 72.9 45.4 80.8 123.5 130.7 138.0 139.1 94.7 91.0 120.4 120.8 102.7 104.4 63.0 25.4 25.9
[10:03:15.843] INFO: PixTestHighRate::doXPixelAlive() done
[10:03:15.895] INFO: PixTest:: pg_setup set to default.
[10:03:15.911] INFO: enter test to run
[10:03:21.347] INFO: test: exit no parameter change
[10:03:21.742] QUIET: Connection to board 33 closed.
[10:03:21.744] INFO: pXar: this is the end, my friend