[12:33:41.514] INFO: *** Welcome to pxar ***
[12:33:41.514] INFO: *** Today: 2016/09/01
[12:33:42.669] INFO: *** Version: v1.9.0-818-g96727
[12:33:42.669] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//dacParameters35_C15.dat
[12:33:42.765] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:33:42.765] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[12:33:42.772] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[12:33:42.916] INFO: clk: 4
[12:33:42.916] INFO: ctr: 4
[12:33:42.916] INFO: sda: 19
[12:33:42.916] INFO: tin: 9
[12:33:42.916] INFO: level: 15
[12:33:42.916] INFO: triggerdelay: 0
[12:33:42.916] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:33:42.916] INFO: Log level: INFO
[12:33:42.954] QUIET: Connection to board DTB_WREK4U opened.
[12:33:42.957] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[12:33:42.960] INFO: RPC call hashes of host and DTB match: 398089610
[12:33:44.513] INFO: DUT info:
[12:33:44.513] INFO: The DUT currently contains the following objects:
[12:33:44.513] INFO: 2 TBM Cores tbm08c (2 ON)
[12:33:44.513] INFO: TBM Core alpha (0): 7 registers set
[12:33:44.513] INFO: TBM Core beta (1): 7 registers set
[12:33:44.513] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:33:44.513] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:44.513] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:45.014] INFO: enter 'restricted' command line mode
[12:33:45.014] INFO: enter test to run
[12:33:50.623] INFO: test: PixelAlive no parameter change
[12:33:50.623] INFO: running: pixelalive
[12:33:50.692] INFO: ----------------------------------------------------------------------
[12:33:50.692] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:33:50.692] INFO: ----------------------------------------------------------------------
[12:33:51.012] INFO: Expecting 41600 events.
[12:33:55.325] INFO: 41600 events read in total (3595ms).
[12:33:55.494] INFO: Test took 4798ms.
[12:33:55.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:56.036] INFO: PixTestAlive::aliveTest() done
[12:33:56.036] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 9 1 0 0 1 1 1 0 0
[12:33:56.224] INFO: enter test to run
[12:34:25.038] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:34:25.039] INFO: running: highrate
[12:34:25.046] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:34:25.289] INFO: ----------------------------------------------------------------------
[12:34:25.289] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:34:25.289] INFO: ----------------------------------------------------------------------
[12:34:25.289] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:34:25.289] INFO: edge/corner pixel THR is adjusted
[12:34:25.289] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:34:26.248] INFO: Collecting data for 5 seconds...
[12:34:31.267] INFO: Done with hot pixel readout
[12:34:42.903] INFO: PixTest:: pg_setup set to default.
[12:34:42.904] INFO: 20 hot pixels found in step 0
[12:34:43.894] INFO: Collecting data for 5 seconds...
[12:34:48.913] INFO: Done with hot pixel readout
[12:35:00.689] INFO: PixTest:: pg_setup set to default.
[12:35:00.690] INFO: 17 hot pixels found in step 1
[12:35:01.685] INFO: Collecting data for 5 seconds...
[12:35:06.704] INFO: Done with hot pixel readout
[12:35:18.727] INFO: PixTest:: pg_setup set to default.
[12:35:18.728] INFO: 17 hot pixels found in step 2
[12:35:19.721] INFO: Collecting data for 5 seconds...
[12:35:24.739] INFO: Done with hot pixel readout
[12:35:36.593] INFO: PixTest:: pg_setup set to default.
[12:35:36.593] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:35:36.594] INFO: 15 hot pixels found in step 3
[12:35:37.586] INFO: Collecting data for 5 seconds...
[12:35:42.606] INFO: Done with hot pixel readout
[12:35:54.450] INFO: PixTest:: pg_setup set to default.
[12:35:54.451] INFO: 18 hot pixels found in step 4
[12:35:55.443] INFO: Collecting data for 5 seconds...
[12:36:00.459] INFO: Done with hot pixel readout
[12:36:12.208] INFO: PixTest:: pg_setup set to default.
[12:36:12.209] INFO: 13 hot pixels found in step 5
[12:36:13.201] INFO: Collecting data for 5 seconds...
[12:36:18.217] INFO: Done with hot pixel readout
[12:36:29.946] INFO: PixTest:: pg_setup set to default.
[12:36:29.946] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:29.946] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:29.946] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:29.947] INFO: 14 hot pixels found in step 6
[12:36:30.940] INFO: Collecting data for 5 seconds...
[12:36:35.957] INFO: Done with hot pixel readout
[12:36:47.635] INFO: PixTest:: pg_setup set to default.
[12:36:47.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:47.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:47.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:47.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:47.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:36:47.636] INFO: 13 hot pixels found in step 7
[12:36:48.629] INFO: Collecting data for 5 seconds...
[12:36:53.645] INFO: Done with hot pixel readout
[12:37:05.407] INFO: PixTest:: pg_setup set to default.
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:05.408] INFO: 9 hot pixels found in step 8
[12:37:06.401] INFO: Collecting data for 5 seconds...
[12:37:11.417] INFO: Done with hot pixel readout
[12:37:23.138] INFO: PixTest:: pg_setup set to default.
[12:37:23.138] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.138] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.139] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:23.139] INFO: 9 hot pixels found in step 9
[12:37:24.131] INFO: Collecting data for 5 seconds...
[12:37:29.148] INFO: Done with hot pixel readout
[12:37:40.901] INFO: PixTest:: pg_setup set to default.
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.901] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:40.902] INFO: 7 hot pixels found in step 10
[12:37:41.895] INFO: Collecting data for 5 seconds...
[12:37:46.911] INFO: Done with hot pixel readout
[12:37:58.554] INFO: PixTest:: pg_setup set to default.
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.554] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:37:58.555] INFO: 9 hot pixels found in step 11
[12:37:59.548] INFO: Collecting data for 5 seconds...
[12:38:04.564] INFO: Done with hot pixel readout
[12:38:16.277] INFO: PixTest:: pg_setup set to default.
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.277] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:16.278] INFO: 11 hot pixels found in step 12
[12:38:17.270] INFO: Collecting data for 5 seconds...
[12:38:22.287] INFO: Done with hot pixel readout
[12:38:34.017] INFO: PixTest:: pg_setup set to default.
[12:38:34.018] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:34.018] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:34.018] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:34.018] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:34.018] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:34.018] INFO: 5 hot pixels found in step 13
[12:38:34.055] INFO: 5 hot pixels could not be trimmed and have been masked.
[12:38:34.067] INFO: PixTest::trimHotPixels() done
[12:38:34.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat
[12:38:34.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C1.dat
[12:38:34.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C2.dat
[12:38:34.092] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C3.dat
[12:38:34.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C4.dat
[12:38:34.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C5.dat
[12:38:34.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C6.dat
[12:38:34.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C7.dat
[12:38:34.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C8.dat
[12:38:34.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C9.dat
[12:38:34.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C10.dat
[12:38:34.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C11.dat
[12:38:34.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C12.dat
[12:38:34.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C13.dat
[12:38:34.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C14.dat
[12:38:34.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:34.162] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:34.179] INFO: enter test to run
[12:39:10.380] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:39:10.380] INFO: running: highrate
[12:39:10.385] INFO: ----------------------------------------------------------------------
[12:39:10.385] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:39:10.385] INFO: ----------------------------------------------------------------------
[12:39:10.385] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:39:10.385] INFO: edge/corner pixel THR is adjusted
[12:39:10.385] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:39:11.344] INFO: Collecting data for 1 seconds...
[12:39:12.347] INFO: Done with hot pixel readout
[12:39:16.409] INFO: PixTest:: pg_setup set to default.
[12:39:16.410] INFO: 0 hot pixels found in step 0
[12:39:16.415] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:39:16.507] INFO: PixTest::trimHotPixels() done
[12:39:16.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat
[12:39:16.516] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C1.dat
[12:39:16.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C2.dat
[12:39:16.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C3.dat
[12:39:16.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C4.dat
[12:39:16.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C5.dat
[12:39:16.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C6.dat
[12:39:16.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C7.dat
[12:39:16.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C8.dat
[12:39:16.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C9.dat
[12:39:16.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C10.dat
[12:39:16.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C11.dat
[12:39:16.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C12.dat
[12:39:16.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C13.dat
[12:39:16.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C14.dat
[12:39:16.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[12:39:16.597] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-08_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[12:39:16.607] INFO: enter test to run
[12:39:39.012] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:39:39.012] INFO: running: xray
[12:39:39.013] INFO: ----------------------------------------------------------------------
[12:39:39.013] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:39:39.013] INFO: ----------------------------------------------------------------------
[12:39:39.994] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:39:51.593] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:40:20.915] INFO: Resuming triggers.
[12:40:32.516] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:41:02.026] INFO: Resuming triggers.
[12:41:13.630] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:41:42.995] INFO: Resuming triggers.
[12:41:54.591] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:42:24.025] INFO: Resuming triggers.
[12:42:35.625] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:43:04.940] INFO: Resuming triggers.
[12:43:16.539] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:43:46.331] INFO: Resuming triggers.
[12:43:57.935] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:44:27.582] INFO: Resuming triggers.
[12:44:39.186] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:45:08.655] INFO: Resuming triggers.
[12:45:16.186] INFO: data taking finished, elapsed time: 100 seconds.
[12:45:35.751] INFO: PixTest:: pg_setup set to default.
[12:45:35.754] INFO: PixTestXray::doPhRun() done
[12:45:36.043] INFO: enter test to run
[12:47:34.313] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:47:34.313] INFO: running: xray
[12:47:34.314] INFO: ----------------------------------------------------------------------
[12:47:34.314] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:47:34.314] INFO: ----------------------------------------------------------------------
[12:47:35.277] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:47:42.051] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:48:13.464] INFO: Resuming triggers.
[12:48:20.241] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:48:50.822] INFO: Resuming triggers.
[12:48:57.594] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:49:27.536] INFO: Resuming triggers.
[12:49:34.325] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:50:04.597] INFO: Resuming triggers.
[12:50:11.369] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:50:41.631] INFO: Resuming triggers.
[12:50:48.402] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:51:18.710] INFO: Resuming triggers.
[12:51:25.482] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:51:55.604] INFO: Resuming triggers.
[12:52:02.376] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:52:32.653] INFO: Resuming triggers.
[12:52:39.425] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:53:09.504] INFO: Resuming triggers.
[12:53:16.277] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:53:46.554] INFO: Resuming triggers.
[12:53:53.326] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:54:23.543] INFO: Resuming triggers.
[12:54:30.317] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:55:00.490] INFO: Resuming triggers.
[12:55:07.266] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:55:37.582] INFO: Resuming triggers.
[12:55:44.355] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:56:14.708] INFO: Resuming triggers.
[12:56:20.220] INFO: data taking finished, elapsed time: 100 seconds.
[12:56:45.084] INFO: PixTest:: pg_setup set to default.
[12:56:45.087] INFO: PixTestXray::doPhRun() done
[12:56:45.255] INFO: enter test to run
[12:57:35.965] INFO: test: HighRate no parameter change
[12:57:35.965] INFO: running: highrate
[12:57:35.984] INFO: ----------------------------------------------------------------------
[12:57:35.984] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:57:35.984] INFO: ----------------------------------------------------------------------
[12:57:36.130] INFO: Expecting 768 events.
[12:57:37.275] INFO: 768 events read in total (430ms).
[12:57:37.276] INFO: Test took 1280ms.
[12:57:38.078] INFO: Expecting 41600 events.
[12:57:41.164] INFO: 41600 events read in total (2560ms).
[12:57:41.166] INFO: Test took 3866ms.
[12:57:41.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:41.921] INFO: Expecting 41600 events.
[12:57:45.143] INFO: 41600 events read in total (2695ms).
[12:57:45.144] INFO: Test took 3928ms.
[12:57:45.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:45.904] INFO: Expecting 41600 events.
[12:57:49.152] INFO: 41600 events read in total (2722ms).
[12:57:49.153] INFO: Test took 3959ms.
[12:57:49.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:49.910] INFO: Expecting 41600 events.
[12:57:53.181] INFO: 41600 events read in total (2745ms).
[12:57:53.182] INFO: Test took 3979ms.
[12:57:53.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:53.939] INFO: Expecting 41600 events.
[12:57:57.227] INFO: 41600 events read in total (2761ms).
[12:57:57.227] INFO: Test took 3995ms.
[12:57:57.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:57.984] INFO: Expecting 41600 events.
[12:58:01.221] INFO: 41600 events read in total (2710ms).
[12:58:01.222] INFO: Test took 3944ms.
[12:58:01.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:01.972] INFO: Expecting 41600 events.
[12:58:05.193] INFO: 41600 events read in total (2694ms).
[12:58:05.194] INFO: Test took 3922ms.
[12:58:05.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:05.944] INFO: Expecting 41600 events.
[12:58:09.173] INFO: 41600 events read in total (2702ms).
[12:58:09.174] INFO: Test took 3928ms.
[12:58:09.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:09.931] INFO: Expecting 41600 events.
[12:58:13.124] INFO: 41600 events read in total (2666ms).
[12:58:13.125] INFO: Test took 3900ms.
[12:58:13.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:13.881] INFO: Expecting 41600 events.
[12:58:17.195] INFO: 41600 events read in total (2787ms).
[12:58:17.196] INFO: Test took 4020ms.
[12:58:17.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:17.941] INFO: Expecting 41600 events.
[12:58:21.151] INFO: 41600 events read in total (2683ms).
[12:58:21.152] INFO: Test took 3905ms.
[12:58:21.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:21.903] INFO: Expecting 41600 events.
[12:58:25.083] INFO: 41600 events read in total (2653ms).
[12:58:25.084] INFO: Test took 3881ms.
[12:58:25.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:25.837] INFO: Expecting 41600 events.
[12:58:29.095] INFO: 41600 events read in total (2731ms).
[12:58:29.096] INFO: Test took 3958ms.
[12:58:29.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:29.848] INFO: Expecting 41600 events.
[12:58:33.131] INFO: 41600 events read in total (2757ms).
[12:58:33.132] INFO: Test took 3986ms.
[12:58:33.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:33.889] INFO: Expecting 41600 events.
[12:58:37.195] INFO: 41600 events read in total (2779ms).
[12:58:37.196] INFO: Test took 4013ms.
[12:58:37.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:37.945] INFO: Expecting 41600 events.
[12:58:41.240] INFO: 41600 events read in total (2768ms).
[12:58:41.241] INFO: Test took 3992ms.
[12:58:41.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:41.985] INFO: Expecting 41600 events.
[12:58:45.157] INFO: 41600 events read in total (2645ms).
[12:58:45.158] INFO: Test took 3867ms.
[12:58:45.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:45.915] INFO: Expecting 41600 events.
[12:58:49.209] INFO: 41600 events read in total (2767ms).
[12:58:49.210] INFO: Test took 4002ms.
[12:58:49.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:49.964] INFO: Expecting 41600 events.
[12:58:53.203] INFO: 41600 events read in total (2712ms).
[12:58:53.204] INFO: Test took 3942ms.
[12:58:53.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:53.957] INFO: Expecting 41600 events.
[12:58:57.150] INFO: 41600 events read in total (2667ms).
[12:58:57.151] INFO: Test took 3896ms.
[12:58:57.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:57.549] INFO: enter test to run
[12:59:27.316] INFO: test: HighRate no parameter change
[12:59:27.316] INFO: running: highrate
[12:59:27.317] INFO: ----------------------------------------------------------------------
[12:59:27.318] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:59:27.318] INFO: ----------------------------------------------------------------------
[12:59:27.937] INFO: Expecting 208000 events.
[12:59:39.960] INFO: 208000 events read in total (11496ms).
[12:59:39.963] INFO: Test took 12637ms.
[12:59:40.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:40.355] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 9 1 0 0 1 1 1 0 0
[12:59:40.367] INFO: number of red-efficiency pixels: 63 46 79 127 118 90 144 95 61 102 119 94 101 75 17 26
[12:59:40.367] INFO: number of X-ray hits detected: 67479 41203 63302 97669 105649 106700 107544 75232 72585 92937 94700 81701 82929 49234 20190 24149
[12:59:40.367] 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:59:40.367] INFO: number of Vcal hits detected: 207935 207954 207921 207873 207878 207909 207854 207461 207889 207894 207879 207852 207850 207876 207983 207971
[12:59:40.367] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[12:59:40.367] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 99.7 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:59:40.367] INFO: X-ray hit rate [MHz/cm2]: 19.8 12.1 18.6 28.6 31.0 31.3 31.5 22.1 21.3 27.2 27.8 23.9 24.3 14.4 5.9 7.1
[12:59:40.367] INFO: PixTestHighRate::doXPixelAlive() done
[12:59:40.415] INFO: PixTest:: pg_setup set to default.
[12:59:40.431] INFO: enter test to run
[13:00:17.748] INFO: test: HighRate no parameter change
[13:00:17.748] INFO: running: highrate
[13:00:17.749] INFO: ----------------------------------------------------------------------
[13:00:17.749] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:00:17.749] INFO: ----------------------------------------------------------------------
[13:00:18.370] INFO: Expecting 208000 events.
[13:00:32.354] INFO: 208000 events read in total (13457ms).
[13:00:32.359] INFO: Test took 14600ms.
[13:00:32.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:32.968] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 9 1 0 0 1 1 1 0 0
[13:00:32.968] INFO: number of red-efficiency pixels: 213 136 325 418 419 412 548 301 232 347 448 343 346 167 57 68
[13:00:32.968] INFO: number of X-ray hits detected: 148058 90418 139508 215686 233287 233589 236990 166574 160319 203556 209268 180348 182993 109652 44329 53019
[13:00:32.968] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:00:32.968] INFO: number of Vcal hits detected: 207774 207857 207652 207549 207553 207546 207398 207239 207709 207631 207523 207585 207588 207775 207943 207931
[13:00:32.968] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:00:32.968] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.6 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:00:32.968] INFO: X-ray hit rate [MHz/cm2]: 43.4 26.5 40.9 63.2 68.4 68.5 69.5 48.8 47.0 59.7 61.3 52.9 53.6 32.1 13.0 15.5
[13:00:32.968] INFO: PixTestHighRate::doXPixelAlive() done
[13:00:33.013] INFO: PixTest:: pg_setup set to default.
[13:00:33.025] INFO: enter test to run
[13:00:50.556] INFO: test: HighRate no parameter change
[13:00:50.556] INFO: running: highrate
[13:00:50.557] INFO: ----------------------------------------------------------------------
[13:00:50.557] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:00:50.557] INFO: ----------------------------------------------------------------------
[13:00:51.195] INFO: Expecting 208000 events.
[13:01:07.020] INFO: 208000 events read in total (15298ms).
[13:01:07.027] INFO: Test took 16459ms.
[13:01:07.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:07.838] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 9 1 0 0 1 1 1 0 0
[13:01:07.838] INFO: number of red-efficiency pixels: 474 282 638 1007 928 963 1336 686 499 714 1053 819 859 368 78 126
[13:01:07.838] INFO: number of X-ray hits detected: 223858 135890 209242 323363 349140 352216 354954 249829 241151 307167 314658 271021 274343 164755 66756 80547
[13:01:07.838] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:01:07.838] INFO: number of Vcal hits detected: 207433 207692 207130 206672 206892 206833 206225 206731 207385 207165 206703 206955 206943 207528 207915 207832
[13:01:07.838] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.5 99.5 99.2 99.6 99.8 99.6 99.4 99.6 99.6 99.8 100.0 99.9
[13:01:07.838] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.4 99.5 99.4 99.1 99.4 99.7 99.6 99.4 99.5 99.5 99.8 100.0 99.9
[13:01:07.838] INFO: X-ray hit rate [MHz/cm2]: 65.6 39.8 61.3 94.8 102.3 103.2 104.0 73.2 70.7 90.0 92.2 79.4 80.4 48.3 19.6 23.6
[13:01:07.838] INFO: PixTestHighRate::doXPixelAlive() done
[13:01:07.883] INFO: PixTest:: pg_setup set to default.
[13:01:07.894] INFO: enter test to run
[13:01:16.755] INFO: test: exit no parameter change
[13:01:17.171] QUIET: Connection to board 32 closed.
[13:01:17.204] INFO: pXar: this is the end, my friend