[16:18:08.847] INFO: *** Welcome to pxar ***
[16:18:08.847] INFO: *** Today: 2016/04/15
[16:18:08.927] INFO: *** Version: v1.9.0-796-gef167-dirty
[16:18:08.927] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//dacParameters35_C15.dat
[16:18:08.927] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:18:08.928] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//defaultMaskFile.dat
[16:18:08.928] INFO: MASKED Roc 8 col/row: 48 65
[16:18:08.928] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C15.dat
[16:18:08.961] INFO: masking Roc 8 col/row: 48 65
[16:18:08.994] INFO: clk: 4
[16:18:08.994] INFO: ctr: 4
[16:18:08.994] INFO: sda: 19
[16:18:08.994] INFO: tin: 9
[16:18:08.994] INFO: level: 15
[16:18:08.994] INFO: triggerdelay: 0
[16:18:08.995] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:18:08.995] INFO: Log level: INFO
[16:18:09.013] QUIET: Connection to board DTB_WREKRL opened.
[16:18:09.016] 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:
------------------------------------------------------
[16:18:09.019] INFO: RPC call hashes of host and DTB match: 398089610
[16:18:10.552] INFO: DUT info:
[16:18:10.552] INFO: The DUT currently contains the following objects:
[16:18:10.552] INFO: 2 TBM Cores tbm08c (2 ON)
[16:18:10.552] INFO: TBM Core alpha (0): 7 registers set
[16:18:10.552] INFO: TBM Core beta (1): 7 registers set
[16:18:10.552] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:18:10.552] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 8: 19 DACs set, Pixels: 1 masked, 0 active.
[16:18:10.552] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.552] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:18:10.955] INFO: enter 'restricted' command line mode
[16:18:10.955] INFO: enter test to run
[16:18:22.224] INFO: test: PixelAlive no parameter change
[16:18:22.224] INFO: running: pixelalive
[16:18:22.234] INFO: ----------------------------------------------------------------------
[16:18:22.234] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:18:22.234] INFO: ----------------------------------------------------------------------
[16:18:22.236] INFO: ROC 8 masking pixel 48/65
[16:18:22.554] INFO: Expecting 41600 events.
[16:18:26.887] INFO: 41600 events read in total (3615ms).
[16:18:27.056] INFO: Test took 4820ms.
[16:18:27.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:27.331] INFO: PixTestAlive::aliveTest() done with 140 decoding errors
[16:18:27.331] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 147 0 0 0 0 0 0 0
[16:18:27.331] INFO: ROC 8 masking pixel 48/65
[16:18:27.363] INFO: enter test to run
[16:18:40.056] INFO: test: timing no parameter change
[16:18:40.056] INFO: running: timing
[16:18:40.059] INFO: ######################################################################
[16:18:40.059] INFO: PixTestTiming::doTest()
[16:18:40.059] INFO: ######################################################################
[16:18:40.059] INFO: ----------------------------------------------------------------------
[16:18:40.059] INFO: PixTestTiming::TBMPhaseScan()
[16:18:40.059] INFO: ----------------------------------------------------------------------
[16:25:59.022] INFO: TBM Phase Settings: 240
[16:25:59.022] INFO: 400MHz Phase: 4
[16:25:59.022] INFO: 160MHz Phase: 7
[16:25:59.022] INFO: Functional Phase Area: 5
[16:25:59.031] INFO: Test took 438972 ms.
[16:25:59.031] INFO: PixTestTiming::TBMPhaseScan() done.
[16:25:59.032] INFO: ROC 8 masking pixel 48/65
[16:25:59.032] INFO: ----------------------------------------------------------------------
[16:25:59.032] INFO: PixTestTiming::ROCDelayScan()
[16:25:59.032] INFO: ----------------------------------------------------------------------
[16:28:34.475] INFO: ROC Delay Settings: 228
[16:28:34.475] INFO: ROC Header-Trailer/Token Delay: 11
[16:28:34.475] INFO: ROC Port 0 Delay: 4
[16:28:34.475] INFO: ROC Port 1 Delay: 4
[16:28:34.475] INFO: Functional ROC Area: 4
[16:28:34.479] INFO: Test took 155447 ms.
[16:28:34.479] INFO: PixTestTiming::ROCDelayScan() done.
[16:28:34.479] INFO: ROC 8 masking pixel 48/65
[16:28:34.479] INFO: ----------------------------------------------------------------------
[16:28:34.479] INFO: PixTestTiming::TimingTest()
[16:28:34.479] INFO: ----------------------------------------------------------------------
[16:28:49.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:04.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:19.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:34.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:49.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:04.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:19.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:34.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:49.009] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:04.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:04.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: Read back bit status: 1
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: Timings are good!
[16:31:04.436] INFO: ----------------------------------------------------------------------
[16:31:04.436] INFO: Test took 149957 ms.
[16:31:04.436] INFO: PixTestTiming::TimingTest() done.
[16:31:04.436] INFO: ROC 8 masking pixel 48/65
[16:31:04.447] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:31:04.447] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:31:04.447] INFO: PixTestTiming::doTest took 744391 ms.
[16:31:04.447] INFO: PixTestTiming::doTest() done
[16:31:04.447] INFO: ROC 8 masking pixel 48/65
[16:31:04.447] INFO: Write out TBMPhaseScan_0_V0
[16:31:04.447] INFO: Write out TBMPhaseScan_1_V0
[16:31:04.448] INFO: Write out CombinedTBMPhaseScan_V0
[16:31:04.460] INFO: Write out ROCDelayScan3_V0
[16:31:04.461] INFO: enter test to run
[16:31:53.410] INFO: test: PixelAlive no parameter change
[16:31:53.410] INFO: running: pixelalive
[16:31:53.415] INFO: ----------------------------------------------------------------------
[16:31:53.415] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:31:53.415] INFO: ----------------------------------------------------------------------
[16:31:53.419] INFO: ROC 8 masking pixel 48/65
[16:31:53.734] INFO: Expecting 41600 events.
[16:31:58.050] INFO: 41600 events read in total (3600ms).
[16:31:58.051] INFO: Test took 4632ms.
[16:31:58.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:58.456] INFO: PixTestAlive::aliveTest() done with 165 decoding errors
[16:31:58.456] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 146 0 0 0 0 0 0 0
[16:31:58.456] INFO: ROC 8 masking pixel 48/65
[16:31:58.460] INFO: enter test to run
[16:32:30.666] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:32:30.666] INFO: running: highrate
[16:32:30.667] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:32:30.819] INFO: ----------------------------------------------------------------------
[16:32:30.819] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:32:30.819] INFO: ----------------------------------------------------------------------
[16:32:30.819] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:32:30.819] INFO: edge/corner pixel THR is adjusted
[16:32:30.819] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:32:31.777] INFO: Collecting data for 5 seconds...
[16:32:36.794] INFO: Done with hot pixel readout
[16:32:48.249] INFO: PixTest:: pg_setup set to default.
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:32:48.250] INFO: 14 hot pixels found in step 0
[16:32:49.241] INFO: Collecting data for 5 seconds...
[16:32:54.259] INFO: Done with hot pixel readout
[16:33:05.811] INFO: PixTest:: pg_setup set to default.
[16:33:05.811] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:05.812] INFO: 10 hot pixels found in step 1
[16:33:05.848] INFO: 10 hot pixels could not be trimmed and have been masked.
[16:33:05.852] INFO: PixTest::trimHotPixels() done
[16:33:05.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C0.dat
[16:33:05.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C1.dat
[16:33:05.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C2.dat
[16:33:05.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C3.dat
[16:33:05.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C4.dat
[16:33:05.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C5.dat
[16:33:05.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C6.dat
[16:33:05.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C7.dat
[16:33:05.896] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C8.dat
[16:33:05.902] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C9.dat
[16:33:05.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C10.dat
[16:33:05.912] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C11.dat
[16:33:05.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C12.dat
[16:33:05.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C13.dat
[16:33:05.929] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C14.dat
[16:33:05.934] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C15.dat
[16:33:05.940] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//defaultMaskFile.dat
[16:33:05.950] INFO: enter test to run
[16:33:24.346] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:33:24.346] INFO: running: highrate
[16:33:24.350] INFO: ----------------------------------------------------------------------
[16:33:24.350] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:33:24.350] INFO: ----------------------------------------------------------------------
[16:33:24.350] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:33:24.350] INFO: edge/corner pixel THR is adjusted
[16:33:24.350] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:33:25.308] INFO: Collecting data for 1 seconds...
[16:33:26.311] INFO: Done with hot pixel readout
[16:33:28.957] INFO: PixTest:: pg_setup set to default.
[16:33:28.958] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:28.958] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:33:28.958] INFO: 2 hot pixels found in step 0
[16:33:28.963] INFO: 2 hot pixels could not be trimmed and have been masked.
[16:33:29.109] INFO: PixTest::trimHotPixels() done
[16:33:29.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C0.dat
[16:33:29.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C1.dat
[16:33:29.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C2.dat
[16:33:29.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C3.dat
[16:33:29.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C4.dat
[16:33:29.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C5.dat
[16:33:29.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C6.dat
[16:33:29.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C7.dat
[16:33:29.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C8.dat
[16:33:29.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C9.dat
[16:33:29.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C10.dat
[16:33:29.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C11.dat
[16:33:29.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C12.dat
[16:33:29.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C13.dat
[16:33:29.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C14.dat
[16:33:29.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//trimParameters35_C15.dat
[16:33:29.199] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-48_FPIXTest-17C-Nebraska-160330-1423_2016-03-30_14h24m_1459365847/000_FPIXTest_p17//defaultMaskFile.dat
[16:33:29.208] INFO: enter test to run
[16:33:35.866] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:33:35.866] INFO: running: xray
[16:33:35.867] INFO: ----------------------------------------------------------------------
[16:33:35.867] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:33:35.867] INFO: ----------------------------------------------------------------------
[16:33:35.870] INFO: ROC 8 masking pixel 48/65
[16:33:36.831] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:33:48.373] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:34:17.510] INFO: Resuming triggers.
[16:34:29.051] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:34:57.600] INFO: Resuming triggers.
[16:35:09.140] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:35:38.381] INFO: Resuming triggers.
[16:35:49.927] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:36:19.160] INFO: Resuming triggers.
[16:36:30.704] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:36:58.713] INFO: Resuming triggers.
[16:37:10.259] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:37:39.642] INFO: Resuming triggers.
[16:37:51.187] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:38:20.462] INFO: Resuming triggers.
[16:38:31.999] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[16:38:59.486] INFO: Resuming triggers.
[16:39:07.464] INFO: data taking finished, elapsed time: 100 seconds.
[16:39:26.830] INFO: PixTest:: pg_setup set to default.
[16:39:26.833] INFO: PixTestXray::doPhRun() done
[16:39:26.973] INFO: enter test to run
[16:40:47.750] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:40:47.751] INFO: running: xray
[16:40:47.751] INFO: ----------------------------------------------------------------------
[16:40:47.751] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:40:47.751] INFO: ----------------------------------------------------------------------
[16:40:47.755] INFO: ROC 8 masking pixel 48/65
[16:40:48.715] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:40:55.423] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:41:25.562] INFO: Resuming triggers.
[16:41:32.272] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:42:02.582] INFO: Resuming triggers.
[16:42:09.290] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:42:39.508] INFO: Resuming triggers.
[16:42:46.217] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:43:16.706] INFO: Resuming triggers.
[16:43:23.411] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:43:53.829] INFO: Resuming triggers.
[16:44:00.538] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:44:29.436] INFO: Resuming triggers.
[16:44:36.144] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:45:07.036] INFO: Resuming triggers.
[16:45:13.746] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:45:42.165] INFO: Resuming triggers.
[16:45:48.873] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:46:17.910] INFO: Resuming triggers.
[16:46:24.617] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:46:54.496] INFO: Resuming triggers.
[16:47:01.208] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:47:31.498] INFO: Resuming triggers.
[16:47:38.206] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:48:08.296] INFO: Resuming triggers.
[16:48:15.002] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[16:48:45.242] INFO: Resuming triggers.
[16:48:51.948] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:49:17.467] INFO: Resuming triggers.
[16:49:23.884] INFO: data taking finished, elapsed time: 100 seconds.
[16:49:52.699] INFO: PixTest:: pg_setup set to default.
[16:49:52.703] INFO: PixTestXray::doPhRun() done
[16:49:52.852] INFO: enter test to run
[16:50:03.890] INFO: test: HighRate no parameter change
[16:50:03.891] INFO: running: highrate
[16:50:03.911] INFO: ----------------------------------------------------------------------
[16:50:03.911] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:50:03.911] INFO: ----------------------------------------------------------------------
[16:50:04.067] INFO: Expecting 768 events.
[16:50:05.201] INFO: 768 events read in total (419ms).
[16:50:05.201] INFO: Test took 1269ms.
[16:50:05.205] INFO: ROC 8 masking pixel 48/65
[16:50:06.004] INFO: Expecting 41600 events.
[16:50:09.176] INFO: 41600 events read in total (2645ms).
[16:50:09.177] INFO: Test took 3969ms.
[16:50:09.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:09.930] INFO: Expecting 41600 events.
[16:50:13.226] INFO: 41600 events read in total (2770ms).
[16:50:13.227] INFO: Test took 3987ms.
[16:50:13.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:13.981] INFO: Expecting 41600 events.
[16:50:17.305] INFO: 41600 events read in total (2797ms).
[16:50:17.306] INFO: Test took 4014ms.
[16:50:17.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:18.057] INFO: Expecting 41600 events.
[16:50:21.382] INFO: 41600 events read in total (2798ms).
[16:50:21.383] INFO: Test took 4012ms.
[16:50:21.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:22.130] INFO: Expecting 41600 events.
[16:50:25.474] INFO: 41600 events read in total (2817ms).
[16:50:25.475] INFO: Test took 4026ms.
[16:50:25.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:26.221] INFO: Expecting 41600 events.
[16:50:29.549] INFO: 41600 events read in total (2802ms).
[16:50:29.551] INFO: Test took 4012ms.
[16:50:29.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:30.300] INFO: Expecting 41600 events.
[16:50:33.622] INFO: 41600 events read in total (2795ms).
[16:50:33.623] INFO: Test took 4007ms.
[16:50:33.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:34.370] INFO: Expecting 41600 events.
[16:50:37.727] INFO: 41600 events read in total (2830ms).
[16:50:37.728] INFO: Test took 4039ms.
[16:50:37.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:38.475] INFO: Expecting 41600 events.
[16:50:41.820] INFO: 41600 events read in total (2818ms).
[16:50:41.821] INFO: Test took 4028ms.
[16:50:41.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:42.570] INFO: Expecting 41600 events.
[16:50:45.923] INFO: 41600 events read in total (2826ms).
[16:50:45.925] INFO: Test took 4038ms.
[16:50:45.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:46.669] INFO: Expecting 41600 events.
[16:50:50.007] INFO: 41600 events read in total (2811ms).
[16:50:50.009] INFO: Test took 4017ms.
[16:50:50.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:50.759] INFO: Expecting 41600 events.
[16:50:54.095] INFO: 41600 events read in total (2809ms).
[16:50:54.096] INFO: Test took 4023ms.
[16:50:54.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:54.843] INFO: Expecting 41600 events.
[16:50:58.187] INFO: 41600 events read in total (2817ms).
[16:50:58.188] INFO: Test took 4027ms.
[16:50:58.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:58.933] INFO: Expecting 41600 events.
[16:51:02.260] INFO: 41600 events read in total (2800ms).
[16:51:02.261] INFO: Test took 4009ms.
[16:51:02.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:03.012] INFO: Expecting 41600 events.
[16:51:06.361] INFO: 41600 events read in total (2822ms).
[16:51:06.362] INFO: Test took 4036ms.
[16:51:06.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:07.111] INFO: Expecting 41600 events.
[16:51:10.464] INFO: 41600 events read in total (2826ms).
[16:51:10.465] INFO: Test took 4038ms.
[16:51:10.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:11.210] INFO: Expecting 41600 events.
[16:51:14.512] INFO: 41600 events read in total (2775ms).
[16:51:14.513] INFO: Test took 3982ms.
[16:51:14.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:15.264] INFO: Expecting 41600 events.
[16:51:18.616] INFO: 41600 events read in total (2825ms).
[16:51:18.617] INFO: Test took 4038ms.
[16:51:18.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:19.368] INFO: Expecting 41600 events.
[16:51:22.681] INFO: 41600 events read in total (2786ms).
[16:51:22.682] INFO: Test took 4000ms.
[16:51:22.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:23.425] INFO: Expecting 41600 events.
[16:51:26.604] INFO: 41600 events read in total (2652ms).
[16:51:26.606] INFO: Test took 3857ms.
[16:51:26.648] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:26.993] INFO: enter test to run
[16:51:59.322] INFO: test: HighRate no parameter change
[16:51:59.322] INFO: running: highrate
[16:51:59.323] INFO: ----------------------------------------------------------------------
[16:51:59.323] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:51:59.323] INFO: ----------------------------------------------------------------------
[16:51:59.331] INFO: ROC 8 masking pixel 48/65
[16:51:59.939] INFO: Expecting 208000 events.
[16:52:12.513] INFO: 208000 events read in total (12047ms).
[16:52:12.517] INFO: Test took 13185ms.
[16:52:12.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:12.976] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 419 0 0 0 0 0 0 0
[16:52:12.976] INFO: number of red-efficiency pixels: 58 45 60 149 137 147 118 94 1719 387 390 391 403 361 347 325
[16:52:12.976] INFO: number of X-ray hits detected: 59614 41790 68196 106056 113907 118360 115013 78605 501343 98668 99703 83050 87835 52823 21057 26788
[16:52:12.976] 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:52:12.976] INFO: number of Vcal hits detected: 207941 207955 207938 207848 207859 207851 207879 207903 165813 207592 207593 207589 207575 207621 207565 207663
[16:52:12.976] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 89.2 99.8 99.8 99.8 99.8 99.8 99.8 99.8
[16:52:12.976] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 79.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8
[16:52:12.976] INFO: X-ray hit rate [MHz/cm2]: 17.5 12.2 20.0 31.1 33.4 34.7 33.7 23.0 146.9 28.9 29.2 24.3 25.7 15.5 6.2 7.9
[16:52:12.976] INFO: PixTestHighRate::doXPixelAlive() done
[16:52:13.021] INFO: PixTest:: pg_setup set to default.
[16:52:13.029] INFO: enter test to run
[16:52:27.802] INFO: test: HighRate no parameter change
[16:52:27.802] INFO: running: highrate
[16:52:27.803] INFO: ----------------------------------------------------------------------
[16:52:27.803] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:52:27.803] INFO: ----------------------------------------------------------------------
[16:52:27.811] INFO: ROC 8 masking pixel 48/65
[16:52:28.418] INFO: Expecting 208000 events.
[16:52:42.426] INFO: 208000 events read in total (13481ms).
[16:52:42.431] INFO: Test took 14619ms.
[16:52:42.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:43.056] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 388 0 0 0 0 0 0 0
[16:52:43.056] INFO: number of red-efficiency pixels: 156 98 190 414 376 382 332 298 2008 787 790 734 770 692 616 598
[16:52:43.056] INFO: number of X-ray hits detected: 115778 81990 133789 207489 223139 229992 222623 154038 562549 192067 192716 163625 170413 103391 41663 52654
[16:52:43.056] 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:52:43.056] INFO: number of Vcal hits detected: 207840 207900 207796 207555 207608 207596 207650 207681 165577 207132 207117 207177 207142 207236 207275 207355
[16:52:43.056] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 88.4 99.6 99.6 99.6 99.6 99.6 99.7 99.7
[16:52:43.056] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 79.6 99.6 99.6 99.6 99.6 99.6 99.7 99.7
[16:52:43.056] INFO: X-ray hit rate [MHz/cm2]: 33.9 24.0 39.2 60.8 65.4 67.4 65.3 45.1 164.9 56.3 56.5 48.0 49.9 30.3 12.2 15.4
[16:52:43.056] INFO: PixTestHighRate::doXPixelAlive() done
[16:52:43.103] INFO: PixTest:: pg_setup set to default.
[16:52:43.122] INFO: enter test to run
[16:52:58.561] INFO: test: HighRate no parameter change
[16:52:58.561] INFO: running: highrate
[16:52:58.562] INFO: ----------------------------------------------------------------------
[16:52:58.562] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:52:58.562] INFO: ----------------------------------------------------------------------
[16:52:58.572] INFO: ROC 8 masking pixel 48/65
[16:52:59.174] INFO: Expecting 208000 events.
[16:53:15.333] INFO: 208000 events read in total (15632ms).
[16:53:15.341] INFO: Test took 16769ms.
[16:53:15.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:16.207] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 373 0 0 0 0 0 0 0
[16:53:16.207] INFO: number of red-efficiency pixels: 348 241 492 1098 935 968 873 778 2336 1372 1319 1208 1217 1059 864 844
[16:53:16.208] INFO: number of X-ray hits detected: 183002 129312 210939 328865 352383 363392 353414 244821 639237 304275 303812 259624 269758 164772 65582 83231
[16:53:16.208] 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:53:16.208] INFO: number of Vcal hits detected: 207613 207735 207410 206657 206856 206823 206935 207031 165267 206333 206368 206551 206550 206774 206960 207056
[16:53:16.208] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.5 99.5 99.5 99.6 87.9 99.2 99.3 99.3 99.3 99.4 99.5 99.5
[16:53:16.208] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.5 99.4 99.5 99.5 79.5 99.2 99.2 99.3 99.3 99.4 99.5 99.5
[16:53:16.208] INFO: X-ray hit rate [MHz/cm2]: 53.6 37.9 61.8 96.4 103.3 106.5 103.6 71.8 187.4 89.2 89.0 76.1 79.1 48.3 19.2 24.4
[16:53:16.208] INFO: PixTestHighRate::doXPixelAlive() done
[16:53:16.257] INFO: PixTest:: pg_setup set to default.
[16:53:16.267] INFO: enter test to run
[16:53:21.049] INFO: test: exit no parameter change
[16:53:21.468] QUIET: Connection to board 33 closed.
[16:53:21.468] INFO: pXar: this is the end, my friend