[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