[10:02:05.273] INFO: *** Welcome to pxar ***
[10:02:05.273] INFO: *** Today: 2016/11/18
[10:02:05.559] INFO: *** Version: v1.9.0-818-g96727
[10:02:05.559] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//dacParameters35_C15.dat
[10:02:05.688] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:02:05.688] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//defaultMaskFile.dat
[10:02:05.696] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C15.dat
[10:02:05.881] INFO: clk: 4
[10:02:05.882] INFO: ctr: 4
[10:02:05.882] INFO: sda: 19
[10:02:05.882] INFO: tin: 9
[10:02:05.882] INFO: level: 15
[10:02:05.882] INFO: triggerdelay: 0
[10:02:05.882] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:02:05.882] INFO: Log level: INFO
[10:02:05.903] QUIET: Connection to board DTB_WREHUL opened.
[10:02:05.906] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 30
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREHUL
MAC address: 40D85511801E
Hostname: pixelDTB030
Comment:
------------------------------------------------------
[10:02:05.909] INFO: RPC call hashes of host and DTB match: 398089610
[10:02:07.451] INFO: DUT info:
[10:02:07.451] INFO: The DUT currently contains the following objects:
[10:02:07.451] INFO: 2 TBM Cores tbm08c (2 ON)
[10:02:07.451] INFO: TBM Core alpha (0): 7 registers set
[10:02:07.451] INFO: TBM Core beta (1): 7 registers set
[10:02:07.451] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:02:07.451] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.451] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.452] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:02:07.885] INFO: enter 'restricted' command line mode
[10:02:07.885] INFO: enter test to run
[10:02:13.830] INFO: test: PixelAlive no parameter change
[10:02:13.830] INFO: running: pixelalive
[10:02:13.839] INFO: ----------------------------------------------------------------------
[10:02:13.839] 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:02:13.839] INFO: ----------------------------------------------------------------------
[10:02:14.163] INFO: Expecting 41600 events.
[10:02:18.510] INFO: 41600 events read in total (3629ms).
[10:02:18.679] INFO: Test took 4837ms.
[10:02:18.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:18.964] INFO: PixTestAlive::aliveTest() done
[10:02:18.964] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 1 0 1 0 0 0 0 0 0 0
[10:02:19.067] INFO: enter test to run
[10:02:24.830] INFO: test: timing no parameter change
[10:02:24.830] INFO: running: timing
[10:02:24.833] INFO: ######################################################################
[10:02:24.833] INFO: PixTestTiming::doTest()
[10:02:24.833] INFO: ######################################################################
[10:02:24.833] INFO: ----------------------------------------------------------------------
[10:02:24.833] INFO: PixTestTiming::TBMPhaseScan()
[10:02:24.833] INFO: ----------------------------------------------------------------------
[10:07:11.713] INFO: TBM Phase Settings: 224
[10:07:11.713] INFO: 400MHz Phase: 0
[10:07:11.713] INFO: 160MHz Phase: 7
[10:07:11.713] INFO: Functional Phase Area: 3
[10:07:11.716] INFO: Test took 286883 ms.
[10:07:11.716] INFO: PixTestTiming::TBMPhaseScan() done.
[10:07:11.716] INFO: ----------------------------------------------------------------------
[10:07:11.716] INFO: PixTestTiming::ROCDelayScan()
[10:07:11.716] INFO: ----------------------------------------------------------------------
[10:09:07.790] INFO: ROC Delay Settings: 228
[10:09:07.790] INFO: ROC Header-Trailer/Token Delay: 11
[10:09:07.790] INFO: ROC Port 0 Delay: 4
[10:09:07.791] INFO: ROC Port 1 Delay: 4
[10:09:07.791] INFO: Functional ROC Area: 4
[10:09:07.794] INFO: Test took 116078 ms.
[10:09:07.794] INFO: PixTestTiming::ROCDelayScan() done.
[10:09:07.794] INFO: ----------------------------------------------------------------------
[10:09:07.794] INFO: PixTestTiming::TimingTest()
[10:09:07.794] INFO: ----------------------------------------------------------------------
[10:09:23.936] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:38.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:53.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:08.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:23.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:38.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:53.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:08.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:23.577] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:38.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:38.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: Read back bit status: 1
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: Timings are good!
[10:11:38.928] INFO: ----------------------------------------------------------------------
[10:11:38.928] INFO: Test took 151134 ms.
[10:11:38.928] INFO: PixTestTiming::TimingTest() done.
[10:11:38.928] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:11:38.928] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:11:38.929] INFO: PixTestTiming::doTest took 554099 ms.
[10:11:38.929] INFO: PixTestTiming::doTest() done
[10:11:38.929] INFO: Write out TBMPhaseScan_0_V0
[10:11:38.929] INFO: Write out TBMPhaseScan_1_V0
[10:11:38.929] INFO: Write out CombinedTBMPhaseScan_V0
[10:11:38.931] INFO: Write out ROCDelayScan3_V0
[10:11:38.932] INFO: enter test to run
[10:12:31.155] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:12:31.155] INFO: running: highrate
[10:12:31.155] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:12:31.391] INFO: ----------------------------------------------------------------------
[10:12:31.391] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:12:31.391] INFO: ----------------------------------------------------------------------
[10:12:31.391] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:12:31.391] INFO: edge/corner pixel THR is adjusted
[10:12:31.391] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:12:32.350] INFO: Collecting data for 5 seconds...
[10:12:37.368] INFO: Done with hot pixel readout
[10:12:49.171] INFO: PixTest:: pg_setup set to default.
[10:12:49.172] INFO: 11 hot pixels found in step 0
[10:12:50.166] INFO: Collecting data for 5 seconds...
[10:12:55.183] INFO: Done with hot pixel readout
[10:13:07.008] INFO: PixTest:: pg_setup set to default.
[10:13:07.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:13:07.009] INFO: 15 hot pixels found in step 1
[10:13:07.003] INFO: Collecting data for 5 seconds...
[10:13:13.019] INFO: Done with hot pixel readout
[10:13:24.825] INFO: PixTest:: pg_setup set to default.
[10:13:24.826] INFO: 15 hot pixels found in step 2
[10:13:25.820] INFO: Collecting data for 5 seconds...
[10:13:30.836] INFO: Done with hot pixel readout
[10:13:42.577] INFO: PixTest:: pg_setup set to default.
[10:13:42.578] INFO: 9 hot pixels found in step 3
[10:13:43.572] INFO: Collecting data for 5 seconds...
[10:13:48.589] INFO: Done with hot pixel readout
[10:14:00.368] INFO: PixTest:: pg_setup set to default.
[10:14:00.369] INFO: 18 hot pixels found in step 4
[10:14:01.361] INFO: Collecting data for 5 seconds...
[10:14:06.378] INFO: Done with hot pixel readout
[10:14:18.383] INFO: PixTest:: pg_setup set to default.
[10:14:18.384] INFO: 12 hot pixels found in step 5
[10:14:19.378] INFO: Collecting data for 5 seconds...
[10:14:24.398] INFO: Done with hot pixel readout
[10:14:36.262] INFO: PixTest:: pg_setup set to default.
[10:14:36.263] INFO: 11 hot pixels found in step 6
[10:14:37.257] INFO: Collecting data for 5 seconds...
[10:14:42.275] INFO: Done with hot pixel readout
[10:14:53.759] INFO: PixTest:: pg_setup set to default.
[10:14:53.760] INFO: 10 hot pixels found in step 7
[10:14:54.756] INFO: Collecting data for 5 seconds...
[10:14:59.774] INFO: Done with hot pixel readout
[10:15:11.441] INFO: PixTest:: pg_setup set to default.
[10:15:11.442] INFO: 6 hot pixels found in step 8
[10:15:12.436] INFO: Collecting data for 5 seconds...
[10:15:17.454] INFO: Done with hot pixel readout
[10:15:29.039] INFO: PixTest:: pg_setup set to default.
[10:15:29.040] INFO: 6 hot pixels found in step 9
[10:15:30.035] INFO: Collecting data for 5 seconds...
[10:15:35.053] INFO: Done with hot pixel readout
[10:15:46.455] INFO: PixTest:: pg_setup set to default.
[10:15:46.456] INFO: 9 hot pixels found in step 10
[10:15:47.450] INFO: Collecting data for 5 seconds...
[10:15:52.467] INFO: Done with hot pixel readout
[10:16:04.265] INFO: PixTest:: pg_setup set to default.
[10:16:04.266] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:16:04.266] INFO: 9 hot pixels found in step 11
[10:16:05.261] INFO: Collecting data for 5 seconds...
[10:16:10.278] INFO: Done with hot pixel readout
[10:16:22.181] INFO: PixTest:: pg_setup set to default.
[10:16:22.182] INFO: 6 hot pixels found in step 12
[10:16:23.176] INFO: Collecting data for 5 seconds...
[10:16:28.195] INFO: Done with hot pixel readout
[10:16:39.642] INFO: PixTest:: pg_setup set to default.
[10:16:39.643] INFO: 10 hot pixels found in step 13
[10:16:40.638] INFO: Collecting data for 5 seconds...
[10:16:45.656] INFO: Done with hot pixel readout
[10:16:57.481] INFO: PixTest:: pg_setup set to default.
[10:16:57.482] INFO: 8 hot pixels found in step 14
[10:16:57.521] INFO: 8 hot pixels could not be trimmed and have been masked.
[10:16:57.525] INFO: PixTest::trimHotPixels() done
[10:16:57.525] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C0.dat
[10:16:57.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C1.dat
[10:16:57.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C2.dat
[10:16:57.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C3.dat
[10:16:57.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C4.dat
[10:16:57.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C5.dat
[10:16:57.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C6.dat
[10:16:57.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C7.dat
[10:16:57.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C8.dat
[10:16:57.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C9.dat
[10:16:57.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C10.dat
[10:16:57.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C11.dat
[10:16:57.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C12.dat
[10:16:57.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C13.dat
[10:16:57.603] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C14.dat
[10:16:57.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C15.dat
[10:16:57.613] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//defaultMaskFile.dat
[10:16:57.624] INFO: enter test to run
[10:17:53.121] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:17:53.121] INFO: running: highrate
[10:17:53.126] INFO: ----------------------------------------------------------------------
[10:17:53.126] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:17:53.126] INFO: ----------------------------------------------------------------------
[10:17:53.126] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:17:53.126] INFO: edge/corner pixel THR is adjusted
[10:17:53.126] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:17:54.083] INFO: Collecting data for 1 seconds...
[10:17:55.088] INFO: Done with hot pixel readout
[10:17:59.257] INFO: PixTest:: pg_setup set to default.
[10:17:59.258] INFO: 0 hot pixels found in step 0
[10:17:59.264] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:17:59.347] INFO: PixTest::trimHotPixels() done
[10:17:59.348] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C0.dat
[10:17:59.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C1.dat
[10:17:59.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C2.dat
[10:17:59.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C3.dat
[10:17:59.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C4.dat
[10:17:59.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C5.dat
[10:17:59.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C6.dat
[10:17:59.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C7.dat
[10:17:59.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C8.dat
[10:17:59.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C9.dat
[10:17:59.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C10.dat
[10:17:59.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C11.dat
[10:17:59.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C12.dat
[10:17:59.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C13.dat
[10:17:59.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C14.dat
[10:17:59.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//trimParameters35_C15.dat
[10:17:59.438] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-08_FPIXTest-17C-FNAL-161115-1259-150V_2016-11-15_12h59m_1479236379/000_FPIXTest_p17//defaultMaskFile.dat
[10:17:59.448] INFO: enter test to run
[10:18:25.616] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:18:25.616] INFO: running: xray
[10:18:25.617] INFO: ----------------------------------------------------------------------
[10:18:25.617] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:18:25.617] INFO: ----------------------------------------------------------------------
[10:18:26.602] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:18:37.002] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:19:08.118] INFO: Resuming triggers.
[10:19:19.517] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:19:49.298] INFO: Resuming triggers.
[10:20:00.698] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:20:30.022] INFO: Resuming triggers.
[10:20:41.424] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[10:21:10.877] INFO: Resuming triggers.
[10:21:22.279] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[10:21:51.761] INFO: Resuming triggers.
[10:22:03.162] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:22:32.658] INFO: Resuming triggers.
[10:22:44.061] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:23:13.502] INFO: Resuming triggers.
[10:23:24.906] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[10:23:54.323] INFO: Resuming triggers.
[10:24:03.461] INFO: data taking finished, elapsed time: 100 seconds.
[10:24:27.156] INFO: PixTest:: pg_setup set to default.
[10:24:27.159] INFO: PixTestXray::doPhRun() done
[10:24:27.371] INFO: enter test to run
[10:25:51.469] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:25:51.469] INFO: running: xray
[10:25:51.470] INFO: ----------------------------------------------------------------------
[10:25:51.470] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:25:51.470] INFO: ----------------------------------------------------------------------
[10:25:52.434] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:25:59.074] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:26:29.486] INFO: Resuming triggers.
[10:26:36.127] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:27:06.201] INFO: Resuming triggers.
[10:27:12.843] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:27:43.641] INFO: Resuming triggers.
[10:27:50.281] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:28:21.238] INFO: Resuming triggers.
[10:28:27.878] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:28:58.772] INFO: Resuming triggers.
[10:29:05.409] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[10:29:36.584] INFO: Resuming triggers.
[10:29:43.223] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:30:14.014] INFO: Resuming triggers.
[10:30:20.650] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:30:51.625] INFO: Resuming triggers.
[10:30:58.259] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:31:29.980] INFO: Resuming triggers.
[10:31:36.617] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:32:07.918] INFO: Resuming triggers.
[10:32:14.559] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:32:45.670] INFO: Resuming triggers.
[10:32:52.309] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:33:23.509] INFO: Resuming triggers.
[10:33:30.148] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[10:34:01.313] INFO: Resuming triggers.
[10:34:07.952] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:34:38.846] INFO: Resuming triggers.
[10:34:45.487] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:35:15.703] INFO: Resuming triggers.
[10:35:16.475] INFO: data taking finished, elapsed time: 100 seconds.
[10:35:20.407] INFO: PixTest:: pg_setup set to default.
[10:35:20.410] INFO: PixTestXray::doPhRun() done
[10:35:20.588] INFO: enter test to run
[10:35:53.097] INFO: test: HighRate no parameter change
[10:35:53.097] INFO: running: highrate
[10:35:53.110] INFO: ----------------------------------------------------------------------
[10:35:53.110] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:35:53.110] INFO: ----------------------------------------------------------------------
[10:35:53.265] INFO: Expecting 768 events.
[10:35:54.399] INFO: 768 events read in total (419ms).
[10:35:54.399] INFO: Test took 1269ms.
[10:35:55.203] INFO: Expecting 41600 events.
[10:35:58.215] INFO: 41600 events read in total (2485ms).
[10:35:58.216] INFO: Test took 3809ms.
[10:35:58.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:58.971] INFO: Expecting 41600 events.
[10:36:02.126] INFO: 41600 events read in total (2629ms).
[10:36:02.127] INFO: Test took 3860ms.
[10:36:02.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:02.887] INFO: Expecting 41600 events.
[10:36:06.096] INFO: 41600 events read in total (2682ms).
[10:36:06.097] INFO: Test took 3920ms.
[10:36:06.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:06.855] INFO: Expecting 41600 events.
[10:36:10.079] INFO: 41600 events read in total (2697ms).
[10:36:10.080] INFO: Test took 3932ms.
[10:36:10.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:10.836] INFO: Expecting 41600 events.
[10:36:14.062] INFO: 41600 events read in total (2699ms).
[10:36:14.063] INFO: Test took 3931ms.
[10:36:14.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:14.818] INFO: Expecting 41600 events.
[10:36:18.047] INFO: 41600 events read in total (2702ms).
[10:36:18.048] INFO: Test took 3932ms.
[10:36:18.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:18.804] INFO: Expecting 41600 events.
[10:36:22.048] INFO: 41600 events read in total (2717ms).
[10:36:22.049] INFO: Test took 3948ms.
[10:36:22.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:22.809] INFO: Expecting 41600 events.
[10:36:26.053] INFO: 41600 events read in total (2717ms).
[10:36:26.054] INFO: Test took 3953ms.
[10:36:26.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:26.812] INFO: Expecting 41600 events.
[10:36:30.057] INFO: 41600 events read in total (2718ms).
[10:36:30.058] INFO: Test took 3950ms.
[10:36:30.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:30.810] INFO: Expecting 41600 events.
[10:36:34.047] INFO: 41600 events read in total (2710ms).
[10:36:34.048] INFO: Test took 3938ms.
[10:36:34.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:34.808] INFO: Expecting 41600 events.
[10:36:38.051] INFO: 41600 events read in total (2716ms).
[10:36:38.052] INFO: Test took 3950ms.
[10:36:38.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:38.806] INFO: Expecting 41600 events.
[10:36:42.037] INFO: 41600 events read in total (2704ms).
[10:36:42.038] INFO: Test took 3933ms.
[10:36:42.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:42.796] INFO: Expecting 41600 events.
[10:36:46.043] INFO: 41600 events read in total (2720ms).
[10:36:46.044] INFO: Test took 3953ms.
[10:36:46.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:46.799] INFO: Expecting 41600 events.
[10:36:50.038] INFO: 41600 events read in total (2712ms).
[10:36:50.039] INFO: Test took 3943ms.
[10:36:50.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:50.795] INFO: Expecting 41600 events.
[10:36:54.043] INFO: 41600 events read in total (2721ms).
[10:36:54.044] INFO: Test took 3953ms.
[10:36:54.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:54.795] INFO: Expecting 41600 events.
[10:36:58.045] INFO: 41600 events read in total (2723ms).
[10:36:58.046] INFO: Test took 3947ms.
[10:36:58.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:58.805] INFO: Expecting 41600 events.
[10:37:02.042] INFO: 41600 events read in total (2710ms).
[10:37:02.043] INFO: Test took 3945ms.
[10:37:02.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:02.802] INFO: Expecting 41600 events.
[10:37:06.050] INFO: 41600 events read in total (2721ms).
[10:37:06.051] INFO: Test took 3956ms.
[10:37:06.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:06.811] INFO: Expecting 41600 events.
[10:37:10.056] INFO: 41600 events read in total (2718ms).
[10:37:10.057] INFO: Test took 3954ms.
[10:37:10.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:10.815] INFO: Expecting 41600 events.
[10:37:13.001] INFO: 41600 events read in total (2659ms).
[10:37:13.002] INFO: Test took 3893ms.
[10:37:14.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:14.399] INFO: enter test to run
[10:37:19.200] INFO: test: HighRate no parameter change
[10:37:19.200] INFO: running: highrate
[10:37:19.202] INFO: ----------------------------------------------------------------------
[10:37:19.202] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:37:19.202] INFO: ----------------------------------------------------------------------
[10:37:19.812] INFO: Expecting 208000 events.
[10:37:31.763] INFO: 208000 events read in total (11424ms).
[10:37:31.766] INFO: Test took 12558ms.
[10:37:31.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:32.166] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 1 0 1 0 0 0 0 0 0 0
[10:37:32.166] INFO: number of red-efficiency pixels: 60 48 78 144 115 157 149 89 88 121 93 102 99 78 22 27
[10:37:32.166] INFO: number of X-ray hits detected: 66080 43248 66326 105540 112924 115432 122003 76047 70276 96894 91924 85022 97463 57424 22954 24907
[10:37:32.166] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:37:32.166] INFO: number of Vcal hits detected: 207935 207950 207873 207851 207882 207837 207797 207910 207863 207875 207906 207894 207899 207917 207978 207973
[10:37:32.166] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:37:32.166] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0
[10:37:32.166] INFO: X-ray hit rate [MHz/cm2]: 19.4 12.7 19.4 30.9 33.1 33.8 35.8 22.3 20.6 28.4 26.9 24.9 28.6 16.8 6.7 7.3
[10:37:32.166] INFO: PixTestHighRate::doXPixelAlive() done
[10:37:32.223] INFO: PixTest:: pg_setup set to default.
[10:37:32.237] INFO: enter test to run
[10:38:18.904] INFO: test: HighRate no parameter change
[10:38:18.904] INFO: running: highrate
[10:38:18.905] INFO: ----------------------------------------------------------------------
[10:38:18.905] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:38:18.905] INFO: ----------------------------------------------------------------------
[10:38:19.523] INFO: Expecting 208000 events.
[10:38:33.232] INFO: 208000 events read in total (13182ms).
[10:38:33.237] INFO: Test took 14323ms.
[10:38:33.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:33.832] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 1 0 1 0 0 0 0 0 0 0
[10:38:33.832] INFO: number of red-efficiency pixels: 196 130 202 460 384 515 518 264 268 405 310 319 307 239 57 52
[10:38:33.832] INFO: number of X-ray hits detected: 137023 89950 137079 218482 233808 238061 252148 156042 145340 199551 190981 175639 201064 117936 47975 51898
[10:38:33.832] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:38:33.832] INFO: number of Vcal hits detected: 207790 207865 207733 207499 207588 207427 207372 207724 207670 207574 207676 207663 207670 207738 207943 207947
[10:38:33.832] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[10:38:33.832] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[10:38:33.832] INFO: X-ray hit rate [MHz/cm2]: 40.2 26.4 40.2 64.0 68.5 69.8 73.9 45.7 42.6 58.5 56.0 51.5 58.9 34.6 14.1 15.2
[10:38:33.832] INFO: PixTestHighRate::doXPixelAlive() done
[10:38:33.882] INFO: PixTest:: pg_setup set to default.
[10:38:33.896] INFO: enter test to run
[10:38:58.424] INFO: test: HighRate no parameter change
[10:38:58.424] INFO: running: highrate
[10:38:58.425] INFO: ----------------------------------------------------------------------
[10:38:58.425] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:38:58.425] INFO: ----------------------------------------------------------------------
[10:38:59.043] INFO: Expecting 208000 events.
[10:39:14.792] INFO: 208000 events read in total (15222ms).
[10:39:14.799] INFO: Test took 16364ms.
[10:39:15.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:15.623] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 1 0 1 0 0 0 0 0 0 0
[10:39:15.623] INFO: number of red-efficiency pixels: 415 247 504 1076 942 1333 1189 549 503 965 674 734 683 551 102 87
[10:39:15.623] INFO: number of X-ray hits detected: 209255 137130 209595 333599 356922 362646 385018 240400 223482 304173 291071 269168 306357 181712 73559 78927
[10:39:15.623] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:39:15.623] INFO: number of Vcal hits detected: 207514 207731 207360 206628 206842 206192 206404 207315 207348 206830 207209 207142 207224 207313 207894 207911
[10:39:15.623] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.5 99.2 99.3 99.7 99.8 99.5 99.7 99.6 99.7 99.7 100.0 100.0
[10:39:15.623] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.3 99.4 99.1 99.2 99.7 99.7 99.4 99.6 99.6 99.6 99.7 99.9 100.0
[10:39:15.623] INFO: X-ray hit rate [MHz/cm2]: 61.3 40.2 61.4 97.8 104.6 106.3 112.9 70.5 65.5 89.2 85.3 78.9 89.8 53.3 21.6 23.1
[10:39:15.623] INFO: PixTestHighRate::doXPixelAlive() done
[10:39:15.671] INFO: PixTest:: pg_setup set to default.
[10:39:15.689] INFO: enter test to run
[10:39:42.391] INFO: test: exit no parameter change
[10:39:42.884] QUIET: Connection to board 30 closed.
[10:39:42.897] INFO: pXar: this is the end, my friend