[12:56:15.723]     INFO: *** Welcome to pxar ***
[12:56:15.723]     INFO: *** Today: 2016/08/18
[12:56:16.170]     INFO: *** Version: v1.9.0-818-g96727
[12:56:16.170]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//dacParameters35_C15.dat
[12:56:16.207]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//tbmParameters_C0b.dat
[12:56:16.207]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//defaultMaskFile.dat
[12:56:16.207]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C15.dat
[12:56:16.287]     INFO:         clk: 4
[12:56:16.287]     INFO:         ctr: 4
[12:56:16.287]     INFO:         sda: 19
[12:56:16.287]     INFO:         tin: 9
[12:56:16.287]     INFO:         level: 15
[12:56:16.288]     INFO:         triggerdelay: 0
[12:56:16.288]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:56:16.288]     INFO: Log level: INFO
[12:56:16.306]    QUIET: Connection to board DTB_WREKRL opened.
[12:56:16.309]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[12:56:16.312]     INFO: RPC call hashes of host and DTB match: 398089610
[12:56:17.847]     INFO: DUT info: 
[12:56:17.847]     INFO: The DUT currently contains the following objects:
[12:56:17.847]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:56:17.847]     INFO: 	TBM Core alpha (0): 7 registers set
[12:56:17.847]     INFO: 	TBM Core beta  (1): 7 registers set
[12:56:17.847]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:56:17.848]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:17.848]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:56:18.274]     INFO: enter 'restricted' command line mode
[12:56:18.274]     INFO: enter test to run
[12:56:22.118]     INFO:   test: timing no parameter change
[12:56:22.118]     INFO:   running: timing
[12:56:22.147]     INFO: ######################################################################
[12:56:22.149]     INFO: PixTestTiming::doTest()
[12:56:22.149]     INFO: ######################################################################
[12:56:22.149]     INFO:    ----------------------------------------------------------------------
[12:56:22.149]     INFO:    PixTestTiming::TBMPhaseScan()
[12:56:22.149]     INFO:    ----------------------------------------------------------------------
[13:04:57.432]     INFO: TBM Phase Settings: 232
[13:04:57.432]     INFO: 400MHz Phase: 2
[13:04:57.432]     INFO: 160MHz Phase: 7
[13:04:57.432]     INFO: Functional Phase Area: 3
[13:04:57.440]     INFO: Test took 515291 ms.
[13:04:57.440]     INFO: PixTestTiming::TBMPhaseScan() done.
[13:04:57.441]     INFO:    ----------------------------------------------------------------------
[13:04:57.441]     INFO:    PixTestTiming::ROCDelayScan()
[13:04:57.441]     INFO:    ----------------------------------------------------------------------
[13:06:57.470]     INFO: ROC Delay Settings: 228
[13:06:57.470]     INFO: ROC Header-Trailer/Token Delay: 11
[13:06:57.470]     INFO: ROC Port 0 Delay: 4
[13:06:57.470]     INFO: ROC Port 1 Delay: 4
[13:06:57.470]     INFO: Functional ROC Area: 5
[13:06:57.473]     INFO: Test took 120033 ms.
[13:06:57.473]     INFO: PixTestTiming::ROCDelayScan() done.
[13:06:57.473]     INFO:    ----------------------------------------------------------------------
[13:06:57.473]     INFO:    PixTestTiming::TimingTest()
[13:06:57.473]     INFO:    ----------------------------------------------------------------------
[13:07:13.622]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:28.603]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.570]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:58.497]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:13.462]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:28.435]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:43.389]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:58.356]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:13.315]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:28.282]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:28.664]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO:    The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO:    Read back bit status: 1
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO:    Timings are good!
[13:09:28.684]     INFO:    ----------------------------------------------------------------------
[13:09:28.684]     INFO: Test took 151211 ms.
[13:09:28.684]     INFO: PixTestTiming::TimingTest() done.
[13:09:28.695]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//tbmParameters_C0a.dat
[13:09:28.695]     INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//tbmParameters_C0b.dat
[13:09:28.695]     INFO: PixTestTiming::doTest took 786553 ms.
[13:09:28.695]     INFO: PixTestTiming::doTest() done
[13:09:28.695]     INFO: Write out TBMPhaseScan_0_V0
[13:09:28.749]     INFO: Write out TBMPhaseScan_1_V0
[13:09:28.749]     INFO: Write out CombinedTBMPhaseScan_V0
[13:09:28.778]     INFO: Write out ROCDelayScan3_V0
[13:09:28.778]     INFO: enter test to run
[13:19:24.301]     INFO:   test: PixelAlive no parameter change
[13:19:24.301]     INFO:   running: pixelalive
[13:19:24.305]     INFO:    ----------------------------------------------------------------------
[13:19:24.305]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:19:24.305]     INFO:    ----------------------------------------------------------------------
[13:19:24.622]     INFO: Expecting 41600 events.
[13:19:28.947]     INFO: 41600 events read in total (3610ms).
[13:19:28.948]     INFO: Test took 4640ms.
[13:19:28.954]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:29.353]     INFO: PixTestAlive::aliveTest() done
[13:19:29.353]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    2    0    0    0
[13:19:29.357]     INFO: enter test to run
[13:19:49.741]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:19:49.741]     INFO:   running: highrate
[13:19:49.741]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//phCalibrationFitErr35_C15.dat
[13:19:49.951]     INFO:    ----------------------------------------------------------------------
[13:19:49.951]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:19:49.951]     INFO:    ----------------------------------------------------------------------
[13:19:49.951]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:19:49.952]     INFO: edge/corner pixel THR is adjusted
[13:19:49.952]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:19:50.910]     INFO: Collecting data for 5 seconds...
[13:19:55.927]     INFO: Done with hot pixel readout
[13:20:07.172]     INFO: PixTest::       pg_setup set to default.
[13:20:07.172]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:20:07.172]     INFO: 3 hot pixels found in step 0
[13:20:08.162]     INFO: Collecting data for 5 seconds...
[13:20:13.179]     INFO: Done with hot pixel readout
[13:20:24.537]     INFO: PixTest::       pg_setup set to default.
[13:20:24.537]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:20:24.538]     INFO: 5 hot pixels found in step 1
[13:20:25.528]     INFO: Collecting data for 5 seconds...
[13:20:30.545]     INFO: Done with hot pixel readout
[13:20:42.010]     INFO: PixTest::       pg_setup set to default.
[13:20:42.010]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:20:42.011]     INFO: 4 hot pixels found in step 2
[13:20:42.003]     INFO: Collecting data for 5 seconds...
[13:20:48.020]     INFO: Done with hot pixel readout
[13:20:59.078]     INFO: PixTest::       pg_setup set to default.
[13:20:59.078]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:20:59.079]     INFO: 3 hot pixels found in step 3
[13:21:00.076]     INFO: Collecting data for 5 seconds...
[13:21:05.092]     INFO: Done with hot pixel readout
[13:21:16.483]     INFO: PixTest::       pg_setup set to default.
[13:21:16.484]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:16.484]     INFO: 2 hot pixels found in step 4
[13:21:17.474]     INFO: Collecting data for 5 seconds...
[13:21:22.491]     INFO: Done with hot pixel readout
[13:21:33.497]     INFO: PixTest::       pg_setup set to default.
[13:21:33.498]     INFO: 0 hot pixels found in step 5
[13:21:33.532]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:21:33.535]     INFO: PixTest::trimHotPixels() done
[13:21:33.536]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C0.dat
[13:21:33.547]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C1.dat
[13:21:33.556]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C2.dat
[13:21:33.561]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C3.dat
[13:21:33.567]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C4.dat
[13:21:33.572]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C5.dat
[13:21:33.577]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C6.dat
[13:21:33.582]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C7.dat
[13:21:33.587]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C8.dat
[13:21:33.592]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C9.dat
[13:21:33.597]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C10.dat
[13:21:33.603]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C11.dat
[13:21:33.608]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C12.dat
[13:21:33.613]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C13.dat
[13:21:33.618]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C14.dat
[13:21:33.624]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C15.dat
[13:21:33.629]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//defaultMaskFile.dat
[13:21:33.638]     INFO: enter test to run
[13:22:21.524]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:22:21.524]     INFO:   running: highrate
[13:22:21.528]     INFO:    ----------------------------------------------------------------------
[13:22:21.528]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:22:21.528]     INFO:    ----------------------------------------------------------------------
[13:22:21.528]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:22:21.528]     INFO: edge/corner pixel THR is adjusted
[13:22:21.528]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:22:22.486]     INFO: Collecting data for 1 seconds...
[13:22:23.490]     INFO: Done with hot pixel readout
[13:22:27.368]     INFO: PixTest::       pg_setup set to default.
[13:22:27.369]     INFO: 0 hot pixels found in step 0
[13:22:27.375]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:22:27.467]     INFO: PixTest::trimHotPixels() done
[13:22:27.467]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C0.dat
[13:22:27.476]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C1.dat
[13:22:27.485]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C2.dat
[13:22:27.490]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C3.dat
[13:22:27.495]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C4.dat
[13:22:27.500]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C5.dat
[13:22:27.505]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C6.dat
[13:22:27.511]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C7.dat
[13:22:27.516]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C8.dat
[13:22:27.521]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C9.dat
[13:22:27.526]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C10.dat
[13:22:27.532]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C11.dat
[13:22:27.537]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C12.dat
[13:22:27.542]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C13.dat
[13:22:27.547]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C14.dat
[13:22:27.552]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//trimParameters35_C15.dat
[13:22:27.558]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-47_FPIXTest-m20C-FNAL-160816-1000-150V_2016-08-16_10h00m_1471359628/000_FPIXTest_m20//defaultMaskFile.dat
[13:22:27.567]     INFO: enter test to run
[13:23:12.723]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[13:23:12.724]     INFO:   running: xray
[13:23:12.777]     INFO:    ----------------------------------------------------------------------
[13:23:12.777]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:23:12.777]     INFO:    ----------------------------------------------------------------------
[13:23:13.773]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:23:25.555]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:23:57.138]     INFO: Resuming triggers.
[13:24:08.921]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:24:39.211]     INFO: Resuming triggers.
[13:24:50.991]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:25:21.958]     INFO: Resuming triggers.
[13:25:33.741]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:26:05.463]     INFO: Resuming triggers.
[13:26:17.249]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:26:48.324]     INFO: Resuming triggers.
[13:27:00.105]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:27:30.999]     INFO: Resuming triggers.
[13:27:42.787]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:28:13.508]     INFO: Resuming triggers.
[13:28:25.299]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:28:56.138]     INFO: Resuming triggers.
[13:29:02.218]     INFO: data taking finished, elapsed time: 100 seconds.
[13:29:18.369]     INFO: PixTest::       pg_setup set to default.
[13:29:18.372]     INFO: PixTestXray::doPhRun() done
[13:29:18.575]     INFO: enter test to run
[13:29:38.097]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[13:29:38.097]     INFO:   running: xray
[13:29:38.098]     INFO:    ----------------------------------------------------------------------
[13:29:38.098]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:29:38.098]     INFO:    ----------------------------------------------------------------------
[13:29:39.062]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:29:46.109]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:30:18.931]     INFO: Resuming triggers.
[13:30:25.982]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[13:30:58.775]     INFO: Resuming triggers.
[13:31:05.825]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:31:38.643]     INFO: Resuming triggers.
[13:31:45.693]     INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:32:17.378]     INFO: Resuming triggers.
[13:32:24.430]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:32:56.083]     INFO: Resuming triggers.
[13:33:03.135]     INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:33:35.969]     INFO: Resuming triggers.
[13:33:43.023]     INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:34:15.775]     INFO: Resuming triggers.
[13:34:22.828]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:34:55.609]     INFO: Resuming triggers.
[13:35:02.659]     INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:35:36.291]     INFO: Resuming triggers.
[13:35:43.339]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:36:16.772]     INFO: Resuming triggers.
[13:36:23.820]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:36:56.604]     INFO: Resuming triggers.
[13:37:03.651]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:37:37.551]     INFO: Resuming triggers.
[13:37:44.597]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:38:18.391]     INFO: Resuming triggers.
[13:38:25.438]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:38:58.700]     INFO: Resuming triggers.
[13:39:00.341]     INFO: data taking finished, elapsed time: 100 seconds.
[13:39:08.284]     INFO: PixTest::       pg_setup set to default.
[13:39:08.288]     INFO: PixTestXray::doPhRun() done
[13:39:08.438]     INFO: enter test to run
[13:39:22.765]     INFO:   test: HighRate no parameter change
[13:39:22.765]     INFO:   running: highrate
[13:39:22.786]     INFO:    ----------------------------------------------------------------------
[13:39:22.787]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:39:22.787]     INFO:    ----------------------------------------------------------------------
[13:39:22.932]     INFO: Expecting 768 events.
[13:39:24.067]     INFO: 768 events read in total (419ms).
[13:39:24.067]     INFO: Test took 1269ms.
[13:39:24.870]     INFO: Expecting 41600 events.
[13:39:27.918]     INFO: 41600 events read in total (2521ms).
[13:39:27.919]     INFO: Test took 3844ms.
[13:39:27.951]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:28.680]     INFO: Expecting 41600 events.
[13:39:31.860]     INFO: 41600 events read in total (2653ms).
[13:39:31.861]     INFO: Test took 3893ms.
[13:39:31.894]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:32.624]     INFO: Expecting 41600 events.
[13:39:35.829]     INFO: 41600 events read in total (2678ms).
[13:39:35.830]     INFO: Test took 3919ms.
[13:39:35.862]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:36.587]     INFO: Expecting 41600 events.
[13:39:39.793]     INFO: 41600 events read in total (2679ms).
[13:39:39.794]     INFO: Test took 3916ms.
[13:39:39.827]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:40.555]     INFO: Expecting 41600 events.
[13:39:43.784]     INFO: 41600 events read in total (2702ms).
[13:39:43.785]     INFO: Test took 3941ms.
[13:39:43.817]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:44.542]     INFO: Expecting 41600 events.
[13:39:47.759]     INFO: 41600 events read in total (2691ms).
[13:39:47.760]     INFO: Test took 3925ms.
[13:39:47.791]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:48.522]     INFO: Expecting 41600 events.
[13:39:51.741]     INFO: 41600 events read in total (2692ms).
[13:39:51.742]     INFO: Test took 3934ms.
[13:39:51.775]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:52.498]     INFO: Expecting 41600 events.
[13:39:55.727]     INFO: 41600 events read in total (2702ms).
[13:39:55.728]     INFO: Test took 3937ms.
[13:39:55.760]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:56.488]     INFO: Expecting 41600 events.
[13:39:59.709]     INFO: 41600 events read in total (2694ms).
[13:39:59.710]     INFO: Test took 3932ms.
[13:39:59.743]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:00.466]     INFO: Expecting 41600 events.
[13:40:03.697]     INFO: 41600 events read in total (2704ms).
[13:40:03.698]     INFO: Test took 3937ms.
[13:40:03.730]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:04.459]     INFO: Expecting 41600 events.
[13:40:07.678]     INFO: 41600 events read in total (2692ms).
[13:40:07.679]     INFO: Test took 3932ms.
[13:40:07.711]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:08.437]     INFO: Expecting 41600 events.
[13:40:11.663]     INFO: 41600 events read in total (2699ms).
[13:40:11.664]     INFO: Test took 3935ms.
[13:40:11.696]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:12.424]     INFO: Expecting 41600 events.
[13:40:15.647]     INFO: 41600 events read in total (2696ms).
[13:40:15.648]     INFO: Test took 3934ms.
[13:40:15.680]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:16.406]     INFO: Expecting 41600 events.
[13:40:19.633]     INFO: 41600 events read in total (2700ms).
[13:40:19.634]     INFO: Test took 3937ms.
[13:40:19.665]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:20.395]     INFO: Expecting 41600 events.
[13:40:23.604]     INFO: 41600 events read in total (2682ms).
[13:40:23.605]     INFO: Test took 3922ms.
[13:40:23.637]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:24.365]     INFO: Expecting 41600 events.
[13:40:27.600]     INFO: 41600 events read in total (2708ms).
[13:40:27.601]     INFO: Test took 3947ms.
[13:40:27.633]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:28.361]     INFO: Expecting 41600 events.
[13:40:31.582]     INFO: 41600 events read in total (2694ms).
[13:40:31.583]     INFO: Test took 3933ms.
[13:40:31.615]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:32.342]     INFO: Expecting 41600 events.
[13:40:35.555]     INFO: 41600 events read in total (2686ms).
[13:40:35.556]     INFO: Test took 3923ms.
[13:40:35.588]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.316]     INFO: Expecting 41600 events.
[13:40:39.539]     INFO: 41600 events read in total (2696ms).
[13:40:39.539]     INFO: Test took 3934ms.
[13:40:39.571]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:40.299]     INFO: Expecting 41600 events.
[13:40:43.391]     INFO: 41600 events read in total (2565ms).
[13:40:43.392]     INFO: Test took 3804ms.
[13:40:43.424]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:43.797]     INFO: enter test to run
[13:40:51.908]     INFO:   test: HighRate no parameter change
[13:40:51.908]     INFO:   running: highrate
[13:40:51.909]     INFO:    ----------------------------------------------------------------------
[13:40:51.909]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:40:51.909]     INFO:    ----------------------------------------------------------------------
[13:40:52.517]     INFO: Expecting 208000 events.
[13:41:04.280]     INFO: 208000 events read in total (11236ms).
[13:41:04.283]     INFO: Test took 12367ms.
[13:41:04.415]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:04.664]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    2    0    0    0
[13:41:04.664]     INFO: number of red-efficiency pixels:   103   44   62  157  132  141  146   84   75  131  130  106   70   55   30   33
[13:41:04.664]     INFO: number of X-ray hits detected:    68558 43029 64319 101579 106815 104779 108481 69238 63914 92330 91775 77338 74018 49191 20220 22321
[13:41:04.664]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:41:04.664]     INFO: number of Vcal hits detected:  207893 207956 207934 207839 207867 207855 207850 207913 207922 207866 207868 207892 207828 207944 207970 207967
[13:41:04.664]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:41:04.664]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:41:04.664]     INFO: X-ray hit rate [MHz/cm2]:  20.1 12.6 18.9 29.8 31.3 30.7 31.8 20.3 18.7 27.1 26.9 22.7 21.7 14.4 5.9 6.5
[13:41:04.664]     INFO: PixTestHighRate::doXPixelAlive() done
[13:41:04.710]     INFO: PixTest::       pg_setup set to default.
[13:41:04.722]     INFO: enter test to run
[13:41:16.532]     INFO:   test: HighRate no parameter change
[13:41:16.532]     INFO:   running: highrate
[13:41:16.533]     INFO:    ----------------------------------------------------------------------
[13:41:16.533]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:16.533]     INFO:    ----------------------------------------------------------------------
[13:41:17.151]     INFO: Expecting 208000 events.
[13:41:30.604]     INFO: 208000 events read in total (12926ms).
[13:41:30.609]     INFO: Test took 14067ms.
[13:41:30.895]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:31.190]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    2    0    0    0
[13:41:31.190]     INFO: number of red-efficiency pixels:   294  128  240  508  539  510  538  317  227  420  390  308  201  183   29   58
[13:41:31.190]     INFO: number of X-ray hits detected:    147043 90786 136841 216186 227222 222032 230227 147145 136975 197301 196207 165717 158218 104416 43694 47591
[13:41:31.190]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:41:31.190]     INFO: number of Vcal hits detected:  207676 207870 207737 207434 207412 207435 207406 207653 207762 207542 207584 207669 207691 207804 207971 207942
[13:41:31.190]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:41:31.190]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.9 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[13:41:31.190]     INFO: X-ray hit rate [MHz/cm2]:  43.1 26.6 40.1 63.4 66.6 65.1 67.5 43.1 40.1 57.8 57.5 48.6 46.4 30.6 12.8 13.9
[13:41:31.190]     INFO: PixTestHighRate::doXPixelAlive() done
[13:41:31.235]     INFO: PixTest::       pg_setup set to default.
[13:41:31.252]     INFO: enter test to run
[13:41:48.236]     INFO:   test: HighRate no parameter change
[13:41:48.236]     INFO:   running: highrate
[13:41:48.237]     INFO:    ----------------------------------------------------------------------
[13:41:48.237]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:48.237]     INFO:    ----------------------------------------------------------------------
[13:41:48.856]     INFO: Expecting 208000 events.
[13:42:03.780]     INFO: 208000 events read in total (14397ms).
[13:42:03.787]     INFO: Test took 15539ms.
[13:42:04.174]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:04.508]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    2    0    0    0
[13:42:04.508]     INFO: number of red-efficiency pixels:   576  308  487 1109 1193 1102 1183  603  452  831  856  626  376  358   74   82
[13:42:04.508]     INFO: number of X-ray hits detected:    210978 131280 195546 310614 326610 319064 330596 212727 197844 283933 281873 236533 226954 150236 62738 68988
[13:42:04.508]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:42:04.508]     INFO: number of Vcal hits detected:  207271 207652 207420 206605 206506 206595 206475 207264 207492 207022 206991 207281 207491 207582 207922 207915
[13:42:04.508]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.8 99.8 99.4 99.3 99.4 99.3 99.7 99.8 99.6 99.6 99.7 99.8 99.8 100.0 100.0
[13:42:04.508]     INFO: Vcal hit overall efficiency (%):  99.6 99.8 99.7 99.3 99.3 99.3 99.3 99.6 99.8 99.5 99.5 99.7 99.8 99.8 100.0 100.0
[13:42:04.508]     INFO: X-ray hit rate [MHz/cm2]:  61.8 38.5 57.3 91.0 95.7 93.5 96.9 62.4 58.0 83.2 82.6 69.3 66.5 44.0 18.4 20.2
[13:42:04.508]     INFO: PixTestHighRate::doXPixelAlive() done
[13:42:04.555]     INFO: PixTest::       pg_setup set to default.
[13:42:04.568]     INFO: enter test to run
[13:42:16.747]     INFO:   test: exit no parameter change
[13:42:17.150]    QUIET: Connection to board 33 closed.
[13:42:17.166]     INFO: pXar: this is the end, my friend