[14:48:14.332] INFO: *** Welcome to pxar ***
[14:48:14.332] INFO: *** Today: 2016/10/12
[14:48:15.118] INFO: *** Version: v1.9.0-818-g96727
[14:48:15.118] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//dacParameters35_C15.dat
[14:48:15.144] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:48:15.144] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//defaultMaskFile.dat
[14:48:15.146] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C15.dat
[14:48:15.262] INFO: clk: 4
[14:48:15.262] INFO: ctr: 4
[14:48:15.262] INFO: sda: 19
[14:48:15.262] INFO: tin: 9
[14:48:15.262] INFO: level: 15
[14:48:15.263] INFO: triggerdelay: 0
[14:48:15.263] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:48:15.263] INFO: Log level: INFO
[14:48:15.283] QUIET: Connection to board DTB_WREKRL opened.
[14:48:15.287] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:48:15.289] INFO: RPC call hashes of host and DTB match: 398089610
[14:48:16.825] INFO: DUT info:
[14:48:16.825] INFO: The DUT currently contains the following objects:
[14:48:16.825] INFO: 2 TBM Cores tbm08c (2 ON)
[14:48:16.838] INFO: TBM Core alpha (0): 7 registers set
[14:48:16.838] INFO: TBM Core beta (1): 7 registers set
[14:48:16.838] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:48:16.838] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.838] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.838] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.838] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.838] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.838] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:16.839] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:48:17.291] INFO: enter 'restricted' command line mode
[14:48:17.291] INFO: enter test to run
[14:48:22.217] INFO: test: PixelAlive no parameter change
[14:48:22.217] INFO: running: pixelalive
[14:48:22.238] INFO: ----------------------------------------------------------------------
[14:48:22.238] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:48:22.238] INFO: ----------------------------------------------------------------------
[14:48:22.565] INFO: Expecting 41600 events.
[14:48:26.880] INFO: 41600 events read in total (3597ms).
[14:48:27.043] INFO: Test took 4801ms.
[14:48:27.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:27.343] INFO: PixTestAlive::aliveTest() done
[14:48:27.343] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:48:27.372] INFO: enter test to run
[14:48:55.377] INFO: test: timing no parameter change
[14:48:55.377] INFO: running: timing
[14:48:55.381] INFO: ######################################################################
[14:48:55.381] INFO: PixTestTiming::doTest()
[14:48:55.381] INFO: ######################################################################
[14:48:55.381] INFO: ----------------------------------------------------------------------
[14:48:55.381] INFO: PixTestTiming::TBMPhaseScan()
[14:48:55.381] INFO: ----------------------------------------------------------------------
[14:54:26.563] INFO: TBM Phase Settings: 244
[14:54:26.563] INFO: 400MHz Phase: 5
[14:54:26.563] INFO: 160MHz Phase: 7
[14:54:26.563] INFO: Functional Phase Area: 4
[14:54:26.566] INFO: Test took 331185 ms.
[14:54:26.566] INFO: PixTestTiming::TBMPhaseScan() done.
[14:54:26.567] INFO: ----------------------------------------------------------------------
[14:54:26.567] INFO: PixTestTiming::ROCDelayScan()
[14:54:26.567] INFO: ----------------------------------------------------------------------
[14:56:27.489] INFO: ROC Delay Settings: 227
[14:56:27.489] INFO: ROC Header-Trailer/Token Delay: 11
[14:56:27.489] INFO: ROC Port 0 Delay: 3
[14:56:27.489] INFO: ROC Port 1 Delay: 4
[14:56:27.489] INFO: Functional ROC Area: 4
[14:56:27.492] INFO: Test took 120925 ms.
[14:56:27.492] INFO: PixTestTiming::ROCDelayScan() done.
[14:56:27.492] INFO: ----------------------------------------------------------------------
[14:56:27.492] INFO: PixTestTiming::TimingTest()
[14:56:27.492] INFO: ----------------------------------------------------------------------
[14:56:44.032] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:59.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:14.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:29.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:44.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:59.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:15.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:30.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:45.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:00.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:00.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: Read back bit status: 1
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: Timings are good!
[14:59:00.894] INFO: ----------------------------------------------------------------------
[14:59:00.894] INFO: Test took 153402 ms.
[14:59:00.894] INFO: PixTestTiming::TimingTest() done.
[14:59:00.903] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:59:00.904] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:59:00.904] INFO: PixTestTiming::doTest took 605527 ms.
[14:59:00.904] INFO: PixTestTiming::doTest() done
[14:59:00.904] INFO: Write out TBMPhaseScan_0_V0
[14:59:00.904] INFO: Write out TBMPhaseScan_1_V0
[14:59:00.904] INFO: Write out CombinedTBMPhaseScan_V0
[14:59:00.918] INFO: Write out ROCDelayScan3_V0
[14:59:00.919] INFO: enter test to run
[15:00:20.869] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:00:20.869] INFO: running: highrate
[15:00:20.869] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:00:21.125] INFO: ----------------------------------------------------------------------
[15:00:21.125] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:00:21.125] INFO: ----------------------------------------------------------------------
[15:00:21.126] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:00:21.126] INFO: edge/corner pixel THR is adjusted
[15:00:21.126] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:00:22.108] INFO: Collecting data for 5 seconds...
[15:00:27.124] INFO: Done with hot pixel readout
[15:00:38.842] INFO: PixTest:: pg_setup set to default.
[15:00:38.842] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:00:38.843] INFO: 29 hot pixels found in step 0
[15:00:39.836] INFO: Collecting data for 5 seconds...
[15:00:44.851] INFO: Done with hot pixel readout
[15:00:56.646] INFO: PixTest:: pg_setup set to default.
[15:00:56.646] INFO: 24 hot pixels found in step 1
[15:00:57.640] INFO: Collecting data for 5 seconds...
[15:01:02.656] INFO: Done with hot pixel readout
[15:01:14.397] INFO: PixTest:: pg_setup set to default.
[15:01:14.398] INFO: 23 hot pixels found in step 2
[15:01:15.391] INFO: Collecting data for 5 seconds...
[15:01:20.407] INFO: Done with hot pixel readout
[15:01:32.101] INFO: PixTest:: pg_setup set to default.
[15:01:32.101] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:01:32.102] INFO: 27 hot pixels found in step 3
[15:01:33.095] INFO: Collecting data for 5 seconds...
[15:01:38.111] INFO: Done with hot pixel readout
[15:01:49.833] INFO: PixTest:: pg_setup set to default.
[15:01:49.833] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:01:49.834] INFO: 20 hot pixels found in step 4
[15:01:50.827] INFO: Collecting data for 5 seconds...
[15:01:55.843] INFO: Done with hot pixel readout
[15:02:07.595] INFO: PixTest:: pg_setup set to default.
[15:02:07.595] INFO: 21 hot pixels found in step 5
[15:02:08.588] INFO: Collecting data for 5 seconds...
[15:02:13.603] INFO: Done with hot pixel readout
[15:02:25.377] INFO: PixTest:: pg_setup set to default.
[15:02:25.377] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:02:25.378] INFO: 21 hot pixels found in step 6
[15:02:26.371] INFO: Collecting data for 5 seconds...
[15:02:31.387] INFO: Done with hot pixel readout
[15:02:42.970] INFO: PixTest:: pg_setup set to default.
[15:02:42.970] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:02:42.971] INFO: 21 hot pixels found in step 7
[15:02:43.964] INFO: Collecting data for 5 seconds...
[15:02:48.980] INFO: Done with hot pixel readout
[15:03:00.409] INFO: PixTest:: pg_setup set to default.
[15:03:00.409] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:00.410] INFO: 19 hot pixels found in step 8
[15:03:01.403] INFO: Collecting data for 5 seconds...
[15:03:06.419] INFO: Done with hot pixel readout
[15:03:18.262] INFO: PixTest:: pg_setup set to default.
[15:03:18.262] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:18.263] INFO: 9 hot pixels found in step 9
[15:03:19.255] INFO: Collecting data for 5 seconds...
[15:03:24.271] INFO: Done with hot pixel readout
[15:03:36.039] INFO: PixTest:: pg_setup set to default.
[15:03:36.039] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:36.040] INFO: 8 hot pixels found in step 10
[15:03:37.032] INFO: Collecting data for 5 seconds...
[15:03:42.049] INFO: Done with hot pixel readout
[15:03:53.881] INFO: PixTest:: pg_setup set to default.
[15:03:53.881] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:53.882] INFO: 14 hot pixels found in step 11
[15:03:54.875] INFO: Collecting data for 5 seconds...
[15:03:59.892] INFO: Done with hot pixel readout
[15:04:11.640] INFO: PixTest:: pg_setup set to default.
[15:04:11.640] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:11.641] INFO: 12 hot pixels found in step 12
[15:04:12.634] INFO: Collecting data for 5 seconds...
[15:04:17.649] INFO: Done with hot pixel readout
[15:04:29.473] INFO: PixTest:: pg_setup set to default.
[15:04:29.473] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:29.474] INFO: 18 hot pixels found in step 13
[15:04:30.466] INFO: Collecting data for 5 seconds...
[15:04:35.483] INFO: Done with hot pixel readout
[15:04:47.257] INFO: PixTest:: pg_setup set to default.
[15:04:47.257] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:47.257] INFO: 10 hot pixels found in step 14
[15:04:47.294] INFO: 10 hot pixels could not be trimmed and have been masked.
[15:04:47.298] INFO: PixTest::trimHotPixels() done
[15:04:47.314] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C0.dat
[15:04:47.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C1.dat
[15:04:47.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C2.dat
[15:04:47.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C3.dat
[15:04:47.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C4.dat
[15:04:47.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C5.dat
[15:04:47.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C6.dat
[15:04:47.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C7.dat
[15:04:47.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C8.dat
[15:04:47.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C9.dat
[15:04:47.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C10.dat
[15:04:47.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C11.dat
[15:04:47.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C12.dat
[15:04:47.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C13.dat
[15:04:47.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C14.dat
[15:04:47.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C15.dat
[15:04:47.400] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//defaultMaskFile.dat
[15:04:47.410] INFO: enter test to run
[15:05:09.571] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:05:09.571] INFO: running: highrate
[15:05:09.575] INFO: ----------------------------------------------------------------------
[15:05:09.575] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:05:09.576] INFO: ----------------------------------------------------------------------
[15:05:09.576] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:05:09.576] INFO: edge/corner pixel THR is adjusted
[15:05:09.576] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:05:10.533] INFO: Collecting data for 1 seconds...
[15:05:11.536] INFO: Done with hot pixel readout
[15:05:15.603] INFO: PixTest:: pg_setup set to default.
[15:05:15.604] INFO: 0 hot pixels found in step 0
[15:05:15.609] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:05:15.697] INFO: PixTest::trimHotPixels() done
[15:05:15.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C0.dat
[15:05:15.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C1.dat
[15:05:15.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C2.dat
[15:05:15.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C3.dat
[15:05:15.725] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C4.dat
[15:05:15.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C5.dat
[15:05:15.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C6.dat
[15:05:15.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C7.dat
[15:05:15.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C8.dat
[15:05:15.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C9.dat
[15:05:15.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C10.dat
[15:05:15.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C11.dat
[15:05:15.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C12.dat
[15:05:15.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C13.dat
[15:05:15.776] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C14.dat
[15:05:15.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//trimParameters35_C15.dat
[15:05:15.787] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-13_FPIXTest-17C-FNAL-161007-1342-150V_2016-10-07_13h42m_1475865776/000_FPIXTest_p17//defaultMaskFile.dat
[15:05:15.798] INFO: enter test to run
[15:05:48.243] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:05:48.243] INFO: running: xray
[15:05:48.244] INFO: ----------------------------------------------------------------------
[15:05:48.244] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:05:48.244] INFO: ----------------------------------------------------------------------
[15:05:49.207] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:06:00.590] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:06:30.417] INFO: Resuming triggers.
[15:06:41.803] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:07:11.361] INFO: Resuming triggers.
[15:07:22.748] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:07:51.341] INFO: Resuming triggers.
[15:08:02.728] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:08:32.468] INFO: Resuming triggers.
[15:08:43.855] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:09:13.560] INFO: Resuming triggers.
[15:09:24.948] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:09:54.663] INFO: Resuming triggers.
[15:10:06.048] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:10:36.898] INFO: Resuming triggers.
[15:10:48.303] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:11:18.620] INFO: Resuming triggers.
[15:11:27.881] INFO: data taking finished, elapsed time: 100 seconds.
[15:11:52.480] INFO: PixTest:: pg_setup set to default.
[15:11:52.483] INFO: PixTestXray::doPhRun() done
[15:11:52.646] INFO: enter test to run
[15:14:19.159] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:14:19.159] INFO: running: xray
[15:14:19.160] INFO: ----------------------------------------------------------------------
[15:14:19.160] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:14:19.160] INFO: ----------------------------------------------------------------------
[15:14:20.124] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:14:26.680] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:14:56.857] INFO: Resuming triggers.
[15:15:03.406] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:15:33.660] INFO: Resuming triggers.
[15:15:40.212] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:16:10.402] INFO: Resuming triggers.
[15:16:16.955] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:16:47.362] INFO: Resuming triggers.
[15:16:53.915] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:17:24.448] INFO: Resuming triggers.
[15:17:30.999] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:18:01.219] INFO: Resuming triggers.
[15:18:07.770] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:18:38.087] INFO: Resuming triggers.
[15:18:44.631] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:19:14.876] INFO: Resuming triggers.
[15:19:21.428] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:19:51.587] INFO: Resuming triggers.
[15:19:58.137] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:20:29.126] INFO: Resuming triggers.
[15:20:35.671] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:21:06.524] INFO: Resuming triggers.
[15:21:13.071] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:21:43.927] INFO: Resuming triggers.
[15:21:50.476] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[15:22:21.342] INFO: Resuming triggers.
[15:22:27.895] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:22:58.935] INFO: Resuming triggers.
[15:23:05.482] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:23:36.394] INFO: Resuming triggers.
[15:23:38.473] INFO: data taking finished, elapsed time: 100 seconds.
[15:23:48.539] INFO: PixTest:: pg_setup set to default.
[15:23:48.543] INFO: PixTestXray::doPhRun() done
[15:23:48.694] INFO: enter test to run
[15:24:03.075] INFO: test: HighRate no parameter change
[15:24:03.075] INFO: running: highrate
[15:24:03.091] INFO: ----------------------------------------------------------------------
[15:24:03.092] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:24:03.092] INFO: ----------------------------------------------------------------------
[15:24:03.283] INFO: Expecting 768 events.
[15:24:04.435] INFO: 768 events read in total (437ms).
[15:24:04.435] INFO: Test took 1306ms.
[15:24:05.238] INFO: Expecting 41600 events.
[15:24:08.378] INFO: 41600 events read in total (2613ms).
[15:24:08.379] INFO: Test took 3938ms.
[15:24:08.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:09.140] INFO: Expecting 41600 events.
[15:24:12.384] INFO: 41600 events read in total (2718ms).
[15:24:12.385] INFO: Test took 3953ms.
[15:24:12.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:13.138] INFO: Expecting 41600 events.
[15:24:16.333] INFO: 41600 events read in total (2668ms).
[15:24:16.334] INFO: Test took 3895ms.
[15:24:16.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:17.090] INFO: Expecting 41600 events.
[15:24:20.416] INFO: 41600 events read in total (2799ms).
[15:24:20.417] INFO: Test took 4029ms.
[15:24:20.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:21.172] INFO: Expecting 41600 events.
[15:24:24.436] INFO: 41600 events read in total (2737ms).
[15:24:24.437] INFO: Test took 3965ms.
[15:24:24.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:25.193] INFO: Expecting 41600 events.
[15:24:28.459] INFO: 41600 events read in total (2739ms).
[15:24:28.460] INFO: Test took 3968ms.
[15:24:28.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:29.210] INFO: Expecting 41600 events.
[15:24:32.485] INFO: 41600 events read in total (2748ms).
[15:24:32.486] INFO: Test took 3970ms.
[15:24:32.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:33.240] INFO: Expecting 41600 events.
[15:24:36.579] INFO: 41600 events read in total (2813ms).
[15:24:36.580] INFO: Test took 4041ms.
[15:24:36.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:37.337] INFO: Expecting 41600 events.
[15:24:40.649] INFO: 41600 events read in total (2785ms).
[15:24:40.651] INFO: Test took 4016ms.
[15:24:40.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:41.408] INFO: Expecting 41600 events.
[15:24:44.651] INFO: 41600 events read in total (2716ms).
[15:24:44.652] INFO: Test took 3946ms.
[15:24:44.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:45.404] INFO: Expecting 41600 events.
[15:24:48.709] INFO: 41600 events read in total (2778ms).
[15:24:48.710] INFO: Test took 4003ms.
[15:24:48.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:49.464] INFO: Expecting 41600 events.
[15:24:52.803] INFO: 41600 events read in total (2813ms).
[15:24:52.804] INFO: Test took 4039ms.
[15:24:52.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:53.562] INFO: Expecting 41600 events.
[15:24:56.882] INFO: 41600 events read in total (2794ms).
[15:24:56.883] INFO: Test took 4024ms.
[15:24:56.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:57.636] INFO: Expecting 41600 events.
[15:25:00.953] INFO: 41600 events read in total (2790ms).
[15:25:00.954] INFO: Test took 4006ms.
[15:25:00.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:01.698] INFO: Expecting 41600 events.
[15:25:04.988] INFO: 41600 events read in total (2763ms).
[15:25:04.989] INFO: Test took 3979ms.
[15:25:05.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:05.736] INFO: Expecting 41600 events.
[15:25:09.071] INFO: 41600 events read in total (2808ms).
[15:25:09.071] INFO: Test took 4024ms.
[15:25:09.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:09.823] INFO: Expecting 41600 events.
[15:25:13.134] INFO: 41600 events read in total (2784ms).
[15:25:13.135] INFO: Test took 4009ms.
[15:25:13.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:13.888] INFO: Expecting 41600 events.
[15:25:17.186] INFO: 41600 events read in total (2771ms).
[15:25:17.187] INFO: Test took 3997ms.
[15:25:17.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:17.942] INFO: Expecting 41600 events.
[15:25:21.197] INFO: 41600 events read in total (2728ms).
[15:25:21.198] INFO: Test took 3956ms.
[15:25:21.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:21.957] INFO: Expecting 41600 events.
[15:25:25.087] INFO: 41600 events read in total (2603ms).
[15:25:25.088] INFO: Test took 3836ms.
[15:25:25.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:25.474] INFO: enter test to run
[15:26:02.522] INFO: test: HighRate no parameter change
[15:26:02.522] INFO: running: highrate
[15:26:02.523] INFO: ----------------------------------------------------------------------
[15:26:02.523] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:26:02.523] INFO: ----------------------------------------------------------------------
[15:26:03.170] INFO: Expecting 208000 events.
[15:26:15.402] INFO: 208000 events read in total (11705ms).
[15:26:15.405] INFO: Test took 12871ms.
[15:26:15.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:15.818] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:26:15.833] INFO: number of red-efficiency pixels: 77 43 100 169 124 165 147 120 107 110 129 117 117 64 16 38
[15:26:15.833] INFO: number of X-ray hits detected: 68328 44602 72064 112159 117332 123522 122353 87161 78929 105519 98859 84162 88388 54344 21785 28200
[15:26:15.833] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:26:15.833] INFO: number of Vcal hits detected: 207921 207957 207897 207826 207872 207833 207851 207879 207890 207889 207869 207880 207881 207936 207984 207913
[15:26:15.833] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:26:15.833] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:26:15.833] INFO: X-ray hit rate [MHz/cm2]: 20.0 13.1 21.1 32.9 34.4 36.2 35.9 25.5 23.1 30.9 29.0 24.7 25.9 15.9 6.4 8.3
[15:26:15.833] INFO: PixTestHighRate::doXPixelAlive() done
[15:26:15.881] INFO: PixTest:: pg_setup set to default.
[15:26:15.891] INFO: enter test to run
[15:26:41.018] INFO: test: HighRate no parameter change
[15:26:41.018] INFO: running: highrate
[15:26:41.019] INFO: ----------------------------------------------------------------------
[15:26:41.019] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:26:41.019] INFO: ----------------------------------------------------------------------
[15:26:41.641] INFO: Expecting 208000 events.
[15:26:55.765] INFO: 208000 events read in total (13597ms).
[15:26:55.771] INFO: Test took 14743ms.
[15:26:56.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:56.385] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:26:56.385] INFO: number of red-efficiency pixels: 254 117 336 535 548 469 464 390 317 372 410 387 341 234 52 71
[15:26:56.385] INFO: number of X-ray hits detected: 140118 92241 147785 229913 239846 252440 251197 179019 162205 215808 202571 173797 180606 110889 44560 58245
[15:26:56.385] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:26:56.385] INFO: number of Vcal hits detected: 207725 207874 207627 207418 207397 207484 207475 207579 207662 207605 207562 207592 207639 207754 207947 207880
[15:26:56.385] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:26:56.385] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[15:26:56.385] INFO: X-ray hit rate [MHz/cm2]: 41.1 27.0 43.3 67.4 70.3 74.0 73.6 52.5 47.5 63.3 59.4 50.9 52.9 32.5 13.1 17.1
[15:26:56.385] INFO: PixTestHighRate::doXPixelAlive() done
[15:26:56.433] INFO: PixTest:: pg_setup set to default.
[15:26:56.451] INFO: enter test to run
[15:27:10.570] INFO: test: HighRate no parameter change
[15:27:10.570] INFO: running: highrate
[15:27:10.571] INFO: ----------------------------------------------------------------------
[15:27:10.571] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:27:10.571] INFO: ----------------------------------------------------------------------
[15:27:11.191] INFO: Expecting 208000 events.
[15:27:26.809] INFO: 208000 events read in total (15091ms).
[15:27:26.819] INFO: Test took 16237ms.
[15:27:27.270] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:27.626] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:27:27.626] INFO: number of red-efficiency pixels: 578 228 749 1274 1300 1120 1117 934 693 858 857 742 772 443 87 109
[15:27:27.626] INFO: number of X-ray hits detected: 212049 138440 223095 346341 361972 380205 378560 270079 244787 324713 306174 262208 272507 167845 67833 87742
[15:27:27.626] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:27:27.626] INFO: number of Vcal hits detected: 207263 207754 206942 206322 206281 206557 206537 206739 207173 206983 206996 207086 207074 207455 207913 207838
[15:27:27.626] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.3 99.3 99.4 99.4 99.4 99.6 99.6 99.6 99.6 99.6 99.8 100.0 99.9
[15:27:27.626] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.5 99.2 99.2 99.3 99.3 99.4 99.6 99.5 99.5 99.6 99.6 99.7 100.0 99.9
[15:27:27.626] INFO: X-ray hit rate [MHz/cm2]: 62.2 40.6 65.4 101.5 106.1 111.4 111.0 79.2 71.7 95.2 89.7 76.9 79.9 49.2 19.9 25.7
[15:27:27.626] INFO: PixTestHighRate::doXPixelAlive() done
[15:27:27.679] INFO: PixTest:: pg_setup set to default.
[15:27:27.693] INFO: enter test to run
[15:27:30.850] INFO: test: exit no parameter change
[15:27:31.417] QUIET: Connection to board 33 closed.
[15:27:31.479] INFO: pXar: this is the end, my friend