[11:46:58.728] INFO: *** Welcome to pxar ***
[11:46:58.728] INFO: *** Today: 2016/06/02
[11:46:58.744] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:46:58.744] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C15.dat
[11:46:58.783] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:46:58.784] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[11:46:58.784] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:46:58.873] INFO: clk: 4
[11:46:58.873] INFO: ctr: 4
[11:46:58.873] INFO: sda: 19
[11:46:58.873] INFO: tin: 9
[11:46:58.873] INFO: level: 15
[11:46:58.873] INFO: triggerdelay: 0
[11:46:58.873] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:46:58.873] INFO: Log level: INFO
[11:46:58.891] QUIET: Connection to board DTB_WREKRL opened.
[11:46:58.894] 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:
------------------------------------------------------
[11:46:58.897] INFO: RPC call hashes of host and DTB match: 398089610
[11:47:00.427] INFO: DUT info:
[11:47:00.428] INFO: The DUT currently contains the following objects:
[11:47:00.428] INFO: 2 TBM Cores tbm08c (2 ON)
[11:47:00.428] INFO: TBM Core alpha (0): 7 registers set
[11:47:00.428] INFO: TBM Core beta (1): 7 registers set
[11:47:00.428] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:47:00.428] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.428] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:47:00.834] INFO: enter 'restricted' command line mode
[11:47:00.834] INFO: enter test to run
[11:47:08.664] INFO: test: PixelAlive no parameter change
[11:47:08.664] INFO: running: pixelalive
[11:47:08.673] INFO: ----------------------------------------------------------------------
[11:47:08.673] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:47:08.673] INFO: ----------------------------------------------------------------------
[11:47:08.998] INFO: Expecting 41600 events.
[11:47:13.340] INFO: 41600 events read in total (3624ms).
[11:47:13.506] INFO: Test took 4831ms.
[11:47:13.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:13.784] INFO: PixTestAlive::aliveTest() done
[11:47:13.784] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 167
[11:47:13.817] INFO: enter test to run
[11:49:48.583] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:49:48.583] INFO: running: highrate
[11:49:48.583] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:49:48.830] INFO: ----------------------------------------------------------------------
[11:49:48.830] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:49:48.830] INFO: ----------------------------------------------------------------------
[11:49:48.831] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:49:48.831] INFO: edge/corner pixel THR is adjusted
[11:49:48.831] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:49:49.790] INFO: Collecting data for 5 seconds...
[11:49:54.806] INFO: Done with hot pixel readout
[11:50:06.577] INFO: PixTest:: pg_setup set to default.
[11:50:06.577] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:06.578] INFO: 21 hot pixels found in step 0
[11:50:07.591] INFO: Collecting data for 5 seconds...
[11:50:12.608] INFO: Done with hot pixel readout
[11:50:24.317] INFO: PixTest:: pg_setup set to default.
[11:50:24.318] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:24.318] INFO: 19 hot pixels found in step 1
[11:50:25.307] INFO: Collecting data for 5 seconds...
[11:50:30.323] INFO: Done with hot pixel readout
[11:50:42.081] INFO: PixTest:: pg_setup set to default.
[11:50:42.082] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:42.082] INFO: 19 hot pixels found in step 2
[11:50:43.071] INFO: Collecting data for 5 seconds...
[11:50:48.088] INFO: Done with hot pixel readout
[11:50:59.844] INFO: PixTest:: pg_setup set to default.
[11:50:59.844] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:59.845] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:59.845] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:50:59.845] INFO: 17 hot pixels found in step 3
[11:51:00.834] INFO: Collecting data for 5 seconds...
[11:51:05.850] INFO: Done with hot pixel readout
[11:51:17.592] INFO: PixTest:: pg_setup set to default.
[11:51:17.592] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:17.592] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:17.592] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:17.593] INFO: 20 hot pixels found in step 4
[11:51:18.582] INFO: Collecting data for 5 seconds...
[11:51:23.599] INFO: Done with hot pixel readout
[11:51:35.379] INFO: PixTest:: pg_setup set to default.
[11:51:35.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:35.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:35.380] INFO: 17 hot pixels found in step 5
[11:51:36.369] INFO: Collecting data for 5 seconds...
[11:51:41.386] INFO: Done with hot pixel readout
[11:51:53.122] INFO: PixTest:: pg_setup set to default.
[11:51:53.122] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:53.122] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:53.122] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:53.122] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:53.122] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:51:53.123] INFO: 13 hot pixels found in step 6
[11:51:54.111] INFO: Collecting data for 5 seconds...
[11:51:59.127] INFO: Done with hot pixel readout
[11:52:10.858] INFO: PixTest:: pg_setup set to default.
[11:52:10.858] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:10.858] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:10.858] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:10.858] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:10.859] INFO: 14 hot pixels found in step 7
[11:52:11.847] INFO: Collecting data for 5 seconds...
[11:52:16.864] INFO: Done with hot pixel readout
[11:52:28.615] INFO: PixTest:: pg_setup set to default.
[11:52:28.615] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:28.616] INFO: 13 hot pixels found in step 8
[11:52:29.606] INFO: Collecting data for 5 seconds...
[11:52:34.622] INFO: Done with hot pixel readout
[11:52:46.400] INFO: PixTest:: pg_setup set to default.
[11:52:46.400] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:46.400] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:46.400] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:46.400] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:46.400] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:46.401] INFO: 13 hot pixels found in step 9
[11:52:47.390] INFO: Collecting data for 5 seconds...
[11:52:52.406] INFO: Done with hot pixel readout
[11:53:04.139] INFO: PixTest:: pg_setup set to default.
[11:53:04.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:04.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:04.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:04.140] INFO: 14 hot pixels found in step 10
[11:53:05.128] INFO: Collecting data for 5 seconds...
[11:53:10.145] INFO: Done with hot pixel readout
[11:53:21.885] INFO: PixTest:: pg_setup set to default.
[11:53:21.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:21.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:21.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:21.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:21.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:21.886] INFO: 11 hot pixels found in step 11
[11:53:22.874] INFO: Collecting data for 5 seconds...
[11:53:27.890] INFO: Done with hot pixel readout
[11:53:39.631] INFO: PixTest:: pg_setup set to default.
[11:53:39.631] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:39.631] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:39.631] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:39.631] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:39.632] INFO: 12 hot pixels found in step 12
[11:53:40.620] INFO: Collecting data for 5 seconds...
[11:53:45.636] INFO: Done with hot pixel readout
[11:53:57.359] INFO: PixTest:: pg_setup set to default.
[11:53:57.359] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:57.360] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:57.360] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:57.360] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:57.360] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:53:57.361] INFO: 14 hot pixels found in step 13
[11:53:58.349] INFO: Collecting data for 5 seconds...
[11:54:03.364] INFO: Done with hot pixel readout
[11:54:15.084] INFO: PixTest:: pg_setup set to default.
[11:54:15.084] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:54:15.084] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:54:15.084] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:54:15.084] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:54:15.085] INFO: 12 hot pixels found in step 14
[11:54:15.117] INFO: 12 hot pixels could not be trimmed and have been masked.
[11:54:15.121] INFO: PixTest::trimHotPixels() done
[11:54:15.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[11:54:15.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[11:54:15.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[11:54:15.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[11:54:15.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[11:54:15.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[11:54:15.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[11:54:15.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[11:54:15.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[11:54:15.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[11:54:15.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[11:54:15.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[11:54:15.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[11:54:15.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[11:54:15.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[11:54:15.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:54:15.211] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[11:54:15.221] INFO: enter test to run
[11:55:07.028] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:55:07.028] INFO: running: highrate
[11:55:07.033] INFO: ----------------------------------------------------------------------
[11:55:07.033] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:55:07.033] INFO: ----------------------------------------------------------------------
[11:55:07.033] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:55:07.033] INFO: edge/corner pixel THR is adjusted
[11:55:07.033] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:55:07.994] INFO: Collecting data for 1 seconds...
[11:55:08.998] INFO: Done with hot pixel readout
[11:55:13.016] INFO: PixTest:: pg_setup set to default.
[11:55:13.017] INFO: 0 hot pixels found in step 0
[11:55:13.022] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:55:13.111] INFO: PixTest::trimHotPixels() done
[11:55:13.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[11:55:13.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[11:55:13.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[11:55:13.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[11:55:13.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[11:55:13.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[11:55:13.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[11:55:13.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[11:55:13.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[11:55:13.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[11:55:13.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[11:55:13.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[11:55:13.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[11:55:13.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[11:55:13.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[11:55:13.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:55:13.202] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-50_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[11:55:13.212] INFO: enter test to run
[11:55:47.980] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:55:47.980] INFO: running: xray
[11:55:47.981] INFO: ----------------------------------------------------------------------
[11:55:47.981] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:55:47.981] INFO: ----------------------------------------------------------------------
[11:55:48.946] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:56:00.373] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:56:29.500] INFO: Resuming triggers.
[11:56:40.927] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:57:10.584] INFO: Resuming triggers.
[11:57:22.010] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:57:51.311] INFO: Resuming triggers.
[11:58:02.737] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:58:32.039] INFO: Resuming triggers.
[11:58:43.468] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:59:12.831] INFO: Resuming triggers.
[11:59:24.259] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:59:53.563] INFO: Resuming triggers.
[12:00:04.992] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:00:34.334] INFO: Resuming triggers.
[12:00:45.761] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:01:15.226] INFO: Resuming triggers.
[12:01:24.137] INFO: data taking finished, elapsed time: 100 seconds.
[12:01:47.367] INFO: PixTest:: pg_setup set to default.
[12:01:47.370] INFO: PixTestXray::doPhRun() done
[12:01:47.513] INFO: enter test to run
[12:02:19.425] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:02:19.425] INFO: running: xray
[12:02:19.426] INFO: ----------------------------------------------------------------------
[12:02:19.426] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:02:19.426] INFO: ----------------------------------------------------------------------
[12:02:20.389] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:02:27.044] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:02:57.141] INFO: Resuming triggers.
[12:03:03.801] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:03:33.893] INFO: Resuming triggers.
[12:03:40.550] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:04:10.702] INFO: Resuming triggers.
[12:04:17.362] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:04:47.474] INFO: Resuming triggers.
[12:04:54.131] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:05:24.288] INFO: Resuming triggers.
[12:05:30.945] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:06:01.073] INFO: Resuming triggers.
[12:06:07.730] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:06:37.840] INFO: Resuming triggers.
[12:06:44.499] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:07:14.604] INFO: Resuming triggers.
[12:07:21.259] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:07:51.277] INFO: Resuming triggers.
[12:07:57.937] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:08:28.123] INFO: Resuming triggers.
[12:08:34.776] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:09:04.818] INFO: Resuming triggers.
[12:09:11.473] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:09:41.587] INFO: Resuming triggers.
[12:09:48.244] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:10:18.356] INFO: Resuming triggers.
[12:10:25.016] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:10:55.116] INFO: Resuming triggers.
[12:11:01.772] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:11:31.923] INFO: Resuming triggers.
[12:11:32.395] INFO: data taking finished, elapsed time: 100 seconds.
[12:11:34.968] INFO: PixTest:: pg_setup set to default.
[12:11:34.971] INFO: PixTestXray::doPhRun() done
[12:11:35.118] INFO: enter test to run
[12:12:02.725] INFO: test: HighRate no parameter change
[12:12:02.725] INFO: running: highrate
[12:12:02.726] INFO: ----------------------------------------------------------------------
[12:12:02.726] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:12:02.726] INFO: ----------------------------------------------------------------------
[12:12:02.867] INFO: Expecting 768 events.
[12:12:03.000] INFO: 768 events read in total (417ms).
[12:12:03.001] INFO: Test took 1269ms.
[12:12:04.803] INFO: Expecting 41600 events.
[12:12:07.848] INFO: 41600 events read in total (2518ms).
[12:12:07.849] INFO: Test took 3839ms.
[12:12:07.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:08.608] INFO: Expecting 41600 events.
[12:12:11.751] INFO: 41600 events read in total (2616ms).
[12:12:11.752] INFO: Test took 3855ms.
[12:12:11.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:12.511] INFO: Expecting 41600 events.
[12:12:15.686] INFO: 41600 events read in total (2648ms).
[12:12:15.687] INFO: Test took 3884ms.
[12:12:15.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:16.444] INFO: Expecting 41600 events.
[12:12:19.625] INFO: 41600 events read in total (2655ms).
[12:12:19.626] INFO: Test took 3887ms.
[12:12:19.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:20.385] INFO: Expecting 41600 events.
[12:12:23.571] INFO: 41600 events read in total (2659ms).
[12:12:23.572] INFO: Test took 3894ms.
[12:12:23.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:24.328] INFO: Expecting 41600 events.
[12:12:27.519] INFO: 41600 events read in total (2664ms).
[12:12:27.520] INFO: Test took 3898ms.
[12:12:27.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:28.277] INFO: Expecting 41600 events.
[12:12:31.468] INFO: 41600 events read in total (2665ms).
[12:12:31.469] INFO: Test took 3898ms.
[12:12:31.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:32.226] INFO: Expecting 41600 events.
[12:12:35.417] INFO: 41600 events read in total (2664ms).
[12:12:35.418] INFO: Test took 3897ms.
[12:12:35.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:36.178] INFO: Expecting 41600 events.
[12:12:39.365] INFO: 41600 events read in total (2660ms).
[12:12:39.366] INFO: Test took 3896ms.
[12:12:39.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:40.125] INFO: Expecting 41600 events.
[12:12:43.315] INFO: 41600 events read in total (2663ms).
[12:12:43.316] INFO: Test took 3900ms.
[12:12:43.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:44.077] INFO: Expecting 41600 events.
[12:12:47.260] INFO: 41600 events read in total (2656ms).
[12:12:47.261] INFO: Test took 3894ms.
[12:12:47.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:48.018] INFO: Expecting 41600 events.
[12:12:51.221] INFO: 41600 events read in total (2676ms).
[12:12:51.222] INFO: Test took 3911ms.
[12:12:51.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:51.982] INFO: Expecting 41600 events.
[12:12:55.168] INFO: 41600 events read in total (2659ms).
[12:12:55.168] INFO: Test took 3896ms.
[12:12:55.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:55.927] INFO: Expecting 41600 events.
[12:12:59.106] INFO: 41600 events read in total (2653ms).
[12:12:59.107] INFO: Test took 3888ms.
[12:12:59.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:59.868] INFO: Expecting 41600 events.
[12:13:03.054] INFO: 41600 events read in total (2660ms).
[12:13:03.055] INFO: Test took 3897ms.
[12:13:03.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:03.817] INFO: Expecting 41600 events.
[12:13:07.014] INFO: 41600 events read in total (2670ms).
[12:13:07.015] INFO: Test took 3909ms.
[12:13:07.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:07.775] INFO: Expecting 41600 events.
[12:13:10.972] INFO: 41600 events read in total (2670ms).
[12:13:10.973] INFO: Test took 3908ms.
[12:13:11.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:11.730] INFO: Expecting 41600 events.
[12:13:14.922] INFO: 41600 events read in total (2666ms).
[12:13:14.923] INFO: Test took 3898ms.
[12:13:14.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:15.683] INFO: Expecting 41600 events.
[12:13:18.869] INFO: 41600 events read in total (2659ms).
[12:13:18.870] INFO: Test took 3895ms.
[12:13:18.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:19.629] INFO: Expecting 41600 events.
[12:13:22.680] INFO: 41600 events read in total (2524ms).
[12:13:22.681] INFO: Test took 3761ms.
[12:13:22.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:23.082] INFO: enter test to run
[12:13:27.220] INFO: test: HighRate no parameter change
[12:13:27.220] INFO: running: highrate
[12:13:27.221] INFO: ----------------------------------------------------------------------
[12:13:27.221] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:13:27.221] INFO: ----------------------------------------------------------------------
[12:13:27.831] INFO: Expecting 208000 events.
[12:13:39.418] INFO: 208000 events read in total (11060ms).
[12:13:39.421] INFO: Test took 12193ms.
[12:13:39.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:39.813] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 4148
[12:13:39.813] INFO: number of red-efficiency pixels: 66 70 98 165 123 156 197 105 121 119 110 118 125 72 29 4160
[12:13:39.813] INFO: number of X-ray hits detected: 62828 42120 66822 106792 111896 115239 113808 81388 86213 89377 89350 77142 83203 48765 22842 27060
[12:13:39.813] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:13:39.813] INFO: number of Vcal hits detected: 207933 207927 207899 207782 207875 207840 207795 207889 207876 207879 207888 207879 207873 207927 207971 12
[12:13:39.813] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 2.0
[12:13:39.813] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 0.0
[12:13:39.813] INFO: X-ray hit rate [MHz/cm2]: 18.4 12.3 19.6 31.3 32.8 33.8 33.4 23.9 25.3 26.2 26.2 22.6 24.4 14.3 6.7 7.9
[12:13:39.813] INFO: PixTestHighRate::doXPixelAlive() done
[12:13:39.865] INFO: PixTest:: pg_setup set to default.
[12:13:39.877] INFO: enter test to run
[12:14:20.564] INFO: test: HighRate no parameter change
[12:14:20.564] INFO: running: highrate
[12:14:20.565] INFO: ----------------------------------------------------------------------
[12:14:20.565] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:14:20.565] INFO: ----------------------------------------------------------------------
[12:14:21.182] INFO: Expecting 208000 events.
[12:14:34.595] INFO: 208000 events read in total (12886ms).
[12:14:34.601] INFO: Test took 14028ms.
[12:14:34.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:35.196] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 4147
[12:14:35.196] INFO: number of red-efficiency pixels: 227 163 316 482 413 492 615 356 387 321 401 319 339 210 57 4160
[12:14:35.196] INFO: number of X-ray hits detected: 132998 88901 140908 226677 238785 243008 242821 174097 184594 189858 190938 165066 176039 103723 48666 57718
[12:14:35.196] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:14:35.196] INFO: number of Vcal hits detected: 207759 207831 207653 207423 207550 207458 207312 207609 207586 207663 207573 207659 207637 207781 207942 13
[12:14:35.196] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 2.0
[12:14:35.196] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 0.0
[12:14:35.196] INFO: X-ray hit rate [MHz/cm2]: 39.0 26.1 41.3 66.4 70.0 71.2 71.2 51.0 54.1 55.6 56.0 48.4 51.6 30.4 14.3 16.9
[12:14:35.196] INFO: PixTestHighRate::doXPixelAlive() done
[12:14:35.249] INFO: PixTest:: pg_setup set to default.
[12:14:35.260] INFO: enter test to run
[12:14:59.051] INFO: test: HighRate no parameter change
[12:14:59.051] INFO: running: highrate
[12:14:59.053] INFO: ----------------------------------------------------------------------
[12:14:59.053] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:14:59.053] INFO: ----------------------------------------------------------------------
[12:14:59.664] INFO: Expecting 208000 events.
[12:15:14.982] INFO: 208000 events read in total (14791ms).
[12:15:14.989] INFO: Test took 15928ms.
[12:15:15.434] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:15.783] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 4137
[12:15:15.783] INFO: number of red-efficiency pixels: 449 317 701 989 1012 1139 1447 844 867 699 892 635 699 480 106 4160
[12:15:15.783] INFO: number of X-ray hits detected: 201891 134443 215314 342721 361962 369394 367084 263661 280616 289034 289879 251625 267328 157777 73980 86855
[12:15:15.783] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:15:15.783] INFO: number of Vcal hits detected: 207482 207654 207084 206741 206776 206541 206046 206919 206970 207208 206919 207273 207199 207451 207892 23
[12:15:15.783] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.5 99.5 99.4 99.2 99.5 99.5 99.7 99.5 99.7 99.7 99.8 100.0 2.0
[12:15:15.783] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.6 99.4 99.4 99.3 99.1 99.5 99.5 99.6 99.5 99.7 99.6 99.7 99.9 0.0
[12:15:15.783] INFO: X-ray hit rate [MHz/cm2]: 59.2 39.4 63.1 100.5 106.1 108.3 107.6 77.3 82.3 84.7 85.0 73.8 78.4 46.2 21.7 25.5
[12:15:15.783] INFO: PixTestHighRate::doXPixelAlive() done
[12:15:15.841] INFO: PixTest:: pg_setup set to default.
[12:15:15.862] INFO: enter test to run
[12:15:40.475] INFO: test: exit no parameter change
[12:15:40.815] QUIET: Connection to board 33 closed.
[12:15:40.817] INFO: pXar: this is the end, my friend