[15:33:19.181] INFO: *** Welcome to pxar ***
[15:33:19.181] INFO: *** Today: 2016/09/01
[15:33:19.197] INFO: *** Version: v1.9.0-818-g96727
[15:33:19.197] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//dacParameters35_C15.dat
[15:33:19.229] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:33:19.229] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//defaultMaskFile.dat
[15:33:19.229] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C15.dat
[15:33:19.331] INFO: clk: 4
[15:33:19.331] INFO: ctr: 4
[15:33:19.331] INFO: sda: 19
[15:33:19.331] INFO: tin: 9
[15:33:19.331] INFO: level: 15
[15:33:19.331] INFO: triggerdelay: 0
[15:33:19.331] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:33:19.331] INFO: Log level: INFO
[15:33:19.348] QUIET: Connection to board DTB_WREKRL opened.
[15:33:19.351] 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:
------------------------------------------------------
[15:33:19.354] INFO: RPC call hashes of host and DTB match: 398089610
[15:33:20.889] INFO: DUT info:
[15:33:20.889] INFO: The DUT currently contains the following objects:
[15:33:20.889] INFO: 2 TBM Cores tbm08c (2 ON)
[15:33:20.889] INFO: TBM Core alpha (0): 7 registers set
[15:33:20.889] INFO: TBM Core beta (1): 7 registers set
[15:33:20.889] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:33:20.889] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.889] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:20.890] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:33:21.293] INFO: enter 'restricted' command line mode
[15:33:21.293] INFO: enter test to run
[15:33:29.878] INFO: test: PixelAlive no parameter change
[15:33:29.878] INFO: running: pixelalive
[15:33:29.891] INFO: ----------------------------------------------------------------------
[15:33:29.891] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:33:29.891] INFO: ----------------------------------------------------------------------
[15:33:30.215] INFO: Expecting 41600 events.
[15:33:34.592] INFO: 41600 events read in total (3659ms).
[15:33:34.752] INFO: Test took 4858ms.
[15:33:34.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:35.278] INFO: PixTestAlive::aliveTest() done
[15:33:35.279] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:33:35.312] INFO: enter test to run
[15:34:07.670] INFO: test: timing no parameter change
[15:34:07.670] INFO: running: timing
[15:34:07.673] INFO: ######################################################################
[15:34:07.674] INFO: PixTestTiming::doTest()
[15:34:07.674] INFO: ######################################################################
[15:34:07.674] INFO: ----------------------------------------------------------------------
[15:34:07.674] INFO: PixTestTiming::TBMPhaseScan()
[15:34:07.674] INFO: ----------------------------------------------------------------------
[15:38:33.067] INFO: TBM Phase Settings: 236
[15:38:33.067] INFO: 400MHz Phase: 3
[15:38:33.067] INFO: 160MHz Phase: 7
[15:38:33.067] INFO: Functional Phase Area: 5
[15:38:33.070] INFO: Test took 265396 ms.
[15:38:33.070] INFO: PixTestTiming::TBMPhaseScan() done.
[15:38:33.070] INFO: ----------------------------------------------------------------------
[15:38:33.071] INFO: PixTestTiming::ROCDelayScan()
[15:38:33.071] INFO: ----------------------------------------------------------------------
[15:40:45.614] INFO: ROC Delay Settings: 228
[15:40:45.614] INFO: ROC Header-Trailer/Token Delay: 11
[15:40:45.614] INFO: ROC Port 0 Delay: 4
[15:40:45.614] INFO: ROC Port 1 Delay: 4
[15:40:45.614] INFO: Functional ROC Area: 6
[15:40:45.617] INFO: Test took 132547 ms.
[15:40:45.617] INFO: PixTestTiming::ROCDelayScan() done.
[15:40:45.618] INFO: ----------------------------------------------------------------------
[15:40:45.618] INFO: PixTestTiming::TimingTest()
[15:40:45.618] INFO: ----------------------------------------------------------------------
[15:41:01.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:16.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:31.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:46.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:01.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:16.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:31.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:46.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:01.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:16.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:17.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: Read back bit status: 1
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: Timings are good!
[15:43:17.069] INFO: ----------------------------------------------------------------------
[15:43:17.069] INFO: Test took 151452 ms.
[15:43:17.069] INFO: PixTestTiming::TimingTest() done.
[15:43:17.069] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:43:17.069] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:43:17.069] INFO: PixTestTiming::doTest took 549399 ms.
[15:43:17.069] INFO: PixTestTiming::doTest() done
[15:43:17.069] INFO: Write out TBMPhaseScan_0_V0
[15:43:17.069] INFO: Write out TBMPhaseScan_1_V0
[15:43:17.070] INFO: Write out CombinedTBMPhaseScan_V0
[15:43:17.070] INFO: Write out ROCDelayScan3_V0
[15:43:17.071] INFO: enter test to run
[15:43:40.138] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:43:40.138] INFO: running: highrate
[15:43:40.139] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:43:40.359] INFO: ----------------------------------------------------------------------
[15:43:40.359] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:43:40.359] INFO: ----------------------------------------------------------------------
[15:43:40.359] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:43:40.359] INFO: edge/corner pixel THR is adjusted
[15:43:40.359] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:43:41.316] INFO: Collecting data for 5 seconds...
[15:43:46.336] INFO: Done with hot pixel readout
[15:43:58.186] INFO: PixTest:: pg_setup set to default.
[15:43:58.187] INFO: 14 hot pixels found in step 0
[15:43:59.182] INFO: Collecting data for 5 seconds...
[15:44:04.201] INFO: Done with hot pixel readout
[15:44:16.326] INFO: PixTest:: pg_setup set to default.
[15:44:16.327] INFO: 16 hot pixels found in step 1
[15:44:17.324] INFO: Collecting data for 5 seconds...
[15:44:22.342] INFO: Done with hot pixel readout
[15:44:34.013] INFO: PixTest:: pg_setup set to default.
[15:44:34.014] INFO: 10 hot pixels found in step 2
[15:44:35.008] INFO: Collecting data for 5 seconds...
[15:44:40.027] INFO: Done with hot pixel readout
[15:44:52.361] INFO: PixTest:: pg_setup set to default.
[15:44:52.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:52.362] INFO: 19 hot pixels found in step 3
[15:44:53.356] INFO: Collecting data for 5 seconds...
[15:44:58.375] INFO: Done with hot pixel readout
[15:45:10.721] INFO: PixTest:: pg_setup set to default.
[15:45:10.721] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:10.723] INFO: 12 hot pixels found in step 4
[15:45:11.719] INFO: Collecting data for 5 seconds...
[15:45:16.737] INFO: Done with hot pixel readout
[15:45:29.033] INFO: PixTest:: pg_setup set to default.
[15:45:29.033] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:29.033] INFO: 7 hot pixels found in step 5
[15:45:30.028] INFO: Collecting data for 5 seconds...
[15:45:35.047] INFO: Done with hot pixel readout
[15:45:47.016] INFO: PixTest:: pg_setup set to default.
[15:45:47.016] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:47.017] INFO: 13 hot pixels found in step 6
[15:45:48.012] INFO: Collecting data for 5 seconds...
[15:45:53.032] INFO: Done with hot pixel readout
[15:46:05.160] INFO: PixTest:: pg_setup set to default.
[15:46:05.160] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:46:05.161] INFO: 12 hot pixels found in step 7
[15:46:06.156] INFO: Collecting data for 5 seconds...
[15:46:11.173] INFO: Done with hot pixel readout
[15:46:23.273] INFO: PixTest:: pg_setup set to default.
[15:46:23.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:46:23.274] INFO: 18 hot pixels found in step 8
[15:46:24.271] INFO: Collecting data for 5 seconds...
[15:46:29.289] INFO: Done with hot pixel readout
[15:46:41.426] INFO: PixTest:: pg_setup set to default.
[15:46:41.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:46:41.427] INFO: 8 hot pixels found in step 9
[15:46:42.423] INFO: Collecting data for 5 seconds...
[15:46:47.439] INFO: Done with hot pixel readout
[15:46:59.232] INFO: PixTest:: pg_setup set to default.
[15:46:59.232] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:46:59.233] INFO: 11 hot pixels found in step 10
[15:47:00.228] INFO: Collecting data for 5 seconds...
[15:47:05.244] INFO: Done with hot pixel readout
[15:47:17.293] INFO: PixTest:: pg_setup set to default.
[15:47:17.293] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:47:17.294] INFO: 7 hot pixels found in step 11
[15:47:18.289] INFO: Collecting data for 5 seconds...
[15:47:23.306] INFO: Done with hot pixel readout
[15:47:35.405] INFO: PixTest:: pg_setup set to default.
[15:47:35.405] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:47:35.406] INFO: 12 hot pixels found in step 12
[15:47:36.401] INFO: Collecting data for 5 seconds...
[15:47:41.418] INFO: Done with hot pixel readout
[15:47:53.510] INFO: PixTest:: pg_setup set to default.
[15:47:53.510] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:47:53.511] INFO: 7 hot pixels found in step 13
[15:47:54.506] INFO: Collecting data for 5 seconds...
[15:47:59.523] INFO: Done with hot pixel readout
[15:48:11.530] INFO: PixTest:: pg_setup set to default.
[15:48:11.530] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:48:11.530] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:48:11.531] INFO: 11 hot pixels found in step 14
[15:48:11.570] INFO: 11 hot pixels could not be trimmed and have been masked.
[15:48:11.573] INFO: PixTest::trimHotPixels() done
[15:48:11.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C0.dat
[15:48:11.579] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C1.dat
[15:48:11.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C2.dat
[15:48:11.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C3.dat
[15:48:11.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C4.dat
[15:48:11.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C5.dat
[15:48:11.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C6.dat
[15:48:11.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C7.dat
[15:48:11.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C8.dat
[15:48:11.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C9.dat
[15:48:11.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C10.dat
[15:48:11.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C11.dat
[15:48:11.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C12.dat
[15:48:11.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C13.dat
[15:48:11.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C14.dat
[15:48:11.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C15.dat
[15:48:11.658] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//defaultMaskFile.dat
[15:48:11.668] INFO: enter test to run
[15:48:44.968] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:48:44.968] INFO: running: highrate
[15:48:44.973] INFO: ----------------------------------------------------------------------
[15:48:44.973] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:48:44.973] INFO: ----------------------------------------------------------------------
[15:48:44.973] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:48:44.973] INFO: edge/corner pixel THR is adjusted
[15:48:44.973] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:48:45.930] INFO: Collecting data for 1 seconds...
[15:48:46.934] INFO: Done with hot pixel readout
[15:48:51.052] INFO: PixTest:: pg_setup set to default.
[15:48:51.053] INFO: 0 hot pixels found in step 0
[15:48:51.058] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:48:51.141] INFO: PixTest::trimHotPixels() done
[15:48:51.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C0.dat
[15:48:51.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C1.dat
[15:48:51.155] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C2.dat
[15:48:51.160] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C3.dat
[15:48:51.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C4.dat
[15:48:51.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C5.dat
[15:48:51.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C6.dat
[15:48:51.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C7.dat
[15:48:51.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C8.dat
[15:48:51.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C9.dat
[15:48:51.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C10.dat
[15:48:51.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C11.dat
[15:48:51.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C12.dat
[15:48:51.213] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C13.dat
[15:48:51.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C14.dat
[15:48:51.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//trimParameters35_C15.dat
[15:48:51.228] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-23_FPIXTest-17C-FNAL-160824-1317-300V_2016-08-24_13h17m_1472062643/000_FPIXTest_p17//defaultMaskFile.dat
[15:48:51.238] INFO: enter test to run
[15:49:27.280] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:49:27.280] INFO: running: xray
[15:49:27.281] INFO: ----------------------------------------------------------------------
[15:49:27.281] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:49:27.281] INFO: ----------------------------------------------------------------------
[15:49:28.244] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:49:39.319] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:50:08.999] INFO: Resuming triggers.
[15:50:20.179] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:50:49.938] INFO: Resuming triggers.
[15:51:01.017] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:51:30.821] INFO: Resuming triggers.
[15:51:41.904] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:52:11.558] INFO: Resuming triggers.
[15:52:22.639] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:52:52.329] INFO: Resuming triggers.
[15:53:03.410] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:53:33.101] INFO: Resuming triggers.
[15:53:44.184] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:54:13.853] INFO: Resuming triggers.
[15:54:24.935] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:54:55.053] INFO: Resuming triggers.
[15:55:06.137] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:55:35.663] INFO: Resuming triggers.
[15:55:36.267] INFO: data taking finished, elapsed time: 100 seconds.
[15:55:38.300] INFO: PixTest:: pg_setup set to default.
[15:55:38.303] INFO: PixTestXray::doPhRun() done
[15:55:38.491] INFO: enter test to run
[15:56:22.341] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:56:22.341] INFO: running: xray
[15:56:22.342] INFO: ----------------------------------------------------------------------
[15:56:22.342] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:56:22.342] INFO: ----------------------------------------------------------------------
[15:56:23.320] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:56:29.732] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:57:00.786] INFO: Resuming triggers.
[15:57:07.207] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:57:38.926] INFO: Resuming triggers.
[15:57:45.338] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:58:17.089] INFO: Resuming triggers.
[15:58:23.502] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:58:54.475] INFO: Resuming triggers.
[15:59:00.894] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:59:31.366] INFO: Resuming triggers.
[15:59:37.778] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[16:00:08.195] INFO: Resuming triggers.
[16:00:14.613] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:00:45.095] INFO: Resuming triggers.
[16:00:51.509] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[16:01:21.871] INFO: Resuming triggers.
[16:01:28.283] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:01:58.686] INFO: Resuming triggers.
[16:02:05.098] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:02:35.513] INFO: Resuming triggers.
[16:02:41.931] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:03:12.392] INFO: Resuming triggers.
[16:03:18.811] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[16:03:49.292] INFO: Resuming triggers.
[16:03:55.708] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:04:26.252] INFO: Resuming triggers.
[16:04:32.674] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:05:03.034] INFO: Resuming triggers.
[16:05:09.455] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:05:39.969] INFO: Resuming triggers.
[16:05:44.069] INFO: data taking finished, elapsed time: 100 seconds.
[16:06:03.745] INFO: PixTest:: pg_setup set to default.
[16:06:03.749] INFO: PixTestXray::doPhRun() done
[16:06:03.897] INFO: enter test to run
[16:06:42.265] INFO: test: HighRate no parameter change
[16:06:42.265] INFO: running: highrate
[16:06:42.281] INFO: ----------------------------------------------------------------------
[16:06:42.281] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:06:42.281] INFO: ----------------------------------------------------------------------
[16:06:42.435] INFO: Expecting 768 events.
[16:06:43.569] INFO: 768 events read in total (418ms).
[16:06:43.570] INFO: Test took 1269ms.
[16:06:44.373] INFO: Expecting 41600 events.
[16:06:47.471] INFO: 41600 events read in total (2572ms).
[16:06:47.472] INFO: Test took 3894ms.
[16:06:47.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:48.233] INFO: Expecting 41600 events.
[16:06:51.446] INFO: 41600 events read in total (2686ms).
[16:06:51.447] INFO: Test took 3921ms.
[16:06:51.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:52.204] INFO: Expecting 41600 events.
[16:06:55.499] INFO: 41600 events read in total (2768ms).
[16:06:55.500] INFO: Test took 4000ms.
[16:06:55.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:56.253] INFO: Expecting 41600 events.
[16:06:59.550] INFO: 41600 events read in total (2771ms).
[16:06:59.551] INFO: Test took 3996ms.
[16:06:59.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:00.307] INFO: Expecting 41600 events.
[16:07:03.633] INFO: 41600 events read in total (2799ms).
[16:07:03.634] INFO: Test took 4028ms.
[16:07:03.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:04.379] INFO: Expecting 41600 events.
[16:07:07.614] INFO: 41600 events read in total (2709ms).
[16:07:07.615] INFO: Test took 3926ms.
[16:07:07.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:08.373] INFO: Expecting 41600 events.
[16:07:11.585] INFO: 41600 events read in total (2686ms).
[16:07:11.586] INFO: Test took 3916ms.
[16:07:11.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:12.343] INFO: Expecting 41600 events.
[16:07:15.628] INFO: 41600 events read in total (2758ms).
[16:07:15.629] INFO: Test took 3987ms.
[16:07:15.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:16.386] INFO: Expecting 41600 events.
[16:07:19.698] INFO: 41600 events read in total (2785ms).
[16:07:19.699] INFO: Test took 4014ms.
[16:07:19.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:20.452] INFO: Expecting 41600 events.
[16:07:23.772] INFO: 41600 events read in total (2793ms).
[16:07:23.773] INFO: Test took 4018ms.
[16:07:23.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:24.523] INFO: Expecting 41600 events.
[16:07:27.919] INFO: 41600 events read in total (2869ms).
[16:07:27.920] INFO: Test took 4091ms.
[16:07:27.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:28.668] INFO: Expecting 41600 events.
[16:07:31.894] INFO: 41600 events read in total (2700ms).
[16:07:31.895] INFO: Test took 3919ms.
[16:07:31.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:32.653] INFO: Expecting 41600 events.
[16:07:35.962] INFO: 41600 events read in total (2783ms).
[16:07:35.963] INFO: Test took 4012ms.
[16:07:35.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:36.708] INFO: Expecting 41600 events.
[16:07:39.928] INFO: 41600 events read in total (2693ms).
[16:07:39.929] INFO: Test took 3909ms.
[16:07:39.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:40.679] INFO: Expecting 41600 events.
[16:07:43.950] INFO: 41600 events read in total (2744ms).
[16:07:43.951] INFO: Test took 3968ms.
[16:07:43.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:44.702] INFO: Expecting 41600 events.
[16:07:47.955] INFO: 41600 events read in total (2726ms).
[16:07:47.955] INFO: Test took 3948ms.
[16:07:47.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:48.712] INFO: Expecting 41600 events.
[16:07:51.867] INFO: 41600 events read in total (2628ms).
[16:07:51.868] INFO: Test took 3857ms.
[16:07:51.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:52.623] INFO: Expecting 41600 events.
[16:07:55.886] INFO: 41600 events read in total (2737ms).
[16:07:55.887] INFO: Test took 3963ms.
[16:07:55.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:56.639] INFO: Expecting 41600 events.
[16:07:59.797] INFO: 41600 events read in total (2632ms).
[16:07:59.798] INFO: Test took 3856ms.
[16:07:59.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:00.555] INFO: Expecting 41600 events.
[16:08:03.803] INFO: 41600 events read in total (2721ms).
[16:08:03.804] INFO: Test took 3949ms.
[16:08:03.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:04.191] INFO: enter test to run
[16:08:10.072] INFO: test: HighRate no parameter change
[16:08:10.072] INFO: running: highrate
[16:08:10.073] INFO: ----------------------------------------------------------------------
[16:08:10.073] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:08:10.073] INFO: ----------------------------------------------------------------------
[16:08:10.690] INFO: Expecting 208000 events.
[16:08:22.417] INFO: 208000 events read in total (11201ms).
[16:08:22.421] INFO: Test took 12341ms.
[16:08:22.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:22.838] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:08:22.838] INFO: number of red-efficiency pixels: 99 46 112 142 147 139 170 94 96 109 107 107 113 70 26 30
[16:08:22.838] INFO: number of X-ray hits detected: 74453 49086 74316 119116 125093 125352 124899 87329 81878 101728 98251 88959 92203 58350 23385 27554
[16:08:22.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
[16:08:22.838] INFO: number of Vcal hits detected: 207897 207953 207887 207857 207851 207854 207823 207895 207904 207890 207891 207891 207885 207929 207973 207969
[16:08:22.838] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:08:22.838] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:08:22.838] INFO: X-ray hit rate [MHz/cm2]: 21.8 14.4 21.8 34.9 36.7 36.7 36.6 25.6 24.0 29.8 28.8 26.1 27.0 17.1 6.9 8.1
[16:08:22.838] INFO: PixTestHighRate::doXPixelAlive() done
[16:08:22.887] INFO: PixTest:: pg_setup set to default.
[16:08:22.911] INFO: enter test to run
[16:08:41.592] INFO: test: HighRate no parameter change
[16:08:41.592] INFO: running: highrate
[16:08:41.594] INFO: ----------------------------------------------------------------------
[16:08:41.594] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:08:41.594] INFO: ----------------------------------------------------------------------
[16:08:42.216] INFO: Expecting 208000 events.
[16:08:55.991] INFO: 208000 events read in total (13248ms).
[16:08:55.996] INFO: Test took 14393ms.
[16:08:56.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:56.625] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:08:56.625] INFO: number of red-efficiency pixels: 313 137 328 490 519 533 586 292 303 343 379 351 347 227 59 64
[16:08:56.625] INFO: number of X-ray hits detected: 152220 100506 152088 243584 255585 256910 255952 179544 168865 208845 201546 182093 188016 119741 48165 57383
[16:08:56.625] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:08:56.625] INFO: number of Vcal hits detected: 207654 207854 207636 207464 207444 207415 207346 207658 207679 207632 207588 207621 207641 207755 207938 207935
[16:08:56.625] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:08:56.625] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:08:56.625] INFO: X-ray hit rate [MHz/cm2]: 44.6 29.5 44.6 71.4 74.9 75.3 75.0 52.6 49.5 61.2 59.1 53.4 55.1 35.1 14.1 16.8
[16:08:56.625] INFO: PixTestHighRate::doXPixelAlive() done
[16:08:56.671] INFO: PixTest:: pg_setup set to default.
[16:08:56.690] INFO: enter test to run
[16:09:16.608] INFO: test: HighRate no parameter change
[16:09:16.608] INFO: running: highrate
[16:09:16.609] INFO: ----------------------------------------------------------------------
[16:09:16.609] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:09:16.609] INFO: ----------------------------------------------------------------------
[16:09:17.229] INFO: Expecting 208000 events.
[16:09:33.468] INFO: 208000 events read in total (15712ms).
[16:09:33.476] INFO: Test took 16858ms.
[16:09:33.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:34.353] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:09:34.353] INFO: number of red-efficiency pixels: 626 259 785 1086 1140 1258 1343 671 667 833 961 765 824 548 116 114
[16:09:34.353] INFO: number of X-ray hits detected: 229038 151577 229967 366823 385006 386506 384979 271055 254032 315739 304572 274645 284370 181102 73083 86793
[16:09:34.353] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:09:34.353] INFO: number of Vcal hits detected: 207198 207710 206892 206622 206529 206312 206172 207164 207236 207024 206847 207084 207036 207322 207882 207884
[16:09:34.353] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.4 99.4 99.3 99.2 99.6 99.7 99.6 99.5 99.6 99.6 99.7 99.9 99.9
[16:09:34.353] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.5 99.3 99.3 99.2 99.1 99.6 99.6 99.5 99.4 99.6 99.5 99.7 99.9 99.9
[16:09:34.353] INFO: X-ray hit rate [MHz/cm2]: 67.1 44.4 67.4 107.5 112.8 113.3 112.8 79.4 74.5 92.5 89.3 80.5 83.4 53.1 21.4 25.4
[16:09:34.353] INFO: PixTestHighRate::doXPixelAlive() done
[16:09:34.398] INFO: PixTest:: pg_setup set to default.
[16:09:34.412] INFO: enter test to run
[16:09:41.184] INFO: test: exit no parameter change
[16:09:41.658] QUIET: Connection to board 33 closed.
[16:09:41.668] INFO: pXar: this is the end, my friend