[14:02:35.700] INFO: *** Welcome to pxar ***
[14:02:35.701] INFO: *** Today: 2016/06/06
[14:02:36.403] INFO: *** Version: v1.9.0-814-g7497
[14:02:36.403] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//dacParameters35_C15.dat
[14:02:36.448] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:02:36.448] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[14:02:36.450] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[14:02:36.564] INFO: clk: 4
[14:02:36.564] INFO: ctr: 4
[14:02:36.564] INFO: sda: 19
[14:02:36.564] INFO: tin: 9
[14:02:36.565] INFO: level: 15
[14:02:36.565] INFO: triggerdelay: 0
[14:02:36.565] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:02:36.565] INFO: Log level: INFO
[14:02:36.580] QUIET: Connection to board DTB_WREKRL opened.
[14:02:36.583] 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:
------------------------------------------------------
[14:02:36.586] INFO: RPC call hashes of host and DTB match: 398089610
[14:02:38.132] INFO: DUT info:
[14:02:38.132] INFO: The DUT currently contains the following objects:
[14:02:38.132] INFO: 2 TBM Cores tbm08c (2 ON)
[14:02:38.132] INFO: TBM Core alpha (0): 7 registers set
[14:02:38.132] INFO: TBM Core beta (1): 7 registers set
[14:02:38.132] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:02:38.132] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.132] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.132] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.132] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.132] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.132] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.133] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:38.536] INFO: enter 'restricted' command line mode
[14:02:38.536] INFO: enter test to run
[14:02:41.402] INFO: test: PixelAlive no parameter change
[14:02:41.402] INFO: running: pixelalive
[14:02:41.411] INFO: ----------------------------------------------------------------------
[14:02:41.411] 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:02:41.411] INFO: ----------------------------------------------------------------------
[14:02:41.732] INFO: Expecting 41600 events.
[14:02:45.971] INFO: 41600 events read in total (3520ms).
[14:02:46.135] INFO: Test took 4721ms.
[14:02:46.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:46.424] INFO: PixTestAlive::aliveTest() done
[14:02:46.424] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 0 0 0 0 1 0
[14:02:46.451] INFO: enter test to run
[14:04:09.185] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:04:09.185] INFO: running: highrate
[14:04:09.222] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:04:09.572] INFO: ----------------------------------------------------------------------
[14:04:09.572] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:04:09.572] INFO: ----------------------------------------------------------------------
[14:04:09.572] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:04:09.572] INFO: edge/corner pixel THR is adjusted
[14:04:09.572] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:04:10.531] INFO: Collecting data for 5 seconds...
[14:04:15.547] INFO: Done with hot pixel readout
[14:04:27.411] INFO: PixTest:: pg_setup set to default.
[14:04:27.412] INFO: 60 hot pixels found in step 0
[14:04:28.447] INFO: Collecting data for 5 seconds...
[14:04:33.464] INFO: Done with hot pixel readout
[14:04:45.399] INFO: PixTest:: pg_setup set to default.
[14:04:45.400] INFO: 72 hot pixels found in step 1
[14:04:46.395] INFO: Collecting data for 5 seconds...
[14:04:51.413] INFO: Done with hot pixel readout
[14:05:03.500] INFO: PixTest:: pg_setup set to default.
[14:05:03.500] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:03.501] INFO: 69 hot pixels found in step 2
[14:05:04.495] INFO: Collecting data for 5 seconds...
[14:05:09.512] INFO: Done with hot pixel readout
[14:05:21.808] INFO: PixTest:: pg_setup set to default.
[14:05:21.809] INFO: 63 hot pixels found in step 3
[14:05:22.804] INFO: Collecting data for 5 seconds...
[14:05:27.820] INFO: Done with hot pixel readout
[14:05:39.950] INFO: PixTest:: pg_setup set to default.
[14:05:39.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:39.951] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:39.951] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:39.951] INFO: 67 hot pixels found in step 4
[14:05:40.946] INFO: Collecting data for 5 seconds...
[14:05:45.962] INFO: Done with hot pixel readout
[14:05:58.104] INFO: PixTest:: pg_setup set to default.
[14:05:58.105] INFO: 57 hot pixels found in step 5
[14:05:59.099] INFO: Collecting data for 5 seconds...
[14:06:04.116] INFO: Done with hot pixel readout
[14:06:16.380] INFO: PixTest:: pg_setup set to default.
[14:06:16.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.381] INFO: 57 hot pixels found in step 6
[14:06:17.375] INFO: Collecting data for 5 seconds...
[14:06:22.391] INFO: Done with hot pixel readout
[14:06:34.608] INFO: PixTest:: pg_setup set to default.
[14:06:34.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:34.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:34.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:34.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:34.608] INFO: 50 hot pixels found in step 7
[14:06:35.602] INFO: Collecting data for 5 seconds...
[14:06:40.619] INFO: Done with hot pixel readout
[14:06:52.611] INFO: PixTest:: pg_setup set to default.
[14:06:52.611] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:52.612] INFO: 42 hot pixels found in step 8
[14:06:53.607] INFO: Collecting data for 5 seconds...
[14:06:58.623] INFO: Done with hot pixel readout
[14:07:10.846] INFO: PixTest:: pg_setup set to default.
[14:07:10.846] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:10.846] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:10.846] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:10.846] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:10.847] INFO: 37 hot pixels found in step 9
[14:07:11.842] INFO: Collecting data for 5 seconds...
[14:07:16.857] INFO: Done with hot pixel readout
[14:07:28.888] INFO: PixTest:: pg_setup set to default.
[14:07:28.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:28.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:28.889] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:28.889] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:28.889] INFO: 31 hot pixels found in step 10
[14:07:29.888] INFO: Collecting data for 5 seconds...
[14:07:34.904] INFO: Done with hot pixel readout
[14:07:46.773] INFO: PixTest:: pg_setup set to default.
[14:07:46.773] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:46.774] INFO: 25 hot pixels found in step 11
[14:07:47.768] INFO: Collecting data for 5 seconds...
[14:07:52.785] INFO: Done with hot pixel readout
[14:08:04.681] INFO: PixTest:: pg_setup set to default.
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.681] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:04.682] INFO: 32 hot pixels found in step 12
[14:08:05.676] INFO: Collecting data for 5 seconds...
[14:08:10.693] INFO: Done with hot pixel readout
[14:08:22.828] INFO: PixTest:: pg_setup set to default.
[14:08:22.828] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.828] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:22.829] INFO: 41 hot pixels found in step 13
[14:08:23.829] INFO: Collecting data for 5 seconds...
[14:08:28.845] INFO: Done with hot pixel readout
[14:08:41.023] INFO: PixTest:: pg_setup set to default.
[14:08:41.023] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:41.023] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:41.023] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:41.024] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:41.024] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:41.025] INFO: 29 hot pixels found in step 14
[14:08:41.069] INFO: 29 hot pixels could not be trimmed and have been masked.
[14:08:41.073] INFO: PixTest::trimHotPixels() done
[14:08:41.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat
[14:08:41.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C1.dat
[14:08:41.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C2.dat
[14:08:41.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C3.dat
[14:08:41.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C4.dat
[14:08:41.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C5.dat
[14:08:41.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C6.dat
[14:08:41.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C7.dat
[14:08:41.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C8.dat
[14:08:41.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C9.dat
[14:08:41.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C10.dat
[14:08:41.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C11.dat
[14:08:41.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C12.dat
[14:08:41.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C13.dat
[14:08:41.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C14.dat
[14:08:41.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[14:08:41.169] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[14:08:41.180] INFO: enter test to run
[14:09:00.511] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:09:00.511] INFO: running: highrate
[14:09:00.516] INFO: ----------------------------------------------------------------------
[14:09:00.516] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:09:00.516] INFO: ----------------------------------------------------------------------
[14:09:00.516] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:09:00.516] INFO: edge/corner pixel THR is adjusted
[14:09:00.516] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:09:01.473] INFO: Collecting data for 1 seconds...
[14:09:02.478] INFO: Done with hot pixel readout
[14:09:06.944] INFO: PixTest:: pg_setup set to default.
[14:09:06.945] INFO: 0 hot pixels found in step 0
[14:09:06.950] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:09:07.013] INFO: PixTest::trimHotPixels() done
[14:09:07.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat
[14:09:07.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C1.dat
[14:09:07.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C2.dat
[14:09:07.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C3.dat
[14:09:07.040] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C4.dat
[14:09:07.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C5.dat
[14:09:07.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C6.dat
[14:09:07.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C7.dat
[14:09:07.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C8.dat
[14:09:07.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C9.dat
[14:09:07.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C10.dat
[14:09:07.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C11.dat
[14:09:07.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C12.dat
[14:09:07.092] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C13.dat
[14:09:07.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C14.dat
[14:09:07.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[14:09:07.109] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NG_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[14:09:07.118] INFO: enter test to run
[14:09:59.382] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:09:59.382] INFO: running: xray
[14:09:59.383] INFO: ----------------------------------------------------------------------
[14:09:59.383] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:09:59.383] INFO: ----------------------------------------------------------------------
[14:10:00.346] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:10:10.668] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:10:39.347] INFO: Resuming triggers.
[14:10:49.672] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:11:18.854] INFO: Resuming triggers.
[14:11:29.175] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:11:57.929] INFO: Resuming triggers.
[14:12:08.250] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:12:37.583] INFO: Resuming triggers.
[14:12:47.904] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:13:16.895] INFO: Resuming triggers.
[14:13:27.211] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:13:56.507] INFO: Resuming triggers.
[14:14:06.829] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:14:35.177] INFO: Resuming triggers.
[14:14:45.494] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:15:14.730] INFO: Resuming triggers.
[14:15:25.045] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:15:54.404] INFO: Resuming triggers.
[14:16:01.874] INFO: data taking finished, elapsed time: 100 seconds.
[14:16:22.873] INFO: PixTest:: pg_setup set to default.
[14:16:22.876] INFO: PixTestXray::doPhRun() done
[14:16:23.030] INFO: enter test to run
[14:17:04.363] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:17:04.363] INFO: running: xray
[14:17:04.364] INFO: ----------------------------------------------------------------------
[14:17:04.364] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:17:04.364] INFO: ----------------------------------------------------------------------
[14:17:05.326] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:17:10.923] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[14:17:39.977] INFO: Resuming triggers.
[14:17:45.578] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:18:15.325] INFO: Resuming triggers.
[14:18:20.924] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[14:18:51.531] INFO: Resuming triggers.
[14:18:57.134] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:19:27.499] INFO: Resuming triggers.
[14:19:33.099] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:20:04.031] INFO: Resuming triggers.
[14:20:09.632] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:20:39.951] INFO: Resuming triggers.
[14:20:45.551] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:21:15.691] INFO: Resuming triggers.
[14:21:21.293] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:21:51.554] INFO: Resuming triggers.
[14:21:57.156] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[14:22:28.832] INFO: Resuming triggers.
[14:22:34.433] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:23:04.558] INFO: Resuming triggers.
[14:23:10.158] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:23:40.708] INFO: Resuming triggers.
[14:23:46.310] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:24:16.872] INFO: Resuming triggers.
[14:24:22.470] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:24:53.408] INFO: Resuming triggers.
[14:24:59.009] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:25:30.199] INFO: Resuming triggers.
[14:25:35.802] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:26:06.903] INFO: Resuming triggers.
[14:26:12.502] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:26:42.694] INFO: Resuming triggers.
[14:26:48.290] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:27:18.413] INFO: Resuming triggers.
[14:27:23.551] INFO: data taking finished, elapsed time: 100 seconds.
[14:27:51.400] INFO: PixTest:: pg_setup set to default.
[14:27:51.404] INFO: PixTestXray::doPhRun() done
[14:27:51.554] INFO: enter test to run
[14:29:56.141] INFO: test: HighRate no parameter change
[14:29:56.141] INFO: running: highrate
[14:29:56.158] INFO: ----------------------------------------------------------------------
[14:29:56.158] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:29:56.158] INFO: ----------------------------------------------------------------------
[14:29:56.313] INFO: Expecting 768 events.
[14:29:57.447] INFO: 768 events read in total (419ms).
[14:29:57.447] INFO: Test took 1268ms.
[14:29:58.251] INFO: Expecting 41600 events.
[14:30:01.340] INFO: 41600 events read in total (2562ms).
[14:30:01.341] INFO: Test took 3887ms.
[14:30:01.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:02.095] INFO: Expecting 41600 events.
[14:30:05.379] INFO: 41600 events read in total (2757ms).
[14:30:05.380] INFO: Test took 3976ms.
[14:30:05.423] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:06.132] INFO: Expecting 41600 events.
[14:30:09.449] INFO: 41600 events read in total (2790ms).
[14:30:09.450] INFO: Test took 4006ms.
[14:30:09.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:10.201] INFO: Expecting 41600 events.
[14:30:13.588] INFO: 41600 events read in total (2860ms).
[14:30:13.589] INFO: Test took 4075ms.
[14:30:13.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:14.337] INFO: Expecting 41600 events.
[14:30:17.551] INFO: 41600 events read in total (2687ms).
[14:30:17.553] INFO: Test took 3898ms.
[14:30:17.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:18.300] INFO: Expecting 41600 events.
[14:30:21.602] INFO: 41600 events read in total (2775ms).
[14:30:21.603] INFO: Test took 3980ms.
[14:30:21.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:22.350] INFO: Expecting 41600 events.
[14:30:25.707] INFO: 41600 events read in total (2831ms).
[14:30:25.708] INFO: Test took 4041ms.
[14:30:25.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:26.454] INFO: Expecting 41600 events.
[14:30:29.619] INFO: 41600 events read in total (2638ms).
[14:30:29.620] INFO: Test took 3845ms.
[14:30:29.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:30.364] INFO: Expecting 41600 events.
[14:30:33.618] INFO: 41600 events read in total (2728ms).
[14:30:33.619] INFO: Test took 3931ms.
[14:30:33.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:34.369] INFO: Expecting 41600 events.
[14:30:37.650] INFO: 41600 events read in total (2755ms).
[14:30:37.651] INFO: Test took 3966ms.
[14:30:37.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:38.401] INFO: Expecting 41600 events.
[14:30:41.679] INFO: 41600 events read in total (2751ms).
[14:30:41.680] INFO: Test took 3963ms.
[14:30:41.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:42.426] INFO: Expecting 41600 events.
[14:30:45.760] INFO: 41600 events read in total (2807ms).
[14:30:45.761] INFO: Test took 4017ms.
[14:30:45.804] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:46.511] INFO: Expecting 41600 events.
[14:30:49.857] INFO: 41600 events read in total (2819ms).
[14:30:49.859] INFO: Test took 4032ms.
[14:30:49.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:50.606] INFO: Expecting 41600 events.
[14:30:53.898] INFO: 41600 events read in total (2766ms).
[14:30:53.899] INFO: Test took 3972ms.
[14:30:53.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:54.649] INFO: Expecting 41600 events.
[14:30:57.975] INFO: 41600 events read in total (2799ms).
[14:30:57.976] INFO: Test took 4011ms.
[14:30:58.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:58.725] INFO: Expecting 41600 events.
[14:31:01.995] INFO: 41600 events read in total (2743ms).
[14:31:01.996] INFO: Test took 3955ms.
[14:31:02.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:02.745] INFO: Expecting 41600 events.
[14:31:06.078] INFO: 41600 events read in total (2806ms).
[14:31:06.079] INFO: Test took 4015ms.
[14:31:06.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:06.830] INFO: Expecting 41600 events.
[14:31:10.158] INFO: 41600 events read in total (2801ms).
[14:31:10.159] INFO: Test took 4015ms.
[14:31:10.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:10.909] INFO: Expecting 41600 events.
[14:31:14.258] INFO: 41600 events read in total (2822ms).
[14:31:14.259] INFO: Test took 4035ms.
[14:31:14.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:15.005] INFO: Expecting 41600 events.
[14:31:18.263] INFO: 41600 events read in total (2731ms).
[14:31:18.265] INFO: Test took 3940ms.
[14:31:18.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:18.646] INFO: enter test to run
[14:32:00.428] INFO: test: HighRate no parameter change
[14:32:00.428] INFO: running: highrate
[14:32:00.429] INFO: ----------------------------------------------------------------------
[14:32:00.429] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:32:00.429] INFO: ----------------------------------------------------------------------
[14:32:01.061] INFO: Expecting 208000 events.
[14:32:12.393] INFO: 208000 events read in total (10806ms).
[14:32:12.398] INFO: Test took 11961ms.
[14:32:12.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:12.873] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 0 0 0 0 1 0
[14:32:12.873] INFO: number of red-efficiency pixels: 102 74 107 160 213 206 232 138 129 163 161 136 182 85 29 33
[14:32:12.873] INFO: number of X-ray hits detected: 89568 61554 92539 143213 153697 151376 153272 111088 100648 132663 134651 114505 122399 69503 28380 31058
[14:32:12.873] 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:32:12.873] INFO: number of Vcal hits detected: 207894 207877 207889 207787 207780 207785 207765 207860 207869 207835 207836 207862 207811 207909 207922 207967
[14:32:12.873] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:32:12.873] INFO: Vcal hit overall efficiency (%): 99.9 99.9 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
[14:32:12.873] INFO: X-ray hit rate [MHz/cm2]: 26.3 18.0 27.1 42.0 45.0 44.4 44.9 32.6 29.5 38.9 39.5 33.6 35.9 20.4 8.3 9.1
[14:32:12.873] INFO: PixTestHighRate::doXPixelAlive() done
[14:32:12.918] INFO: PixTest:: pg_setup set to default.
[14:32:12.927] INFO: enter test to run
[14:32:31.740] INFO: test: HighRate no parameter change
[14:32:31.740] INFO: running: highrate
[14:32:31.741] INFO: ----------------------------------------------------------------------
[14:32:31.741] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:32:31.741] INFO: ----------------------------------------------------------------------
[14:32:32.362] INFO: Expecting 208000 events.
[14:32:46.895] INFO: 208000 events read in total (14007ms).
[14:32:46.902] INFO: Test took 15151ms.
[14:32:47.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:47.631] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 0 0 0 0 1 0
[14:32:47.631] INFO: number of red-efficiency pixels: 297 194 373 628 788 726 982 427 378 521 536 415 629 251 59 73
[14:32:47.631] INFO: number of X-ray hits detected: 179005 124227 186841 288087 311149 304640 308676 224824 202940 267966 272552 230512 247936 141452 57520 62644
[14:32:47.631] 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:32:47.631] INFO: number of Vcal hits detected: 207673 207752 207557 207253 207115 207176 206827 207514 207592 207427 207413 207552 207314 207726 207890 207927
[14:32:47.631] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.6 99.5 99.8 99.8 99.7 99.7 99.8 99.7 99.9 100.0 100.0
[14:32:47.631] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.4 99.8 99.8 99.7 99.7 99.8 99.7 99.9 99.9 100.0
[14:32:47.631] INFO: X-ray hit rate [MHz/cm2]: 52.5 36.4 54.8 84.4 91.2 89.3 90.5 65.9 59.5 78.5 79.9 67.6 72.7 41.5 16.9 18.4
[14:32:47.631] INFO: PixTestHighRate::doXPixelAlive() done
[14:32:47.677] INFO: PixTest:: pg_setup set to default.
[14:32:47.697] INFO: enter test to run
[14:33:52.780] INFO: test: HighRate no parameter change
[14:33:52.780] INFO: running: highrate
[14:33:52.781] INFO: ----------------------------------------------------------------------
[14:33:52.781] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:33:52.781] INFO: ----------------------------------------------------------------------
[14:33:53.407] INFO: Expecting 208000 events.
[14:34:10.339] INFO: 208000 events read in total (16405ms).
[14:34:10.351] INFO: Test took 17559ms.
[14:34:10.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:11.386] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 0 0 0 0 1 0
[14:34:11.386] INFO: number of red-efficiency pixels: 651 458 906 1501 1826 1737 2251 1059 1015 1308 1331 1090 1558 599 133 131
[14:34:11.386] INFO: number of X-ray hits detected: 272689 188872 284480 439128 470200 464734 471460 343393 309591 410520 415561 353077 377171 217320 87797 96287
[14:34:11.386] 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:34:11.386] INFO: number of Vcal hits detected: 207139 207397 206639 205897 205239 205422 204240 206561 206734 206284 206209 206614 205836 207253 207810 207867
[14:34:11.386] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.4 99.1 98.8 98.9 98.4 99.4 99.4 99.3 99.2 99.4 99.1 99.7 99.9 99.9
[14:34:11.386] INFO: Vcal hit overall efficiency (%): 99.6 99.7 99.3 99.0 98.7 98.8 98.2 99.3 99.4 99.2 99.1 99.3 99.0 99.6 99.9 99.9
[14:34:11.386] INFO: X-ray hit rate [MHz/cm2]: 79.9 55.4 83.4 128.7 137.8 136.2 138.2 100.7 90.7 120.3 121.8 103.5 110.6 63.7 25.7 28.2
[14:34:11.386] INFO: PixTestHighRate::doXPixelAlive() done
[14:34:11.432] INFO: PixTest:: pg_setup set to default.
[14:34:11.448] INFO: enter test to run
[14:35:10.171] INFO: test: exit no parameter change
[14:35:10.590] QUIET: Connection to board 33 closed.
[14:35:10.619] INFO: pXar: this is the end, my friend