[10:35:53.596] INFO: *** Welcome to pxar ***
[10:35:53.596] INFO: *** Today: 2016/04/18
[10:35:53.614] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:35:53.614] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//dacParameters35_C15.dat
[10:35:53.634] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:35:53.634] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[10:35:53.634] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[10:35:53.724] INFO: clk: 4
[10:35:53.724] INFO: ctr: 4
[10:35:53.724] INFO: sda: 19
[10:35:53.724] INFO: tin: 9
[10:35:53.724] INFO: level: 15
[10:35:53.724] INFO: triggerdelay: 0
[10:35:53.724] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:35:53.724] INFO: Log level: INFO
[10:35:53.741] QUIET: Connection to board DTB_WREKRL opened.
[10:35:53.745] 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:
------------------------------------------------------
[10:35:53.748] INFO: RPC call hashes of host and DTB match: 398089610
[10:35:55.285] INFO: DUT info:
[10:35:55.285] INFO: The DUT currently contains the following objects:
[10:35:55.285] INFO: 2 TBM Cores tbm08c (2 ON)
[10:35:55.285] INFO: TBM Core alpha (0): 7 registers set
[10:35:55.285] INFO: TBM Core beta (1): 7 registers set
[10:35:55.285] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:35:55.285] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.285] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:35:55.711] INFO: enter 'restricted' command line mode
[10:35:55.711] INFO: enter test to run
[10:36:01.845] INFO: test: PixelAlive no parameter change
[10:36:01.845] INFO: running: pixelalive
[10:36:01.854] INFO: ----------------------------------------------------------------------
[10:36:01.854] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:36:01.854] INFO: ----------------------------------------------------------------------
[10:36:02.171] INFO: Expecting 41600 events.
[10:36:06.510] INFO: 41600 events read in total (3620ms).
[10:36:06.677] INFO: Test took 4821ms.
[10:36:06.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:06.953] INFO: PixTestAlive::aliveTest() done
[10:36:06.953] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 3 0
[10:36:06.986] INFO: enter test to run
[10:36:32.980] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:36:32.981] INFO: running: highrate
[10:36:32.981] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:36:33.197] INFO: ----------------------------------------------------------------------
[10:36:33.197] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:36:33.197] INFO: ----------------------------------------------------------------------
[10:36:33.197] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:36:33.197] INFO: edge/corner pixel THR is adjusted
[10:36:33.197] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:36:34.157] INFO: Collecting data for 5 seconds...
[10:36:39.173] INFO: Done with hot pixel readout
[10:36:51.325] INFO: PixTest:: pg_setup set to default.
[10:36:51.325] INFO: 13 hot pixels found in step 0
[10:36:52.344] INFO: Collecting data for 5 seconds...
[10:36:57.361] INFO: Done with hot pixel readout
[10:37:09.469] INFO: PixTest:: pg_setup set to default.
[10:37:09.470] INFO: 11 hot pixels found in step 1
[10:37:10.464] INFO: Collecting data for 5 seconds...
[10:37:15.480] INFO: Done with hot pixel readout
[10:37:27.627] INFO: PixTest:: pg_setup set to default.
[10:37:27.628] INFO: 12 hot pixels found in step 2
[10:37:28.622] INFO: Collecting data for 5 seconds...
[10:37:33.639] INFO: Done with hot pixel readout
[10:37:45.737] INFO: PixTest:: pg_setup set to default.
[10:37:45.738] INFO: 13 hot pixels found in step 3
[10:37:46.733] INFO: Collecting data for 5 seconds...
[10:37:51.749] INFO: Done with hot pixel readout
[10:38:03.879] INFO: PixTest:: pg_setup set to default.
[10:38:03.879] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:03.880] INFO: 14 hot pixels found in step 4
[10:38:04.875] INFO: Collecting data for 5 seconds...
[10:38:09.892] INFO: Done with hot pixel readout
[10:38:21.999] INFO: PixTest:: pg_setup set to default.
[10:38:21.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:21.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:21.999] INFO: 13 hot pixels found in step 5
[10:38:22.995] INFO: Collecting data for 5 seconds...
[10:38:28.012] INFO: Done with hot pixel readout
[10:38:40.105] INFO: PixTest:: pg_setup set to default.
[10:38:40.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:40.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:40.106] INFO: 9 hot pixels found in step 6
[10:38:41.101] INFO: Collecting data for 5 seconds...
[10:38:46.111] INFO: Done with hot pixel readout
[10:38:55.469] INFO: PixTest:: pg_setup set to default.
[10:38:55.469] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:55.470] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:55.470] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:38:55.470] INFO: 10 hot pixels found in step 7
[10:38:56.465] INFO: Collecting data for 5 seconds...
[10:39:01.479] INFO: Done with hot pixel readout
[10:39:13.587] INFO: PixTest:: pg_setup set to default.
[10:39:13.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:13.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:13.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:13.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:13.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:13.588] INFO: 12 hot pixels found in step 8
[10:39:14.583] INFO: Collecting data for 5 seconds...
[10:39:19.600] INFO: Done with hot pixel readout
[10:39:31.743] INFO: PixTest:: pg_setup set to default.
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.743] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:31.744] INFO: 10 hot pixels found in step 9
[10:39:32.739] INFO: Collecting data for 5 seconds...
[10:39:37.755] INFO: Done with hot pixel readout
[10:39:49.851] INFO: PixTest:: pg_setup set to default.
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.851] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:39:49.852] INFO: 8 hot pixels found in step 10
[10:39:50.847] INFO: Collecting data for 5 seconds...
[10:39:55.863] INFO: Done with hot pixel readout
[10:40:07.936] INFO: PixTest:: pg_setup set to default.
[10:40:07.937] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:07.937] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:07.937] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:07.937] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:07.937] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:07.937] INFO: 7 hot pixels found in step 11
[10:40:08.932] INFO: Collecting data for 5 seconds...
[10:40:13.949] INFO: Done with hot pixel readout
[10:40:26.069] INFO: PixTest:: pg_setup set to default.
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:26.070] INFO: 9 hot pixels found in step 12
[10:40:27.065] INFO: Collecting data for 5 seconds...
[10:40:32.082] INFO: Done with hot pixel readout
[10:40:44.212] INFO: PixTest:: pg_setup set to default.
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:40:44.213] INFO: 9 hot pixels found in step 13
[10:40:45.208] INFO: Collecting data for 5 seconds...
[10:40:50.224] INFO: Done with hot pixel readout
[10:41:02.342] INFO: PixTest:: pg_setup set to default.
[10:41:02.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:41:02.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:41:02.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:41:02.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:41:02.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:41:02.343] INFO: 5 hot pixels found in step 14
[10:41:02.382] INFO: 5 hot pixels could not be trimmed and have been masked.
[10:41:02.386] INFO: PixTest::trimHotPixels() done
[10:41:02.386] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat
[10:41:02.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C1.dat
[10:41:02.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C2.dat
[10:41:02.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C3.dat
[10:41:02.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C4.dat
[10:41:02.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C5.dat
[10:41:02.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C6.dat
[10:41:02.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C7.dat
[10:41:02.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C8.dat
[10:41:02.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C9.dat
[10:41:02.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C10.dat
[10:41:02.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C11.dat
[10:41:02.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C12.dat
[10:41:02.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C13.dat
[10:41:02.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C14.dat
[10:41:02.466] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[10:41:02.471] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[10:41:02.481] INFO: enter test to run
[10:41:34.610] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:41:34.610] INFO: running: highrate
[10:41:34.615] INFO: ----------------------------------------------------------------------
[10:41:34.615] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:41:34.615] INFO: ----------------------------------------------------------------------
[10:41:34.615] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:41:34.615] INFO: edge/corner pixel THR is adjusted
[10:41:34.615] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:41:35.574] INFO: Collecting data for 1 seconds...
[10:41:36.577] INFO: Done with hot pixel readout
[10:41:40.765] INFO: PixTest:: pg_setup set to default.
[10:41:40.766] INFO: 0 hot pixels found in step 0
[10:41:40.773] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:41:40.859] INFO: PixTest::trimHotPixels() done
[10:41:40.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat
[10:41:40.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C1.dat
[10:41:40.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C2.dat
[10:41:40.877] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C3.dat
[10:41:40.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C4.dat
[10:41:40.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C5.dat
[10:41:40.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C6.dat
[10:41:40.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C7.dat
[10:41:40.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C8.dat
[10:41:40.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C9.dat
[10:41:40.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C10.dat
[10:41:40.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C11.dat
[10:41:40.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C12.dat
[10:41:40.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C13.dat
[10:41:40.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C14.dat
[10:41:40.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[10:41:40.945] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-40_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[10:41:40.955] INFO: enter test to run
[10:42:04.146] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:42:04.146] INFO: running: xray
[10:42:04.147] INFO: ----------------------------------------------------------------------
[10:42:04.147] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:42:04.147] INFO: ----------------------------------------------------------------------
[10:42:05.113] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:42:16.230] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:42:45.462] INFO: Resuming triggers.
[10:42:56.574] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:43:26.014] INFO: Resuming triggers.
[10:43:37.125] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:44:06.747] INFO: Resuming triggers.
[10:44:17.862] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:44:47.411] INFO: Resuming triggers.
[10:44:58.524] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:45:28.073] INFO: Resuming triggers.
[10:45:39.186] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:46:08.757] INFO: Resuming triggers.
[10:46:19.871] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[10:46:49.346] INFO: Resuming triggers.
[10:47:00.460] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:47:29.990] INFO: Resuming triggers.
[10:47:41.102] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:48:10.675] INFO: Resuming triggers.
[10:48:10.993] INFO: data taking finished, elapsed time: 100 seconds.
[10:48:12.296] INFO: PixTest:: pg_setup set to default.
[10:48:12.299] INFO: PixTestXray::doPhRun() done
[10:48:12.436] INFO: enter test to run
[10:48:49.711] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:48:49.711] INFO: running: xray
[10:48:49.712] INFO: ----------------------------------------------------------------------
[10:48:49.712] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:48:49.712] INFO: ----------------------------------------------------------------------
[10:48:50.674] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:48:57.006] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:49:24.800] INFO: Resuming triggers.
[10:49:31.130] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:50:01.095] INFO: Resuming triggers.
[10:50:07.424] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[10:50:37.472] INFO: Resuming triggers.
[10:50:43.803] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:51:13.921] INFO: Resuming triggers.
[10:51:20.251] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:51:50.241] INFO: Resuming triggers.
[10:51:56.575] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[10:52:26.628] INFO: Resuming triggers.
[10:52:32.957] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:53:03.187] INFO: Resuming triggers.
[10:53:09.521] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[10:53:39.553] INFO: Resuming triggers.
[10:53:45.883] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[10:54:15.825] INFO: Resuming triggers.
[10:54:22.153] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:54:52.135] INFO: Resuming triggers.
[10:54:58.464] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:55:28.431] INFO: Resuming triggers.
[10:55:34.757] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[10:56:04.809] INFO: Resuming triggers.
[10:56:11.134] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:56:41.094] INFO: Resuming triggers.
[10:56:47.419] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:57:17.499] INFO: Resuming triggers.
[10:57:23.824] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:57:53.871] INFO: Resuming triggers.
[10:57:59.255] INFO: data taking finished, elapsed time: 100 seconds.
[10:58:25.171] INFO: PixTest:: pg_setup set to default.
[10:58:25.174] INFO: PixTestXray::doPhRun() done
[10:58:25.324] INFO: enter test to run
[11:00:25.314] INFO: test: HighRate no parameter change
[11:00:25.314] INFO: running: highrate
[11:00:25.315] INFO: ----------------------------------------------------------------------
[11:00:25.315] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:00:25.315] INFO: ----------------------------------------------------------------------
[11:00:25.457] INFO: Expecting 768 events.
[11:00:26.587] INFO: 768 events read in total (414ms).
[11:00:26.588] INFO: Test took 1265ms.
[11:00:27.391] INFO: Expecting 41600 events.
[11:00:30.467] INFO: 41600 events read in total (2549ms).
[11:00:30.468] INFO: Test took 3872ms.
[11:00:30.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:31.227] INFO: Expecting 41600 events.
[11:00:34.443] INFO: 41600 events read in total (2689ms).
[11:00:34.444] INFO: Test took 3923ms.
[11:00:34.479] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:35.200] INFO: Expecting 41600 events.
[11:00:38.440] INFO: 41600 events read in total (2713ms).
[11:00:38.441] INFO: Test took 3945ms.
[11:00:38.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:39.198] INFO: Expecting 41600 events.
[11:00:42.440] INFO: 41600 events read in total (2715ms).
[11:00:42.441] INFO: Test took 3946ms.
[11:00:42.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:43.199] INFO: Expecting 41600 events.
[11:00:46.435] INFO: 41600 events read in total (2709ms).
[11:00:46.436] INFO: Test took 3941ms.
[11:00:46.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:47.194] INFO: Expecting 41600 events.
[11:00:50.451] INFO: 41600 events read in total (2730ms).
[11:00:50.452] INFO: Test took 3961ms.
[11:00:50.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:51.207] INFO: Expecting 41600 events.
[11:00:54.472] INFO: 41600 events read in total (2738ms).
[11:00:54.473] INFO: Test took 3968ms.
[11:00:54.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:55.230] INFO: Expecting 41600 events.
[11:00:58.490] INFO: 41600 events read in total (2733ms).
[11:00:58.491] INFO: Test took 3963ms.
[11:00:58.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:59.245] INFO: Expecting 41600 events.
[11:01:02.487] INFO: 41600 events read in total (2715ms).
[11:01:02.488] INFO: Test took 3943ms.
[11:01:02.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:03.242] INFO: Expecting 41600 events.
[11:01:06.497] INFO: 41600 events read in total (2728ms).
[11:01:06.498] INFO: Test took 3955ms.
[11:01:06.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:07.254] INFO: Expecting 41600 events.
[11:01:10.516] INFO: 41600 events read in total (2735ms).
[11:01:10.517] INFO: Test took 3966ms.
[11:01:10.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:11.272] INFO: Expecting 41600 events.
[11:01:14.526] INFO: 41600 events read in total (2727ms).
[11:01:14.527] INFO: Test took 3956ms.
[11:01:14.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:15.285] INFO: Expecting 41600 events.
[11:01:18.536] INFO: 41600 events read in total (2724ms).
[11:01:18.537] INFO: Test took 3956ms.
[11:01:18.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:19.296] INFO: Expecting 41600 events.
[11:01:22.552] INFO: 41600 events read in total (2730ms).
[11:01:22.553] INFO: Test took 3963ms.
[11:01:22.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:23.309] INFO: Expecting 41600 events.
[11:01:26.560] INFO: 41600 events read in total (2725ms).
[11:01:26.561] INFO: Test took 3953ms.
[11:01:26.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:27.316] INFO: Expecting 41600 events.
[11:01:30.567] INFO: 41600 events read in total (2724ms).
[11:01:30.568] INFO: Test took 3952ms.
[11:01:30.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:31.324] INFO: Expecting 41600 events.
[11:01:34.599] INFO: 41600 events read in total (2748ms).
[11:01:34.600] INFO: Test took 3977ms.
[11:01:34.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:35.355] INFO: Expecting 41600 events.
[11:01:38.619] INFO: 41600 events read in total (2737ms).
[11:01:38.620] INFO: Test took 3965ms.
[11:01:38.655] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:39.374] INFO: Expecting 41600 events.
[11:01:42.605] INFO: 41600 events read in total (2704ms).
[11:01:42.606] INFO: Test took 3931ms.
[11:01:42.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:43.364] INFO: Expecting 41600 events.
[11:01:46.540] INFO: 41600 events read in total (2649ms).
[11:01:46.541] INFO: Test took 3881ms.
[11:01:46.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:46.934] INFO: enter test to run
[11:02:18.321] INFO: test: HighRate no parameter change
[11:02:18.321] INFO: running: highrate
[11:02:18.322] INFO: ----------------------------------------------------------------------
[11:02:18.322] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:02:18.323] INFO: ----------------------------------------------------------------------
[11:02:18.936] INFO: Expecting 208000 events.
[11:02:30.906] INFO: 208000 events read in total (11444ms).
[11:02:30.909] INFO: Test took 12578ms.
[11:02:31.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:31.313] INFO: number of dead pixels (per ROC): 160 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0
[11:02:31.313] INFO: number of red-efficiency pixels: 256 62 95 158 157 186 146 118 118 156 122 123 100 66 23 38
[11:02:31.313] INFO: number of X-ray hits detected: 65414 44874 69924 112823 116567 122640 124292 90093 82383 105527 100010 88193 88941 52619 23048 27054
[11:02:31.313] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:02:31.313] INFO: number of Vcal hits detected: 199903 207938 207904 207835 207841 207808 207849 207881 207879 207839 207875 207826 207898 207934 207829 207962
[11:02:31.313] INFO: Vcal hit fiducial 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 100.0 100.0 100.0 100.0
[11:02:31.313] INFO: Vcal hit overall efficiency (%): 96.1 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0
[11:02:31.313] INFO: X-ray hit rate [MHz/cm2]: 19.2 13.2 20.5 33.1 34.2 35.9 36.4 26.4 24.1 30.9 29.3 25.9 26.1 15.4 6.8 7.9
[11:02:31.313] INFO: PixTestHighRate::doXPixelAlive() done
[11:02:31.362] INFO: PixTest:: pg_setup set to default.
[11:02:31.376] INFO: enter test to run
[11:03:07.592] INFO: test: HighRate no parameter change
[11:03:07.592] INFO: running: highrate
[11:03:07.594] INFO: enter test to run
[11:03:20.257] INFO: test: HighRate no parameter change
[11:03:20.257] INFO: running: highrate
[11:03:20.258] INFO: ----------------------------------------------------------------------
[11:03:20.258] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:03:20.258] INFO: ----------------------------------------------------------------------
[11:03:20.869] INFO: Expecting 208000 events.
[11:03:34.786] INFO: 208000 events read in total (13390ms).
[11:03:34.791] INFO: Test took 14525ms.
[11:03:35.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:35.410] INFO: number of dead pixels (per ROC): 160 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0
[11:03:35.410] INFO: number of red-efficiency pixels: 426 155 252 530 515 741 517 368 335 578 348 433 317 234 69 63
[11:03:35.410] INFO: number of X-ray hits detected: 138977 96287 151153 241963 249333 263418 265795 192000 176793 224079 212904 188515 189677 112989 49707 58141
[11:03:35.410] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:03:35.411] INFO: number of Vcal hits detected: 199706 207839 207731 207426 207437 207172 207433 207601 207646 207373 207625 207488 207667 207758 207783 207937
[11:03:35.411] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[11:03:35.411] INFO: Vcal hit overall efficiency (%): 96.0 99.9 99.9 99.7 99.7 99.6 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 99.9 100.0
[11:03:35.411] INFO: X-ray hit rate [MHz/cm2]: 40.7 28.2 44.3 70.9 73.1 77.2 77.9 56.3 51.8 65.7 62.4 55.3 55.6 33.1 14.6 17.0
[11:03:35.411] INFO: PixTestHighRate::doXPixelAlive() done
[11:03:35.461] INFO: PixTest:: pg_setup set to default.
[11:03:35.479] INFO: enter test to run
[11:03:50.064] INFO: test: HighRate no parameter change
[11:03:50.065] INFO: running: highrate
[11:03:50.066] INFO: ----------------------------------------------------------------------
[11:03:50.066] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:03:50.066] INFO: ----------------------------------------------------------------------
[11:03:50.679] INFO: Expecting 208000 events.
[11:04:06.895] INFO: 208000 events read in total (15689ms).
[11:04:06.903] INFO: Test took 16826ms.
[11:04:07.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:07.768] INFO: number of dead pixels (per ROC): 160 0 0 0 0 0 0 0 0 0 0 1 0 0 3 0
[11:04:07.768] INFO: number of red-efficiency pixels: 754 300 614 1354 1229 1746 1327 814 791 1323 909 921 818 511 86 133
[11:04:07.768] INFO: number of X-ray hits detected: 217227 149393 234516 375598 389719 410090 414265 299821 277085 349580 331692 293286 294644 176122 77967 91239
[11:04:07.768] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:04:07.768] INFO: number of Vcal hits detected: 199272 207665 207221 206254 206417 205426 206302 206975 207059 206258 206905 206799 207056 207377 207763 207865
[11:04:07.768] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.2 99.3 98.9 99.3 99.6 99.6 99.2 99.5 99.5 99.6 99.7 100.0 99.9
[11:04:07.768] INFO: Vcal hit overall efficiency (%): 95.8 99.8 99.6 99.2 99.2 98.8 99.2 99.5 99.5 99.2 99.5 99.4 99.5 99.7 99.9 99.9
[11:04:07.768] INFO: X-ray hit rate [MHz/cm2]: 63.7 43.8 68.7 110.1 114.2 120.2 121.4 87.9 81.2 102.5 97.2 86.0 86.4 51.6 22.9 26.7
[11:04:07.768] INFO: PixTestHighRate::doXPixelAlive() done
[11:04:07.814] INFO: PixTest:: pg_setup set to default.
[11:04:07.831] INFO: enter test to run
[11:04:10.232] INFO: test: exit no parameter change
[11:04:10.523] QUIET: Connection to board 33 closed.
[11:04:10.525] INFO: pXar: this is the end, my friend