[09:08:44.060]     INFO: *** Welcome to pxar ***
[09:08:44.060]     INFO: *** Today: 2016/08/26
[09:08:44.083]     INFO: *** Version: v1.9.0-818-g96727
[09:08:44.083]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C15.dat
[09:08:44.084]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:08:44.084]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:08:44.084]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:08:44.161]     INFO:         clk: 4
[09:08:44.161]     INFO:         ctr: 4
[09:08:44.161]     INFO:         sda: 19
[09:08:44.161]     INFO:         tin: 9
[09:08:44.161]     INFO:         level: 15
[09:08:44.161]     INFO:         triggerdelay: 0
[09:08:44.161]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:08:44.161]     INFO: Log level: INFO
[09:08:44.179]    QUIET: Connection to board DTB_WREKRL opened.
[09:08:44.183]     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:     
------------------------------------------------------
[09:08:44.186]     INFO: RPC call hashes of host and DTB match: 398089610
[09:08:45.721]     INFO: DUT info: 
[09:08:45.721]     INFO: The DUT currently contains the following objects:
[09:08:45.721]     INFO:  2 TBM Cores tbm08c (2 ON)
[09:08:45.722]     INFO: 	TBM Core alpha (0): 7 registers set
[09:08:45.722]     INFO: 	TBM Core beta  (1): 7 registers set
[09:08:45.722]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:08:45.722]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:46.177]     INFO: enter 'restricted' command line mode
[09:08:46.177]     INFO: enter test to run
[09:08:53.395]     INFO:   test: PixelAlive no parameter change
[09:08:53.395]     INFO:   running: pixelalive
[09:08:53.439]     INFO:    ----------------------------------------------------------------------
[09:08:53.439]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:08:53.439]     INFO:    ----------------------------------------------------------------------
[09:08:53.757]     INFO: Expecting 41600 events.
[09:08:58.094]     INFO: 41600 events read in total (3618ms).
[09:08:58.261]     INFO: Test took 4818ms.
[09:08:58.275]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:58.582]     INFO: PixTestAlive::aliveTest() done
[09:08:58.582]     INFO: number of dead pixels (per ROC):     0    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:08:58.806]     INFO: enter test to run
[09:09:38.035]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:09:38.035]     INFO:   running: highrate
[09:09:38.051]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:09:38.375]     INFO:    ----------------------------------------------------------------------
[09:09:38.375]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:09:38.375]     INFO:    ----------------------------------------------------------------------
[09:09:38.375]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:09:38.375]     INFO: edge/corner pixel THR is adjusted
[09:09:38.375]     INFO: PixTestHighRate::trimHotPixels: step 0...
[09:09:39.333]     INFO: Collecting data for 5 seconds...
[09:09:44.351]     INFO: Done with hot pixel readout
[09:09:56.334]     INFO: PixTest::       pg_setup set to default.
[09:09:56.334]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:09:56.334]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:09:56.335]     INFO: 34 hot pixels found in step 0
[09:09:57.350]     INFO: Collecting data for 5 seconds...
[09:10:02.367]     INFO: Done with hot pixel readout
[09:10:14.359]     INFO: PixTest::       pg_setup set to default.
[09:10:14.360]     INFO: 24 hot pixels found in step 1
[09:10:15.349]     INFO: Collecting data for 5 seconds...
[09:10:20.367]     INFO: Done with hot pixel readout
[09:10:32.338]     INFO: PixTest::       pg_setup set to default.
[09:10:32.338]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:10:32.339]     INFO: 23 hot pixels found in step 2
[09:10:33.330]     INFO: Collecting data for 5 seconds...
[09:10:38.349]     INFO: Done with hot pixel readout
[09:10:50.299]     INFO: PixTest::       pg_setup set to default.
[09:10:50.299]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:10:50.300]     INFO: 31 hot pixels found in step 3
[09:10:51.291]     INFO: Collecting data for 5 seconds...
[09:10:56.309]     INFO: Done with hot pixel readout
[09:11:08.276]     INFO: PixTest::       pg_setup set to default.
[09:11:08.277]     INFO: 22 hot pixels found in step 4
[09:11:09.267]     INFO: Collecting data for 5 seconds...
[09:11:14.285]     INFO: Done with hot pixel readout
[09:11:26.193]     INFO: PixTest::       pg_setup set to default.
[09:11:26.193]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:11:26.194]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:11:26.194]     INFO: 31 hot pixels found in step 5
[09:11:27.184]     INFO: Collecting data for 5 seconds...
[09:11:32.202]     INFO: Done with hot pixel readout
[09:11:44.170]     INFO: PixTest::       pg_setup set to default.
[09:11:44.170]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:11:44.170]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:11:44.171]     INFO: 29 hot pixels found in step 6
[09:11:45.161]     INFO: Collecting data for 5 seconds...
[09:11:50.179]     INFO: Done with hot pixel readout
[09:12:02.145]     INFO: PixTest::       pg_setup set to default.
[09:12:02.146]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:12:02.146]     INFO: 25 hot pixels found in step 7
[09:12:03.136]     INFO: Collecting data for 5 seconds...
[09:12:08.153]     INFO: Done with hot pixel readout
[09:12:20.136]     INFO: PixTest::       pg_setup set to default.
[09:12:20.136]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:12:20.136]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:12:20.137]     INFO: 17 hot pixels found in step 8
[09:12:21.128]     INFO: Collecting data for 5 seconds...
[09:12:26.145]     INFO: Done with hot pixel readout
[09:12:38.093]     INFO: PixTest::       pg_setup set to default.
[09:12:38.093]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:12:38.094]     INFO: 22 hot pixels found in step 9
[09:12:39.084]     INFO: Collecting data for 5 seconds...
[09:12:44.102]     INFO: Done with hot pixel readout
[09:12:56.024]     INFO: PixTest::       pg_setup set to default.
[09:12:56.024]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:12:56.025]     INFO: 20 hot pixels found in step 10
[09:12:57.015]     INFO: Collecting data for 5 seconds...
[09:13:02.032]     INFO: Done with hot pixel readout
[09:13:13.999]     INFO: PixTest::       pg_setup set to default.
[09:13:13.999]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:13.999]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:13.999]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:13.999]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:13.999]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:13.000]     INFO: 21 hot pixels found in step 11
[09:13:14.990]     INFO: Collecting data for 5 seconds...
[09:13:20.007]     INFO: Done with hot pixel readout
[09:13:31.954]     INFO: PixTest::       pg_setup set to default.
[09:13:31.954]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:31.954]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:31.954]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:31.954]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:31.954]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:31.955]     INFO: 21 hot pixels found in step 12
[09:13:32.946]     INFO: Collecting data for 5 seconds...
[09:13:37.962]     INFO: Done with hot pixel readout
[09:13:49.928]     INFO: PixTest::       pg_setup set to default.
[09:13:49.928]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:49.928]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:49.928]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:13:49.929]     INFO: 12 hot pixels found in step 13
[09:13:50.920]     INFO: Collecting data for 5 seconds...
[09:13:55.938]     INFO: Done with hot pixel readout
[09:14:07.892]     INFO: PixTest::       pg_setup set to default.
[09:14:07.892]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.892]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.892]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.892]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.892]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.893]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[09:14:07.893]     INFO: 18 hot pixels found in step 14
[09:14:07.927]     INFO: 18 hot pixels could not be trimmed and have been masked.
[09:14:07.930]     INFO: PixTest::trimHotPixels() done
[09:14:07.933]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[09:14:07.939]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[09:14:07.945]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[09:14:07.950]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[09:14:07.956]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[09:14:07.961]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[09:14:07.966]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[09:14:07.971]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[09:14:07.977]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[09:14:07.982]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[09:14:07.987]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[09:14:07.992]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[09:14:07.998]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[09:14:07.003]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[09:14:08.008]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[09:14:08.013]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:14:08.019]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:14:08.033]     INFO: enter test to run
[09:14:34.297]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:14:34.297]     INFO:   running: highrate
[09:14:34.301]     INFO:    ----------------------------------------------------------------------
[09:14:34.301]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:14:34.301]     INFO:    ----------------------------------------------------------------------
[09:14:34.301]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:14:34.301]     INFO: edge/corner pixel THR is adjusted
[09:14:34.301]     INFO: PixTestHighRate::trimHotPixels: step 0...
[09:14:35.264]     INFO: Collecting data for 1 seconds...
[09:14:36.268]     INFO: Done with hot pixel readout
[09:14:40.485]     INFO: PixTest::       pg_setup set to default.
[09:14:40.485]     INFO: 0 hot pixels found in step 0
[09:14:40.490]     INFO: 0 hot pixels could not be trimmed and have been masked.
[09:14:40.574]     INFO: PixTest::trimHotPixels() done
[09:14:40.575]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[09:14:40.586]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[09:14:40.592]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[09:14:40.597]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[09:14:40.602]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[09:14:40.607]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[09:14:40.613]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[09:14:40.618]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[09:14:40.623]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[09:14:40.628]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[09:14:40.633]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[09:14:40.639]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[09:14:40.644]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[09:14:40.649]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[09:14:40.655]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[09:14:40.660]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:14:40.665]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:14:40.675]     INFO: enter test to run
[09:15:01.416]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[09:15:01.416]     INFO:   running: xray
[09:15:01.417]     INFO:    ----------------------------------------------------------------------
[09:15:01.417]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[09:15:01.418]     INFO:    ----------------------------------------------------------------------
[09:15:02.398]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[09:15:13.432]     INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:15:43.607]     INFO: Resuming triggers.
[09:15:54.641]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:16:24.701]     INFO: Resuming triggers.
[09:16:35.735]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[09:17:05.715]     INFO: Resuming triggers.
[09:17:16.756]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:17:46.475]     INFO: Resuming triggers.
[09:17:57.517]     INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[09:18:27.827]     INFO: Resuming triggers.
[09:18:38.865]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[09:19:08.003]     INFO: Resuming triggers.
[09:19:20.038]     INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[09:19:49.900]     INFO: Resuming triggers.
[09:20:00.940]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:20:30.346]     INFO: Resuming triggers.
[09:20:41.381]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[09:21:10.939]     INFO: Resuming triggers.
[09:21:11.985]     INFO: data taking finished, elapsed time: 100 seconds.
[09:21:15.143]     INFO: PixTest::       pg_setup set to default.
[09:21:15.146]     INFO: PixTestXray::doPhRun() done
[09:21:15.346]     INFO: enter test to run
[09:22:27.485]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[09:22:27.485]     INFO:   running: xray
[09:22:27.486]     INFO:    ----------------------------------------------------------------------
[09:22:27.487]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[09:22:27.487]     INFO:    ----------------------------------------------------------------------
[09:22:28.468]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[09:22:34.697]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:23:04.770]     INFO: Resuming triggers.
[09:23:10.003]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:23:41.074]     INFO: Resuming triggers.
[09:23:47.306]     INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:24:17.370]     INFO: Resuming triggers.
[09:24:23.606]     INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[09:24:53.260]     INFO: Resuming triggers.
[09:24:59.494]     INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:25:29.808]     INFO: Resuming triggers.
[09:25:36.041]     INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:26:05.944]     INFO: Resuming triggers.
[09:26:12.176]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:26:42.223]     INFO: Resuming triggers.
[09:26:48.461]     INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[09:27:18.527]     INFO: Resuming triggers.
[09:27:24.760]     INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[09:27:55.605]     INFO: Resuming triggers.
[09:28:01.843]     INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:28:32.778]     INFO: Resuming triggers.
[09:28:39.018]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:29:10.067]     INFO: Resuming triggers.
[09:29:16.308]     INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:29:46.673]     INFO: Resuming triggers.
[09:29:52.913]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:30:24.255]     INFO: Resuming triggers.
[09:30:30.495]     INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[09:31:01.813]     INFO: Resuming triggers.
[09:31:08.055]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:31:38.985]     INFO: Resuming triggers.
[09:31:45.226]     INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[09:32:15.394]     INFO: Resuming triggers.
[09:32:15.972]     INFO: data taking finished, elapsed time: 100 seconds.
[09:32:19.145]     INFO: PixTest::       pg_setup set to default.
[09:32:19.149]     INFO: PixTestXray::doPhRun() done
[09:32:19.297]     INFO: enter test to run
[09:39:07.959]     INFO:   test: HighRate no parameter change
[09:39:07.959]     INFO:   running: highrate
[09:39:07.975]     INFO:    ----------------------------------------------------------------------
[09:39:07.975]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:39:07.975]     INFO:    ----------------------------------------------------------------------
[09:39:08.130]     INFO: Expecting 768 events.
[09:39:09.264]     INFO: 768 events read in total (418ms).
[09:39:09.265]     INFO: Test took 1270ms.
[09:39:10.068]     INFO: Expecting 41600 events.
[09:39:13.211]     INFO: 41600 events read in total (2616ms).
[09:39:13.211]     INFO: Test took 3920ms.
[09:39:13.247]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:13.969]     INFO: Expecting 41600 events.
[09:39:17.224]     INFO: 41600 events read in total (2729ms).
[09:39:17.225]     INFO: Test took 3959ms.
[09:39:17.262]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:17.984]     INFO: Expecting 41600 events.
[09:39:21.255]     INFO: 41600 events read in total (2745ms).
[09:39:21.256]     INFO: Test took 3975ms.
[09:39:21.294]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:22.012]     INFO: Expecting 41600 events.
[09:39:25.238]     INFO: 41600 events read in total (2699ms).
[09:39:25.239]     INFO: Test took 3926ms.
[09:39:25.277]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:25.991]     INFO: Expecting 41600 events.
[09:39:29.126]     INFO: 41600 events read in total (2608ms).
[09:39:29.127]     INFO: Test took 3830ms.
[09:39:29.164]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:29.881]     INFO: Expecting 41600 events.
[09:39:33.076]     INFO: 41600 events read in total (2668ms).
[09:39:33.077]     INFO: Test took 3893ms.
[09:39:33.113]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:33.833]     INFO: Expecting 41600 events.
[09:39:37.104]     INFO: 41600 events read in total (2744ms).
[09:39:37.105]     INFO: Test took 3974ms.
[09:39:37.142]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:37.859]     INFO: Expecting 41600 events.
[09:39:41.126]     INFO: 41600 events read in total (2741ms).
[09:39:41.127]     INFO: Test took 3967ms.
[09:39:41.164]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:41.880]     INFO: Expecting 41600 events.
[09:39:45.156]     INFO: 41600 events read in total (2749ms).
[09:39:45.157]     INFO: Test took 3973ms.
[09:39:45.195]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:45.907]     INFO: Expecting 41600 events.
[09:39:49.293]     INFO: 41600 events read in total (2859ms).
[09:39:49.294]     INFO: Test took 4081ms.
[09:39:49.331]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:50.039]     INFO: Expecting 41600 events.
[09:39:53.333]     INFO: 41600 events read in total (2767ms).
[09:39:53.334]     INFO: Test took 3984ms.
[09:39:53.372]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:54.075]     INFO: Expecting 41600 events.
[09:39:57.232]     INFO: 41600 events read in total (2630ms).
[09:39:57.233]     INFO: Test took 3842ms.
[09:39:57.272]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:57.988]     INFO: Expecting 41600 events.
[09:40:01.227]     INFO: 41600 events read in total (2713ms).
[09:40:01.228]     INFO: Test took 3937ms.
[09:40:01.266]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:01.981]     INFO: Expecting 41600 events.
[09:40:05.190]     INFO: 41600 events read in total (2682ms).
[09:40:05.191]     INFO: Test took 3906ms.
[09:40:05.229]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:05.945]     INFO: Expecting 41600 events.
[09:40:09.223]     INFO: 41600 events read in total (2751ms).
[09:40:09.224]     INFO: Test took 3976ms.
[09:40:09.262]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:09.980]     INFO: Expecting 41600 events.
[09:40:13.255]     INFO: 41600 events read in total (2748ms).
[09:40:13.256]     INFO: Test took 3974ms.
[09:40:13.294]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:14.010]     INFO: Expecting 41600 events.
[09:40:17.245]     INFO: 41600 events read in total (2708ms).
[09:40:17.246]     INFO: Test took 3934ms.
[09:40:17.284]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:17.997]     INFO: Expecting 41600 events.
[09:40:21.223]     INFO: 41600 events read in total (2699ms).
[09:40:21.224]     INFO: Test took 3921ms.
[09:40:21.262]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:21.980]     INFO: Expecting 41600 events.
[09:40:25.111]     INFO: 41600 events read in total (2605ms).
[09:40:25.113]     INFO: Test took 3832ms.
[09:40:25.151]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:25.869]     INFO: Expecting 41600 events.
[09:40:28.945]     INFO: 41600 events read in total (2549ms).
[09:40:28.946]     INFO: Test took 3774ms.
[09:40:28.983]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:29.349]     INFO: enter test to run
[09:40:42.358]     INFO:   test: HighRate no parameter change
[09:40:42.358]     INFO:   running: highrate
[09:40:42.359]     INFO:    ----------------------------------------------------------------------
[09:40:42.359]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:40:42.359]     INFO:    ----------------------------------------------------------------------
[09:40:42.982]     INFO: Expecting 208000 events.
[09:40:54.925]     INFO: 208000 events read in total (11416ms).
[09:40:54.928]     INFO: Test took 12560ms.
[09:40:55.094]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:55.353]     INFO: number of dead pixels (per ROC):     0    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:40:55.353]     INFO: number of red-efficiency pixels:    91   55  101  186  192  165  179  125  118  170  126  118  112   82   30   25
[09:40:55.353]     INFO: number of X-ray hits detected:    70252 47137 73756 118500 123359 127449 124267 86888 86539 117998 106823 92687 96406 58641 23684 26724
[09:40:55.353]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:40:55.353]     INFO: number of Vcal hits detected:  207907 207896 207846 207806 207800 207829 207813 207873 207880 207828 207873 207879 207887 207917 207969 207975
[09:40:55.353]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[09:40:55.353]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[09:40:55.353]     INFO: X-ray hit rate [MHz/cm2]:  20.6 13.8 21.6 34.7 36.2 37.4 36.4 25.5 25.4 34.6 31.3 27.2 28.3 17.2 6.9 7.8
[09:40:55.353]     INFO: PixTestHighRate::doXPixelAlive() done
[09:40:55.398]     INFO: PixTest::       pg_setup set to default.
[09:40:55.409]     INFO: enter test to run
[09:41:11.854]     INFO:   test: HighRate no parameter change
[09:41:11.854]     INFO:   running: highrate
[09:41:11.855]     INFO:    ----------------------------------------------------------------------
[09:41:11.855]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:41:11.855]     INFO:    ----------------------------------------------------------------------
[09:41:12.472]     INFO: Expecting 208000 events.
[09:41:26.333]     INFO: 208000 events read in total (13334ms).
[09:41:26.339]     INFO: Test took 14473ms.
[09:41:26.689]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:26.004]     INFO: number of dead pixels (per ROC):     0    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:41:26.004]     INFO: number of red-efficiency pixels:   267  193  374  637  740  634  518  400  349  498  406  443  388  252   57   73
[09:41:26.004]     INFO: number of X-ray hits detected:    147190 99202 154926 248512 256498 266141 258576 182495 180991 245888 224961 194199 202592 122924 49369 56466
[09:41:26.004]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:41:26.004]     INFO: number of Vcal hits detected:  207714 207748 207529 207276 207160 207282 207428 207531 207628 207442 207567 207514 207581 207730 207941 207927
[09:41:26.004]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.8 99.7 99.6 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[09:41:26.004]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.6 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[09:41:26.004]     INFO: X-ray hit rate [MHz/cm2]:  43.1 29.1 45.4 72.8 75.2 78.0 75.8 53.5 53.0 72.1 65.9 56.9 59.4 36.0 14.5 16.6
[09:41:26.004]     INFO: PixTestHighRate::doXPixelAlive() done
[09:41:27.049]     INFO: PixTest::       pg_setup set to default.
[09:41:27.065]     INFO: enter test to run
[09:41:43.013]     INFO:   test: HighRate no parameter change
[09:41:43.014]     INFO:   running: highrate
[09:41:43.015]     INFO:    ----------------------------------------------------------------------
[09:41:43.015]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:41:43.015]     INFO:    ----------------------------------------------------------------------
[09:41:43.633]     INFO: Expecting 208000 events.
[09:41:59.828]     INFO: 208000 events read in total (15668ms).
[09:41:59.836]     INFO: Test took 16811ms.
[09:42:00.360]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:00.728]     INFO: number of dead pixels (per ROC):     0    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:42:00.728]     INFO: number of red-efficiency pixels:   545  321  819 1512 1633 1421 1266  919  776 1105  838  910  873  505  110  115
[09:42:00.728]     INFO: number of X-ray hits detected:    217322 144808 227907 364675 377641 391779 382252 268091 266737 361885 330133 285846 298631 180737 73168 83438
[09:42:00.728]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:42:00.728]     INFO: number of Vcal hits detected:  207357 207596 206797 205939 205703 206007 206345 206744 207031 206617 206999 206890 206955 207375 207888 207883
[09:42:00.728]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.8 99.5 99.1 99.0 99.1 99.3 99.5 99.6 99.4 99.6 99.5 99.5 99.7 99.9 99.9
[09:42:00.728]     INFO: Vcal hit overall efficiency (%):  99.7 99.8 99.4 99.0 98.9 99.0 99.2 99.4 99.5 99.3 99.5 99.5 99.5 99.7 99.9 99.9
[09:42:00.728]     INFO: X-ray hit rate [MHz/cm2]:  63.7 42.4 66.8 106.9 110.7 114.8 112.0 78.6 78.2 106.1 96.8 83.8 87.5 53.0 21.4 24.5
[09:42:00.728]     INFO: PixTestHighRate::doXPixelAlive() done
[09:42:00.775]     INFO: PixTest::       pg_setup set to default.
[09:42:00.789]     INFO: enter test to run
[09:42:04.293]     INFO:   test: exit no parameter change
[09:42:04.647]    QUIET: Connection to board 33 closed.
[09:42:04.662]     INFO: pXar: this is the end, my friend