[12:33:08.337] INFO: *** Welcome to pxar ***
[12:33:08.337] INFO: *** Today: 2016/09/29
[12:33:08.359] INFO: *** Version: v1.9.0-818-g96727
[12:33:08.359] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//dacParameters35_C15.dat
[12:33:08.360] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:33:08.360] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//defaultMaskFile.dat
[12:33:08.360] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C15.dat
[12:33:08.430] INFO: clk: 4
[12:33:08.430] INFO: ctr: 4
[12:33:08.430] INFO: sda: 19
[12:33:08.430] INFO: tin: 9
[12:33:08.430] INFO: level: 15
[12:33:08.430] INFO: triggerdelay: 0
[12:33:08.430] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:33:08.430] INFO: Log level: INFO
[12:33:08.447] QUIET: Connection to board DTB_WREKRL opened.
[12:33:08.451] 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:
------------------------------------------------------
[12:33:08.454] INFO: RPC call hashes of host and DTB match: 398089610
[12:33:09.987] INFO: DUT info:
[12:33:09.987] INFO: The DUT currently contains the following objects:
[12:33:09.987] INFO: 2 TBM Cores tbm08c (2 ON)
[12:33:09.987] INFO: TBM Core alpha (0): 7 registers set
[12:33:09.987] INFO: TBM Core beta (1): 7 registers set
[12:33:09.987] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:33:09.987] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.987] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:09.988] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:10.391] INFO: enter 'restricted' command line mode
[12:33:10.391] INFO: enter test to run
[12:33:14.943] INFO: test: PixelAlive no parameter change
[12:33:14.943] INFO: running: pixelalive
[12:33:14.952] INFO: ----------------------------------------------------------------------
[12:33:14.952] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:33:14.953] INFO: ----------------------------------------------------------------------
[12:33:15.271] INFO: Expecting 41600 events.
[12:33:19.610] INFO: 41600 events read in total (3620ms).
[12:33:19.778] INFO: Test took 4823ms.
[12:33:19.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:20.053] INFO: PixTestAlive::aliveTest() done
[12:33:20.053] INFO: number of dead pixels (per ROC): 0 1 2 0 0 0 0 2 1 0 0 160 0 0 0 0
[12:33:20.086] INFO: enter test to run
[12:33:22.359] INFO: test: timing no parameter change
[12:33:22.359] INFO: running: timing
[12:33:22.363] INFO: ######################################################################
[12:33:22.363] INFO: PixTestTiming::doTest()
[12:33:22.363] INFO: ######################################################################
[12:33:22.363] INFO: ----------------------------------------------------------------------
[12:33:22.363] INFO: PixTestTiming::TBMPhaseScan()
[12:33:22.363] INFO: ----------------------------------------------------------------------
[12:38:33.934] INFO: TBM Phase Settings: 236
[12:38:33.934] INFO: 400MHz Phase: 3
[12:38:33.934] INFO: 160MHz Phase: 7
[12:38:33.934] INFO: Functional Phase Area: 4
[12:38:33.953] INFO: Test took 311590 ms.
[12:38:33.953] INFO: PixTestTiming::TBMPhaseScan() done.
[12:38:33.953] INFO: ----------------------------------------------------------------------
[12:38:33.953] INFO: PixTestTiming::ROCDelayScan()
[12:38:33.954] INFO: ----------------------------------------------------------------------
[12:42:01.488] INFO: ROC Delay Settings: 227
[12:42:01.488] INFO: ROC Header-Trailer/Token Delay: 11
[12:42:01.488] INFO: ROC Port 0 Delay: 3
[12:42:01.488] INFO: ROC Port 1 Delay: 4
[12:42:01.488] INFO: Functional ROC Area: 4
[12:42:01.492] INFO: Test took 207539 ms.
[12:42:01.492] INFO: PixTestTiming::ROCDelayScan() done.
[12:42:01.492] INFO: ----------------------------------------------------------------------
[12:42:01.492] INFO: PixTestTiming::TimingTest()
[12:42:01.492] INFO: ----------------------------------------------------------------------
[12:42:17.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:32.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:47.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:02.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:17.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:32.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:47.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:02.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:17.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:32.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:32.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: Read back bit status: 1
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: Timings are good!
[12:44:32.575] INFO: ----------------------------------------------------------------------
[12:44:32.575] INFO: Test took 151083 ms.
[12:44:32.575] INFO: PixTestTiming::TimingTest() done.
[12:44:32.575] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:44:32.575] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:44:32.575] INFO: PixTestTiming::doTest took 670215 ms.
[12:44:32.575] INFO: PixTestTiming::doTest() done
[12:44:32.575] INFO: Write out TBMPhaseScan_0_V0
[12:44:32.575] INFO: Write out TBMPhaseScan_1_V0
[12:44:32.575] INFO: Write out CombinedTBMPhaseScan_V0
[12:44:32.576] INFO: Write out ROCDelayScan3_V0
[12:44:32.577] INFO: enter test to run
[12:45:20.763] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:45:20.763] INFO: running: highrate
[12:45:20.763] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:45:20.920] INFO: ----------------------------------------------------------------------
[12:45:20.920] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:45:20.920] INFO: ----------------------------------------------------------------------
[12:45:20.920] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:45:20.920] INFO: edge/corner pixel THR is adjusted
[12:45:20.920] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:45:21.879] INFO: Collecting data for 5 seconds...
[12:45:26.896] INFO: Done with hot pixel readout
[12:45:38.451] INFO: PixTest:: pg_setup set to default.
[12:45:38.452] INFO: 21 hot pixels found in step 0
[12:45:39.444] INFO: Collecting data for 5 seconds...
[12:45:44.461] INFO: Done with hot pixel readout
[12:45:56.158] INFO: PixTest:: pg_setup set to default.
[12:45:56.159] INFO: 16 hot pixels found in step 1
[12:45:57.151] INFO: Collecting data for 5 seconds...
[12:46:02.168] INFO: Done with hot pixel readout
[12:46:13.679] INFO: PixTest:: pg_setup set to default.
[12:46:13.680] INFO: 17 hot pixels found in step 2
[12:46:14.672] INFO: Collecting data for 5 seconds...
[12:46:19.689] INFO: Done with hot pixel readout
[12:46:31.297] INFO: PixTest:: pg_setup set to default.
[12:46:31.298] INFO: 18 hot pixels found in step 3
[12:46:32.291] INFO: Collecting data for 5 seconds...
[12:46:37.309] INFO: Done with hot pixel readout
[12:46:48.808] INFO: PixTest:: pg_setup set to default.
[12:46:48.809] INFO: 19 hot pixels found in step 4
[12:46:49.805] INFO: Collecting data for 5 seconds...
[12:46:54.822] INFO: Done with hot pixel readout
[12:47:05.913] INFO: PixTest:: pg_setup set to default.
[12:47:05.913] INFO: 15 hot pixels found in step 5
[12:47:06.905] INFO: Collecting data for 5 seconds...
[12:47:11.924] INFO: Done with hot pixel readout
[12:47:23.063] INFO: PixTest:: pg_setup set to default.
[12:47:23.063] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:47:23.064] INFO: 13 hot pixels found in step 6
[12:47:24.057] INFO: Collecting data for 5 seconds...
[12:47:29.075] INFO: Done with hot pixel readout
[12:47:40.451] INFO: PixTest:: pg_setup set to default.
[12:47:40.451] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:47:40.452] INFO: 8 hot pixels found in step 7
[12:47:41.443] INFO: Collecting data for 5 seconds...
[12:47:46.460] INFO: Done with hot pixel readout
[12:47:57.798] INFO: PixTest:: pg_setup set to default.
[12:47:57.799] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:47:57.799] INFO: 5 hot pixels found in step 8
[12:47:58.791] INFO: Collecting data for 5 seconds...
[12:48:03.809] INFO: Done with hot pixel readout
[12:48:14.957] INFO: PixTest:: pg_setup set to default.
[12:48:14.957] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:48:14.958] INFO: 7 hot pixels found in step 9
[12:48:15.950] INFO: Collecting data for 5 seconds...
[12:48:20.967] INFO: Done with hot pixel readout
[12:48:32.378] INFO: PixTest:: pg_setup set to default.
[12:48:32.378] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:48:32.379] INFO: 6 hot pixels found in step 10
[12:48:33.371] INFO: Collecting data for 5 seconds...
[12:48:38.389] INFO: Done with hot pixel readout
[12:48:49.838] INFO: PixTest:: pg_setup set to default.
[12:48:49.838] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:48:49.839] INFO: 3 hot pixels found in step 11
[12:48:50.831] INFO: Collecting data for 5 seconds...
[12:48:55.849] INFO: Done with hot pixel readout
[12:49:07.206] INFO: PixTest:: pg_setup set to default.
[12:49:07.206] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:49:07.207] INFO: 6 hot pixels found in step 12
[12:49:08.198] INFO: Collecting data for 5 seconds...
[12:49:13.218] INFO: Done with hot pixel readout
[12:49:24.549] INFO: PixTest:: pg_setup set to default.
[12:49:24.549] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:49:24.550] INFO: 5 hot pixels found in step 13
[12:49:25.542] INFO: Collecting data for 5 seconds...
[12:49:30.560] INFO: Done with hot pixel readout
[12:49:42.165] INFO: PixTest:: pg_setup set to default.
[12:49:42.165] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:49:42.166] INFO: 5 hot pixels found in step 14
[12:49:42.202] INFO: 5 hot pixels could not be trimmed and have been masked.
[12:49:42.205] INFO: PixTest::trimHotPixels() done
[12:49:42.205] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C0.dat
[12:49:42.211] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C1.dat
[12:49:42.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C2.dat
[12:49:42.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C3.dat
[12:49:42.228] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C4.dat
[12:49:42.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C5.dat
[12:49:42.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C6.dat
[12:49:42.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C7.dat
[12:49:42.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C8.dat
[12:49:42.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C9.dat
[12:49:42.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C10.dat
[12:49:42.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C11.dat
[12:49:42.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C12.dat
[12:49:42.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C13.dat
[12:49:42.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C14.dat
[12:49:42.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C15.dat
[12:49:42.293] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//defaultMaskFile.dat
[12:49:42.320] INFO: enter test to run
[12:50:01.849] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:50:01.849] INFO: running: highrate
[12:50:01.853] INFO: ----------------------------------------------------------------------
[12:50:01.853] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:50:01.853] INFO: ----------------------------------------------------------------------
[12:50:01.853] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:50:01.854] INFO: edge/corner pixel THR is adjusted
[12:50:01.854] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:50:02.810] INFO: Collecting data for 1 seconds...
[12:50:03.815] INFO: Done with hot pixel readout
[12:50:07.629] INFO: PixTest:: pg_setup set to default.
[12:50:07.630] INFO: 0 hot pixels found in step 0
[12:50:07.636] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:50:07.723] INFO: PixTest::trimHotPixels() done
[12:50:07.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C0.dat
[12:50:07.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C1.dat
[12:50:07.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C2.dat
[12:50:07.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C3.dat
[12:50:07.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C4.dat
[12:50:07.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C5.dat
[12:50:07.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C6.dat
[12:50:07.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C7.dat
[12:50:07.770] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C8.dat
[12:50:07.776] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C9.dat
[12:50:07.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C10.dat
[12:50:07.787] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C11.dat
[12:50:07.792] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C12.dat
[12:50:07.798] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C13.dat
[12:50:07.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C14.dat
[12:50:07.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C15.dat
[12:50:07.814] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-45_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//defaultMaskFile.dat
[12:50:07.823] INFO: enter test to run
[12:50:29.064] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:50:29.064] INFO: running: xray
[12:50:29.066] INFO: ----------------------------------------------------------------------
[12:50:29.066] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:50:29.066] INFO: ----------------------------------------------------------------------
[12:50:30.039] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:50:42.061] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:51:12.341] INFO: Resuming triggers.
[12:51:24.363] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:51:54.189] INFO: Resuming triggers.
[12:52:06.211] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:52:35.505] INFO: Resuming triggers.
[12:52:47.524] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:53:16.810] INFO: Resuming triggers.
[12:53:28.828] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:53:58.173] INFO: Resuming triggers.
[12:54:10.189] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:54:39.458] INFO: Resuming triggers.
[12:54:51.475] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:55:20.772] INFO: Resuming triggers.
[12:55:32.785] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:56:01.004] INFO: Resuming triggers.
[12:56:06.211] INFO: data taking finished, elapsed time: 100 seconds.
[12:56:16.741] INFO: PixTest:: pg_setup set to default.
[12:56:16.744] INFO: PixTestXray::doPhRun() done
[12:56:16.883] INFO: enter test to run
[12:56:51.894] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:56:51.894] INFO: running: xray
[12:56:51.895] INFO: ----------------------------------------------------------------------
[12:56:51.895] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:56:51.895] INFO: ----------------------------------------------------------------------
[12:56:52.870] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:57:00.111] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:57:30.352] INFO: Resuming triggers.
[12:57:37.594] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:58:07.967] INFO: Resuming triggers.
[12:58:15.207] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:58:45.551] INFO: Resuming triggers.
[12:58:52.792] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:59:23.181] INFO: Resuming triggers.
[12:59:30.418] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[13:00:01.475] INFO: Resuming triggers.
[13:00:08.720] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:00:39.413] INFO: Resuming triggers.
[13:00:46.657] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:01:17.575] INFO: Resuming triggers.
[13:01:24.820] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:01:55.639] INFO: Resuming triggers.
[13:02:02.880] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:02:34.334] INFO: Resuming triggers.
[13:02:41.579] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:03:13.274] INFO: Resuming triggers.
[13:03:20.513] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:03:52.499] INFO: Resuming triggers.
[13:03:59.741] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:04:29.998] INFO: Resuming triggers.
[13:04:37.238] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:05:07.523] INFO: Resuming triggers.
[13:05:13.745] INFO: data taking finished, elapsed time: 100 seconds.
[13:05:39.857] INFO: PixTest:: pg_setup set to default.
[13:05:39.860] INFO: PixTestXray::doPhRun() done
[13:05:40.010] INFO: enter test to run
[13:06:22.978] INFO: test: setting parameters: ->HighRate:caldelscan<-
[13:06:22.978] INFO: running:
[13:06:22.978] INFO: command -><- not known, ignored
[13:06:22.978] INFO: enter test to run
[13:06:38.330] INFO: test: HighRate no parameter change
[13:06:38.330] INFO: running: highrate
[13:06:38.331] INFO: ----------------------------------------------------------------------
[13:06:38.331] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:06:38.331] INFO: ----------------------------------------------------------------------
[13:06:38.502] INFO: Expecting 768 events.
[13:06:39.636] INFO: 768 events read in total (419ms).
[13:06:39.636] INFO: Test took 1269ms.
[13:06:40.439] INFO: Expecting 41600 events.
[13:06:43.503] INFO: 41600 events read in total (2537ms).
[13:06:43.504] INFO: Test took 3861ms.
[13:06:43.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:44.260] INFO: Expecting 41600 events.
[13:06:47.386] INFO: 41600 events read in total (2599ms).
[13:06:47.386] INFO: Test took 3835ms.
[13:06:47.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:48.147] INFO: Expecting 41600 events.
[13:06:51.336] INFO: 41600 events read in total (2662ms).
[13:06:51.337] INFO: Test took 3904ms.
[13:06:51.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:52.099] INFO: Expecting 41600 events.
[13:06:55.296] INFO: 41600 events read in total (2670ms).
[13:06:55.297] INFO: Test took 3912ms.
[13:06:55.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:56.059] INFO: Expecting 41600 events.
[13:06:59.256] INFO: 41600 events read in total (2670ms).
[13:06:59.257] INFO: Test took 3913ms.
[13:06:59.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:00.019] INFO: Expecting 41600 events.
[13:07:03.214] INFO: 41600 events read in total (2668ms).
[13:07:03.215] INFO: Test took 3911ms.
[13:07:03.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:03.976] INFO: Expecting 41600 events.
[13:07:07.199] INFO: 41600 events read in total (2696ms).
[13:07:07.200] INFO: Test took 3936ms.
[13:07:07.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:07.961] INFO: Expecting 41600 events.
[13:07:11.170] INFO: 41600 events read in total (2682ms).
[13:07:11.171] INFO: Test took 3922ms.
[13:07:11.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:11.932] INFO: Expecting 41600 events.
[13:07:15.139] INFO: 41600 events read in total (2680ms).
[13:07:15.140] INFO: Test took 3921ms.
[13:07:15.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:15.897] INFO: Expecting 41600 events.
[13:07:19.078] INFO: 41600 events read in total (2654ms).
[13:07:19.079] INFO: Test took 3891ms.
[13:07:19.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:19.838] INFO: Expecting 41600 events.
[13:07:23.015] INFO: 41600 events read in total (2650ms).
[13:07:23.016] INFO: Test took 3890ms.
[13:07:23.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:23.777] INFO: Expecting 41600 events.
[13:07:26.986] INFO: 41600 events read in total (2682ms).
[13:07:26.987] INFO: Test took 3923ms.
[13:07:27.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:27.745] INFO: Expecting 41600 events.
[13:07:30.946] INFO: 41600 events read in total (2674ms).
[13:07:30.947] INFO: Test took 3911ms.
[13:07:30.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:31.708] INFO: Expecting 41600 events.
[13:07:34.918] INFO: 41600 events read in total (2683ms).
[13:07:34.919] INFO: Test took 3924ms.
[13:07:34.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:35.679] INFO: Expecting 41600 events.
[13:07:38.878] INFO: 41600 events read in total (2672ms).
[13:07:38.879] INFO: Test took 3912ms.
[13:07:38.910] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:39.639] INFO: Expecting 41600 events.
[13:07:42.839] INFO: 41600 events read in total (2673ms).
[13:07:42.840] INFO: Test took 3913ms.
[13:07:42.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.600] INFO: Expecting 41600 events.
[13:07:46.810] INFO: 41600 events read in total (2683ms).
[13:07:46.811] INFO: Test took 3922ms.
[13:07:46.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:47.572] INFO: Expecting 41600 events.
[13:07:50.781] INFO: 41600 events read in total (2683ms).
[13:07:50.782] INFO: Test took 3923ms.
[13:07:50.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:51.542] INFO: Expecting 41600 events.
[13:07:54.730] INFO: 41600 events read in total (2662ms).
[13:07:54.731] INFO: Test took 3901ms.
[13:07:54.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:55.491] INFO: Expecting 41600 events.
[13:07:58.506] INFO: 41600 events read in total (2488ms).
[13:07:58.507] INFO: Test took 3727ms.
[13:07:58.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:58.906] INFO: enter test to run
[13:08:01.633] INFO: test: HighRate no parameter change
[13:08:01.633] INFO: running: highrate
[13:08:01.634] INFO: ----------------------------------------------------------------------
[13:08:01.634] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:01.634] INFO: ----------------------------------------------------------------------
[13:08:02.250] INFO: Expecting 208000 events.
[13:08:13.936] INFO: 208000 events read in total (11159ms).
[13:08:13.939] INFO: Test took 12298ms.
[13:08:14.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:14.316] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 1 1 0 0 94 0 0 0 0
[13:08:14.317] INFO: number of red-efficiency pixels: 1485 44 100 111 104 118 129 93 52 91 98 238 83 65 21 29
[13:08:14.317] INFO: number of X-ray hits detected: 62254 38894 62042 92286 96678 98401 98469 73250 65149 86760 86740 72763 76524 47684 20247 24168
[13:08:14.317] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:08:14.317] INFO: number of Vcal hits detected: 206484 207956 207802 207889 207893 207880 207869 207854 207898 207908 207901 200004 207916 207934 207979 207971
[13:08:14.317] INFO: Vcal hit fiducial efficiency (%): 99.3 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 98.3 100.0 100.0 100.0 100.0
[13:08:14.317] INFO: Vcal hit overall efficiency (%): 99.3 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 96.2 100.0 100.0 100.0 100.0
[13:08:14.317] INFO: X-ray hit rate [MHz/cm2]: 18.2 11.4 18.2 27.0 28.3 28.8 28.9 21.5 19.1 25.4 25.4 21.3 22.4 14.0 5.9 7.1
[13:08:14.317] INFO: PixTestHighRate::doXPixelAlive() done
[13:08:14.366] INFO: PixTest:: pg_setup set to default.
[13:08:14.380] INFO: enter test to run
[13:08:36.425] INFO: test: HighRate no parameter change
[13:08:36.425] INFO: running: highrate
[13:08:36.426] INFO: ----------------------------------------------------------------------
[13:08:36.426] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:36.426] INFO: ----------------------------------------------------------------------
[13:08:37.040] INFO: Expecting 208000 events.
[13:08:50.107] INFO: 208000 events read in total (12540ms).
[13:08:50.112] INFO: Test took 13677ms.
[13:08:50.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:50.648] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 1 1 0 0 105 0 0 0 0
[13:08:50.648] INFO: number of red-efficiency pixels: 825 124 228 369 390 314 388 230 168 249 247 428 260 136 33 51
[13:08:50.648] INFO: number of X-ray hits detected: 121641 77756 125258 184519 193536 197872 198228 146807 130920 172689 172740 145520 153695 95406 40734 48882
[13:08:50.649] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:08:50.649] INFO: number of Vcal hits detected: 207126 207872 207647 207611 207585 207659 207586 207711 207775 207740 207735 199784 207725 207864 207967 207949
[13:08:50.649] INFO: Vcal hit fiducial efficiency (%): 99.6 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 98.5 99.9 99.9 100.0 100.0
[13:08:50.649] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 96.0 99.9 99.9 100.0 100.0
[13:08:50.649] INFO: X-ray hit rate [MHz/cm2]: 35.7 22.8 36.7 54.1 56.7 58.0 58.1 43.0 38.4 50.6 50.6 42.7 45.0 28.0 11.9 14.3
[13:08:50.649] INFO: PixTestHighRate::doXPixelAlive() done
[13:08:50.693] INFO: PixTest:: pg_setup set to default.
[13:08:50.707] INFO: enter test to run
[13:09:07.137] INFO: test: HighRate no parameter change
[13:09:07.137] INFO: running: highrate
[13:09:07.138] INFO: ----------------------------------------------------------------------
[13:09:07.138] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:09:07.138] INFO: ----------------------------------------------------------------------
[13:09:07.751] INFO: Expecting 208000 events.
[13:09:22.621] INFO: 208000 events read in total (14343ms).
[13:09:22.628] INFO: Test took 15481ms.
[13:09:23.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:23.358] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 0 1 1 0 0 122 0 0 0 0
[13:09:23.358] INFO: number of red-efficiency pixels: 631 258 612 915 1049 814 959 505 400 605 603 768 590 318 74 110
[13:09:23.358] INFO: number of X-ray hits detected: 192074 124328 198161 293161 306387 312124 312609 232960 207505 274699 273594 229408 242759 152093 65331 77996
[13:09:23.358] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:09:23.358] INFO: number of Vcal hits detected: 207274 207710 207115 206901 206689 207024 206833 207352 207515 207323 207309 199339 207331 207630 207924 207889
[13:09:23.358] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.5 99.4 99.6 99.5 99.7 99.8 99.7 99.7 98.7 99.7 99.8 100.0 99.9
[13:09:23.358] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.4 99.5 99.4 99.7 99.8 99.7 99.7 95.8 99.7 99.8 100.0 99.9
[13:09:23.358] INFO: X-ray hit rate [MHz/cm2]: 56.3 36.4 58.1 85.9 89.8 91.5 91.6 68.3 60.8 80.5 80.2 67.2 71.2 44.6 19.1 22.9
[13:09:23.358] INFO: PixTestHighRate::doXPixelAlive() done
[13:09:23.408] INFO: PixTest:: pg_setup set to default.
[13:09:23.421] INFO: enter test to run
[13:09:25.697] INFO: test: exit no parameter change
[13:09:26.188] QUIET: Connection to board 33 closed.
[13:09:26.201] INFO: pXar: this is the end, my friend