[15:51:42.779] INFO: *** Welcome to pxar ***
[15:51:42.779] INFO: *** Today: 2016/10/07
[15:51:42.800] INFO: *** Version: v1.9.0-818-g96727
[15:51:42.800] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//dacParameters35_C15.dat
[15:51:42.801] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:51:42.801] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//defaultMaskFile.dat
[15:51:42.801] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C15.dat
[15:51:42.877] INFO: clk: 4
[15:51:42.877] INFO: ctr: 4
[15:51:42.877] INFO: sda: 19
[15:51:42.877] INFO: tin: 9
[15:51:42.877] INFO: level: 15
[15:51:42.877] INFO: triggerdelay: 0
[15:51:42.877] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:51:42.877] INFO: Log level: INFO
[15:51:42.894] QUIET: Connection to board DTB_WREKRL opened.
[15:51:42.897] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[15:51:42.900] INFO: RPC call hashes of host and DTB match: 398089610
[15:51:44.439] INFO: DUT info:
[15:51:44.439] INFO: The DUT currently contains the following objects:
[15:51:44.439] INFO: 2 TBM Cores tbm08c (2 ON)
[15:51:44.439] INFO: TBM Core alpha (0): 7 registers set
[15:51:44.439] INFO: TBM Core beta (1): 7 registers set
[15:51:44.439] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:51:44.439] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.439] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.439] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.439] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.439] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.439] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.440] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:44.843] INFO: enter 'restricted' command line mode
[15:51:44.843] INFO: enter test to run
[15:51:56.325] INFO: test: PixelAlive no parameter change
[15:51:56.325] INFO: running: pixelalive
[15:51:56.590] INFO: ----------------------------------------------------------------------
[15:51:56.590] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:51:56.590] INFO: ----------------------------------------------------------------------
[15:51:56.915] INFO: Expecting 41600 events.
[15:52:01.204] INFO: 41600 events read in total (3571ms).
[15:52:01.371] INFO: Test took 4770ms.
[15:52:01.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:01.800] INFO: PixTestAlive::aliveTest() done
[15:52:01.800] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[15:52:01.908] INFO: enter test to run
[15:52:52.685] INFO: test: timing no parameter change
[15:52:52.685] INFO: running: timing
[15:52:52.688] INFO: ######################################################################
[15:52:52.688] INFO: PixTestTiming::doTest()
[15:52:52.688] INFO: ######################################################################
[15:52:52.688] INFO: ----------------------------------------------------------------------
[15:52:52.688] INFO: PixTestTiming::TBMPhaseScan()
[15:52:52.688] INFO: ----------------------------------------------------------------------
[15:57:43.550] INFO: TBM Phase Settings: 236
[15:57:43.550] INFO: 400MHz Phase: 3
[15:57:43.550] INFO: 160MHz Phase: 7
[15:57:43.550] INFO: Functional Phase Area: 4
[15:57:43.577] INFO: Test took 290889 ms.
[15:57:43.577] INFO: PixTestTiming::TBMPhaseScan() done.
[15:57:43.577] INFO: ----------------------------------------------------------------------
[15:57:43.577] INFO: PixTestTiming::ROCDelayScan()
[15:57:43.577] INFO: ----------------------------------------------------------------------
[16:00:11.035] INFO: ROC Delay Settings: 228
[16:00:11.035] INFO: ROC Header-Trailer/Token Delay: 11
[16:00:11.035] INFO: ROC Port 0 Delay: 4
[16:00:11.035] INFO: ROC Port 1 Delay: 4
[16:00:11.035] INFO: Functional ROC Area: 5
[16:00:11.038] INFO: Test took 147461 ms.
[16:00:11.038] INFO: PixTestTiming::ROCDelayScan() done.
[16:00:11.038] INFO: ----------------------------------------------------------------------
[16:00:11.038] INFO: PixTestTiming::TimingTest()
[16:00:11.038] INFO: ----------------------------------------------------------------------
[16:00:27.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:42.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:57.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:12.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:27.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:41.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:56.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:11.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:26.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:41.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:41.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: Read back bit status: 1
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: Timings are good!
[16:02:41.796] INFO: ----------------------------------------------------------------------
[16:02:41.796] INFO: Test took 150758 ms.
[16:02:41.796] INFO: PixTestTiming::TimingTest() done.
[16:02:41.797] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:02:41.797] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:02:41.797] INFO: PixTestTiming::doTest took 589112 ms.
[16:02:41.797] INFO: PixTestTiming::doTest() done
[16:02:41.797] INFO: Write out TBMPhaseScan_0_V0
[16:02:41.797] INFO: Write out TBMPhaseScan_1_V0
[16:02:41.797] INFO: Write out CombinedTBMPhaseScan_V0
[16:02:41.849] INFO: Write out ROCDelayScan3_V0
[16:02:41.850] INFO: enter test to run
[16:04:29.488] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:04:29.488] INFO: running: highrate
[16:04:29.507] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:04:29.806] INFO: ----------------------------------------------------------------------
[16:04:29.806] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:04:29.806] INFO: ----------------------------------------------------------------------
[16:04:29.806] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:04:29.806] INFO: edge/corner pixel THR is adjusted
[16:04:29.806] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:04:30.764] INFO: Collecting data for 5 seconds...
[16:04:35.781] INFO: Done with hot pixel readout
[16:04:47.443] INFO: PixTest:: pg_setup set to default.
[16:04:47.443] INFO: 22 hot pixels found in step 0
[16:04:48.437] INFO: Collecting data for 5 seconds...
[16:04:53.454] INFO: Done with hot pixel readout
[16:05:05.160] INFO: PixTest:: pg_setup set to default.
[16:05:05.160] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:05:05.161] INFO: 27 hot pixels found in step 1
[16:05:06.155] INFO: Collecting data for 5 seconds...
[16:05:11.173] INFO: Done with hot pixel readout
[16:05:22.957] INFO: PixTest:: pg_setup set to default.
[16:05:22.958] INFO: 26 hot pixels found in step 2
[16:05:23.952] INFO: Collecting data for 5 seconds...
[16:05:28.969] INFO: Done with hot pixel readout
[16:05:40.727] INFO: PixTest:: pg_setup set to default.
[16:05:40.728] INFO: 24 hot pixels found in step 3
[16:05:41.723] INFO: Collecting data for 5 seconds...
[16:05:46.740] INFO: Done with hot pixel readout
[16:05:58.528] INFO: PixTest:: pg_setup set to default.
[16:05:58.529] INFO: 22 hot pixels found in step 4
[16:05:59.523] INFO: Collecting data for 5 seconds...
[16:06:04.539] INFO: Done with hot pixel readout
[16:06:16.298] INFO: PixTest:: pg_setup set to default.
[16:06:16.299] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:06:16.299] INFO: 16 hot pixels found in step 5
[16:06:17.293] INFO: Collecting data for 5 seconds...
[16:06:22.311] INFO: Done with hot pixel readout
[16:06:34.068] INFO: PixTest:: pg_setup set to default.
[16:06:34.068] INFO: 26 hot pixels found in step 6
[16:06:35.063] INFO: Collecting data for 5 seconds...
[16:06:40.080] INFO: Done with hot pixel readout
[16:06:51.843] INFO: PixTest:: pg_setup set to default.
[16:06:51.844] INFO: 24 hot pixels found in step 7
[16:06:52.838] INFO: Collecting data for 5 seconds...
[16:06:57.856] INFO: Done with hot pixel readout
[16:07:09.614] INFO: PixTest:: pg_setup set to default.
[16:07:09.615] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:09.615] INFO: 22 hot pixels found in step 8
[16:07:10.609] INFO: Collecting data for 5 seconds...
[16:07:15.626] INFO: Done with hot pixel readout
[16:07:27.330] INFO: PixTest:: pg_setup set to default.
[16:07:27.330] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:27.330] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:27.331] INFO: 20 hot pixels found in step 9
[16:07:28.331] INFO: Collecting data for 5 seconds...
[16:07:33.349] INFO: Done with hot pixel readout
[16:07:45.383] INFO: PixTest:: pg_setup set to default.
[16:07:45.383] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:45.384] INFO: 15 hot pixels found in step 10
[16:07:46.378] INFO: Collecting data for 5 seconds...
[16:07:51.397] INFO: Done with hot pixel readout
[16:08:03.251] INFO: PixTest:: pg_setup set to default.
[16:08:03.252] INFO: 18 hot pixels found in step 11
[16:08:04.249] INFO: Collecting data for 5 seconds...
[16:08:09.267] INFO: Done with hot pixel readout
[16:08:21.233] INFO: PixTest:: pg_setup set to default.
[16:08:21.233] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:08:21.234] INFO: 13 hot pixels found in step 12
[16:08:22.229] INFO: Collecting data for 5 seconds...
[16:08:27.248] INFO: Done with hot pixel readout
[16:08:39.138] INFO: PixTest:: pg_setup set to default.
[16:08:39.138] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:08:39.139] INFO: 15 hot pixels found in step 13
[16:08:40.134] INFO: Collecting data for 5 seconds...
[16:08:45.152] INFO: Done with hot pixel readout
[16:08:56.994] INFO: PixTest:: pg_setup set to default.
[16:08:56.994] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:08:56.995] INFO: 11 hot pixels found in step 14
[16:08:57.035] INFO: 11 hot pixels could not be trimmed and have been masked.
[16:08:57.038] INFO: PixTest::trimHotPixels() done
[16:08:57.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C0.dat
[16:08:57.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C1.dat
[16:08:57.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C2.dat
[16:08:57.056] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C3.dat
[16:08:57.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C4.dat
[16:08:57.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C5.dat
[16:08:57.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C6.dat
[16:08:57.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C7.dat
[16:08:57.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C8.dat
[16:08:57.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C9.dat
[16:08:57.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C10.dat
[16:08:57.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C11.dat
[16:08:57.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C12.dat
[16:08:57.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C13.dat
[16:08:57.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C14.dat
[16:08:57.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C15.dat
[16:08:57.125] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//defaultMaskFile.dat
[16:08:57.136] INFO: enter test to run
[16:09:33.302] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:09:33.302] INFO: running: highrate
[16:09:33.307] INFO: ----------------------------------------------------------------------
[16:09:33.307] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:09:33.307] INFO: ----------------------------------------------------------------------
[16:09:33.307] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:09:33.307] INFO: edge/corner pixel THR is adjusted
[16:09:33.307] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:09:34.263] INFO: Collecting data for 1 seconds...
[16:09:35.267] INFO: Done with hot pixel readout
[16:09:39.148] INFO: PixTest:: pg_setup set to default.
[16:09:39.149] INFO: 0 hot pixels found in step 0
[16:09:39.154] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:09:39.236] INFO: PixTest::trimHotPixels() done
[16:09:39.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C0.dat
[16:09:39.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C1.dat
[16:09:39.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C2.dat
[16:09:39.256] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C3.dat
[16:09:39.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C4.dat
[16:09:39.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C5.dat
[16:09:39.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C6.dat
[16:09:39.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C7.dat
[16:09:39.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C8.dat
[16:09:39.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C9.dat
[16:09:39.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C10.dat
[16:09:39.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C11.dat
[16:09:39.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C12.dat
[16:09:39.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C13.dat
[16:09:39.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C14.dat
[16:09:39.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//trimParameters35_C15.dat
[16:09:39.326] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-35_FPIXTest-17C-FNAL-160929-0938-150V_2016-09-29_09h38m_1475159936/000_FPIXTest_p17//defaultMaskFile.dat
[16:09:39.338] INFO: enter test to run
[16:09:57.878] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:09:57.878] INFO: running: xray
[16:09:57.879] INFO: ----------------------------------------------------------------------
[16:09:57.879] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:09:57.879] INFO: ----------------------------------------------------------------------
[16:09:58.853] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:10:10.122] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:10:40.011] INFO: Resuming triggers.
[16:10:51.288] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:11:21.039] INFO: Resuming triggers.
[16:11:32.316] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:12:02.479] INFO: Resuming triggers.
[16:12:13.752] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:12:44.411] INFO: Resuming triggers.
[16:12:55.685] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:13:26.615] INFO: Resuming triggers.
[16:13:37.893] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:14:08.440] INFO: Resuming triggers.
[16:14:19.714] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:14:49.576] INFO: Resuming triggers.
[16:15:00.853] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:15:30.369] INFO: Resuming triggers.
[16:15:40.535] INFO: data taking finished, elapsed time: 100 seconds.
[16:16:07.368] INFO: PixTest:: pg_setup set to default.
[16:16:07.371] INFO: PixTestXray::doPhRun() done
[16:16:07.577] INFO: enter test to run
[16:17:01.107] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:17:01.107] INFO: running: xray
[16:17:01.108] INFO: ----------------------------------------------------------------------
[16:17:01.108] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:17:01.108] INFO: ----------------------------------------------------------------------
[16:17:02.072] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:17:08.651] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:17:38.802] INFO: Resuming triggers.
[16:17:45.389] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:18:15.612] INFO: Resuming triggers.
[16:18:22.197] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:18:52.419] INFO: Resuming triggers.
[16:18:58.005] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:19:29.341] INFO: Resuming triggers.
[16:19:35.928] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:20:06.182] INFO: Resuming triggers.
[16:20:12.765] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[16:20:43.085] INFO: Resuming triggers.
[16:20:49.671] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:21:19.785] INFO: Resuming triggers.
[16:21:26.374] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:21:56.733] INFO: Resuming triggers.
[16:22:03.322] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:22:34.256] INFO: Resuming triggers.
[16:22:40.842] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[16:23:11.967] INFO: Resuming triggers.
[16:23:18.552] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:23:49.435] INFO: Resuming triggers.
[16:23:56.020] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:24:26.635] INFO: Resuming triggers.
[16:24:33.219] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:25:03.985] INFO: Resuming triggers.
[16:25:10.569] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:25:41.343] INFO: Resuming triggers.
[16:25:47.926] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[16:26:18.892] INFO: Resuming triggers.
[16:26:20.461] INFO: data taking finished, elapsed time: 100 seconds.
[16:26:28.204] INFO: PixTest:: pg_setup set to default.
[16:26:28.207] INFO: PixTestXray::doPhRun() done
[16:26:28.363] INFO: enter test to run
[16:28:15.631] INFO: test: HighRate no parameter change
[16:28:15.631] INFO: running: highrate
[16:28:15.652] INFO: ----------------------------------------------------------------------
[16:28:15.652] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:28:15.652] INFO: ----------------------------------------------------------------------
[16:28:15.835] INFO: Expecting 768 events.
[16:28:16.987] INFO: 768 events read in total (436ms).
[16:28:16.987] INFO: Test took 1298ms.
[16:28:17.790] INFO: Expecting 41600 events.
[16:28:21.007] INFO: 41600 events read in total (2691ms).
[16:28:21.008] INFO: Test took 4014ms.
[16:28:21.043] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:21.762] INFO: Expecting 41600 events.
[16:28:24.997] INFO: 41600 events read in total (2708ms).
[16:28:24.998] INFO: Test took 3937ms.
[16:28:25.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:25.754] INFO: Expecting 41600 events.
[16:28:28.004] INFO: 41600 events read in total (2724ms).
[16:28:28.005] INFO: Test took 3951ms.
[16:28:29.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:29.758] INFO: Expecting 41600 events.
[16:28:33.027] INFO: 41600 events read in total (2742ms).
[16:28:33.028] INFO: Test took 3969ms.
[16:28:33.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:33.776] INFO: Expecting 41600 events.
[16:28:36.000] INFO: 41600 events read in total (2697ms).
[16:28:36.001] INFO: Test took 3912ms.
[16:28:37.037] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:37.758] INFO: Expecting 41600 events.
[16:28:41.029] INFO: 41600 events read in total (2744ms).
[16:28:41.030] INFO: Test took 3976ms.
[16:28:41.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:41.787] INFO: Expecting 41600 events.
[16:28:45.033] INFO: 41600 events read in total (2719ms).
[16:28:45.034] INFO: Test took 3949ms.
[16:28:45.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:45.786] INFO: Expecting 41600 events.
[16:28:49.127] INFO: 41600 events read in total (2814ms).
[16:28:49.128] INFO: Test took 4041ms.
[16:28:49.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:49.879] INFO: Expecting 41600 events.
[16:28:53.104] INFO: 41600 events read in total (2698ms).
[16:28:53.105] INFO: Test took 3923ms.
[16:28:53.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:53.864] INFO: Expecting 41600 events.
[16:28:57.111] INFO: 41600 events read in total (2720ms).
[16:28:57.111] INFO: Test took 3954ms.
[16:28:57.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:57.868] INFO: Expecting 41600 events.
[16:29:01.119] INFO: 41600 events read in total (2724ms).
[16:29:01.120] INFO: Test took 3956ms.
[16:29:01.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:01.879] INFO: Expecting 41600 events.
[16:29:05.136] INFO: 41600 events read in total (2730ms).
[16:29:05.137] INFO: Test took 3963ms.
[16:29:05.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:05.892] INFO: Expecting 41600 events.
[16:29:09.135] INFO: 41600 events read in total (2717ms).
[16:29:09.136] INFO: Test took 3946ms.
[16:29:09.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:09.894] INFO: Expecting 41600 events.
[16:29:13.139] INFO: 41600 events read in total (2718ms).
[16:29:13.140] INFO: Test took 3950ms.
[16:29:13.175] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:13.895] INFO: Expecting 41600 events.
[16:29:17.158] INFO: 41600 events read in total (2736ms).
[16:29:17.159] INFO: Test took 3967ms.
[16:29:17.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:17.913] INFO: Expecting 41600 events.
[16:29:21.158] INFO: 41600 events read in total (2718ms).
[16:29:21.159] INFO: Test took 3946ms.
[16:29:21.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:21.918] INFO: Expecting 41600 events.
[16:29:25.175] INFO: 41600 events read in total (2730ms).
[16:29:25.176] INFO: Test took 3962ms.
[16:29:25.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:25.931] INFO: Expecting 41600 events.
[16:29:29.183] INFO: 41600 events read in total (2725ms).
[16:29:29.184] INFO: Test took 3953ms.
[16:29:29.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:29.939] INFO: Expecting 41600 events.
[16:29:33.144] INFO: 41600 events read in total (2678ms).
[16:29:33.145] INFO: Test took 3908ms.
[16:29:33.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:33.903] INFO: Expecting 41600 events.
[16:29:36.955] INFO: 41600 events read in total (2525ms).
[16:29:36.955] INFO: Test took 3756ms.
[16:29:36.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:37.354] INFO: enter test to run
[16:29:52.814] INFO: test: HighRate no parameter change
[16:29:52.814] INFO: running: highrate
[16:29:52.815] INFO: ----------------------------------------------------------------------
[16:29:52.815] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:29:52.815] INFO: ----------------------------------------------------------------------
[16:29:53.431] INFO: Expecting 208000 events.
[16:30:05.382] INFO: 208000 events read in total (11424ms).
[16:30:05.385] INFO: Test took 12559ms.
[16:30:05.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:05.787] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[16:30:05.787] INFO: number of red-efficiency pixels: 91 47 95 151 134 179 138 94 87 100 118 92 126 59 22 17
[16:30:05.787] INFO: number of X-ray hits detected: 70137 44933 69119 110665 115677 124366 118889 82812 76808 100834 103613 86403 87769 53274 21320 23224
[16:30:05.787] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:30:05.787] INFO: number of Vcal hits detected: 207908 207952 207903 207795 207861 207813 207857 207901 207910 207899 207879 207905 207872 207940 207978 207983
[16:30:05.787] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0
[16:30:05.787] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0
[16:30:05.787] INFO: X-ray hit rate [MHz/cm2]: 20.6 13.2 20.3 32.4 33.9 36.5 34.8 24.3 22.5 29.6 30.4 25.3 25.7 15.6 6.2 6.8
[16:30:05.787] INFO: PixTestHighRate::doXPixelAlive() done
[16:30:05.836] INFO: PixTest:: pg_setup set to default.
[16:30:05.850] INFO: enter test to run
[16:30:47.381] INFO: test: HighRate no parameter change
[16:30:47.381] INFO: running: highrate
[16:30:47.383] INFO: ----------------------------------------------------------------------
[16:30:47.383] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:30:47.383] INFO: ----------------------------------------------------------------------
[16:30:47.003] INFO: Expecting 208000 events.
[16:31:01.708] INFO: 208000 events read in total (13178ms).
[16:31:01.714] INFO: Test took 14322ms.
[16:31:02.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:02.324] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[16:31:02.324] INFO: number of red-efficiency pixels: 284 125 278 544 421 691 468 323 246 430 457 333 344 174 55 41
[16:31:02.324] INFO: number of X-ray hits detected: 143772 93234 143524 228803 238477 256588 246184 172487 158442 209820 214503 180246 182377 111041 44235 48735
[16:31:02.324] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:31:02.324] INFO: number of Vcal hits detected: 207689 207869 207684 207344 207554 207213 207470 207637 207745 207543 207515 207643 207636 207812 207945 207959
[16:31:02.324] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:31:02.324] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:31:02.324] INFO: X-ray hit rate [MHz/cm2]: 42.1 27.3 42.1 67.1 69.9 75.2 72.2 50.6 46.4 61.5 62.9 52.8 53.5 32.5 13.0 14.3
[16:31:02.324] INFO: PixTestHighRate::doXPixelAlive() done
[16:31:02.370] INFO: PixTest:: pg_setup set to default.
[16:31:02.383] INFO: enter test to run
[16:31:26.541] INFO: test: HighRate no parameter change
[16:31:26.541] INFO: running: highrate
[16:31:26.542] INFO: ----------------------------------------------------------------------
[16:31:26.542] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:31:26.542] INFO: ----------------------------------------------------------------------
[16:31:27.154] INFO: Expecting 208000 events.
[16:31:42.756] INFO: 208000 events read in total (15075ms).
[16:31:42.764] INFO: Test took 16213ms.
[16:31:43.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:43.579] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[16:31:43.579] INFO: number of red-efficiency pixels: 597 248 657 1268 936 1676 1141 640 441 1014 1162 794 771 362 91 86
[16:31:43.579] INFO: number of X-ray hits detected: 215357 139763 214950 343467 357299 384372 370307 258024 237991 314333 320890 269692 272229 166531 66013 73152
[16:31:43.579] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:31:43.579] INFO: number of Vcal hits detected: 207223 207726 207089 206309 206852 205597 206525 207186 207494 206796 206514 207071 207099 207586 207907 207910
[16:31:43.580] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.3 99.5 99.0 99.4 99.6 99.8 99.5 99.3 99.6 99.6 99.8 100.0 100.0
[16:31:43.580] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.6 99.2 99.4 98.8 99.3 99.6 99.8 99.4 99.3 99.6 99.6 99.8 100.0 100.0
[16:31:43.580] INFO: X-ray hit rate [MHz/cm2]: 63.1 41.0 63.0 100.7 104.7 112.7 108.5 75.6 69.8 92.1 94.1 79.0 79.8 48.8 19.3 21.4
[16:31:43.580] INFO: PixTestHighRate::doXPixelAlive() done
[16:31:43.630] INFO: PixTest:: pg_setup set to default.
[16:31:43.649] INFO: enter test to run
[16:31:47.397] INFO: test: exit no parameter change
[16:31:47.810] QUIET: Connection to board 33 closed.
[16:31:47.823] INFO: pXar: this is the end, my friend