[15:36:33.942]     INFO: *** Welcome to pxar ***
[15:36:33.942]     INFO: *** Today: 2016/06/24
[15:36:33.958]     INFO: *** Version: v1.9.0-814-g7497
[15:36:33.959]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C15.dat
[15:36:34.387]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:36:34.387]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:36:34.387]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:36:34.462]     INFO:         clk: 4
[15:36:34.462]     INFO:         ctr: 4
[15:36:34.462]     INFO:         sda: 19
[15:36:34.462]     INFO:         tin: 9
[15:36:34.462]     INFO:         level: 15
[15:36:34.462]     INFO:         triggerdelay: 0
[15:36:34.462]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:36:34.462]     INFO: Log level: INFO
[15:36:34.476]    QUIET: Connection to board DTB_WREKRL opened.
[15:36:34.479]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[15:36:34.482]     INFO: RPC call hashes of host and DTB match: 398089610
[15:36:36.016]     INFO: DUT info: 
[15:36:36.016]     INFO: The DUT currently contains the following objects:
[15:36:36.016]     INFO:  2 TBM Cores tbm08c (2 ON)
[15:36:36.016]     INFO: 	TBM Core alpha (0): 7 registers set
[15:36:36.016]     INFO: 	TBM Core beta  (1): 7 registers set
[15:36:36.016]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:36:36.016]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.420]     INFO: enter 'restricted' command line mode
[15:36:36.420]     INFO: enter test to run
[15:36:42.313]     INFO:   test: PixelAlive no parameter change
[15:36:42.313]     INFO:   running: pixelalive
[15:36:42.322]     INFO:    ----------------------------------------------------------------------
[15:36:42.322]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:36:42.323]     INFO:    ----------------------------------------------------------------------
[15:36:42.644]     INFO: Expecting 41600 events.
[15:36:46.991]     INFO: 41600 events read in total (3629ms).
[15:36:47.156]     INFO: Test took 4831ms.
[15:36:47.165]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:47.437]     INFO: PixTestAlive::aliveTest() done
[15:36:47.437]     INFO: number of dead pixels (per ROC):     1    0    0    0    0    0    0    1    0    0    0    0    0    0    0    0
[15:36:47.469]     INFO: enter test to run
[15:37:16.777]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:37:16.777]     INFO:   running: highrate
[15:37:16.777]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:37:16.939]     INFO:    ----------------------------------------------------------------------
[15:37:16.939]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:37:16.939]     INFO:    ----------------------------------------------------------------------
[15:37:16.939]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:37:16.939]     INFO: edge/corner pixel THR is adjusted
[15:37:16.939]     INFO: PixTestHighRate::trimHotPixels: step 0...
[15:37:17.898]     INFO: Collecting data for 5 seconds...
[15:37:22.914]     INFO: Done with hot pixel readout
[15:37:34.304]     INFO: PixTest::       pg_setup set to default.
[15:37:34.305]     INFO: 7 hot pixels found in step 0
[15:37:35.312]     INFO: Collecting data for 5 seconds...
[15:37:40.328]     INFO: Done with hot pixel readout
[15:37:51.648]     INFO: PixTest::       pg_setup set to default.
[15:37:51.649]     INFO: 7 hot pixels found in step 1
[15:37:52.641]     INFO: Collecting data for 5 seconds...
[15:37:57.657]     INFO: Done with hot pixel readout
[15:38:08.999]     INFO: PixTest::       pg_setup set to default.
[15:38:08.000]     INFO: 5 hot pixels found in step 2
[15:38:09.988]     INFO: Collecting data for 5 seconds...
[15:38:15.004]     INFO: Done with hot pixel readout
[15:38:26.386]     INFO: PixTest::       pg_setup set to default.
[15:38:26.386]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:38:26.387]     INFO: 6 hot pixels found in step 3
[15:38:27.375]     INFO: Collecting data for 5 seconds...
[15:38:32.391]     INFO: Done with hot pixel readout
[15:38:43.726]     INFO: PixTest::       pg_setup set to default.
[15:38:43.727]     INFO: 2 hot pixels found in step 4
[15:38:44.715]     INFO: Collecting data for 5 seconds...
[15:38:49.731]     INFO: Done with hot pixel readout
[15:39:01.142]     INFO: PixTest::       pg_setup set to default.
[15:39:01.142]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:01.143]     INFO: 4 hot pixels found in step 5
[15:39:02.133]     INFO: Collecting data for 5 seconds...
[15:39:07.150]     INFO: Done with hot pixel readout
[15:39:18.291]     INFO: PixTest::       pg_setup set to default.
[15:39:18.291]     INFO: 2 hot pixels found in step 6
[15:39:19.281]     INFO: Collecting data for 5 seconds...
[15:39:24.298]     INFO: Done with hot pixel readout
[15:39:35.805]     INFO: PixTest::       pg_setup set to default.
[15:39:35.805]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:35.806]     INFO: 2 hot pixels found in step 7
[15:39:36.795]     INFO: Collecting data for 5 seconds...
[15:39:41.812]     INFO: Done with hot pixel readout
[15:39:52.769]     INFO: PixTest::       pg_setup set to default.
[15:39:52.769]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:52.770]     INFO: 3 hot pixels found in step 8
[15:39:53.758]     INFO: Collecting data for 5 seconds...
[15:39:58.777]     INFO: Done with hot pixel readout
[15:40:09.972]     INFO: PixTest::       pg_setup set to default.
[15:40:09.972]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:09.973]     INFO: 3 hot pixels found in step 9
[15:40:10.961]     INFO: Collecting data for 5 seconds...
[15:40:15.980]     INFO: Done with hot pixel readout
[15:40:26.969]     INFO: PixTest::       pg_setup set to default.
[15:40:26.969]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:26.970]     INFO: 3 hot pixels found in step 10
[15:40:27.959]     INFO: Collecting data for 5 seconds...
[15:40:32.977]     INFO: Done with hot pixel readout
[15:40:44.081]     INFO: PixTest::       pg_setup set to default.
[15:40:44.081]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:44.082]     INFO: 1 hot pixels found in step 11
[15:40:44.115]     INFO: 1 hot pixels could not be trimmed and have been masked.
[15:40:44.118]     INFO: PixTest::trimHotPixels() done
[15:40:44.119]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[15:40:44.124]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[15:40:44.130]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[15:40:44.136]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[15:40:44.141]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[15:40:44.147]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[15:40:44.152]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[15:40:44.158]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[15:40:44.163]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[15:40:44.168]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[15:40:44.173]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[15:40:44.179]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[15:40:44.184]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[15:40:44.189]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[15:40:44.195]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[15:40:44.200]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:40:44.205]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:40:44.217]     INFO: enter test to run
[15:41:30.943]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:41:30.944]     INFO:   running: highrate
[15:41:30.948]     INFO:    ----------------------------------------------------------------------
[15:41:30.948]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:41:30.948]     INFO:    ----------------------------------------------------------------------
[15:41:30.948]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:41:30.948]     INFO: edge/corner pixel THR is adjusted
[15:41:30.948]     INFO: PixTestHighRate::trimHotPixels: step 0...
[15:41:31.906]     INFO: Collecting data for 1 seconds...
[15:41:32.909]     INFO: Done with hot pixel readout
[15:41:36.843]     INFO: PixTest::       pg_setup set to default.
[15:41:36.844]     INFO: 0 hot pixels found in step 0
[15:41:36.849]     INFO: 0 hot pixels could not be trimmed and have been masked.
[15:41:36.931]     INFO: PixTest::trimHotPixels() done
[15:41:36.931]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[15:41:36.944]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[15:41:36.953]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[15:41:36.961]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[15:41:36.967]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[15:41:36.974]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[15:41:36.981]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[15:41:36.986]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[15:41:36.992]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[15:41:36.997]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[15:41:37.002]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[15:41:37.008]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[15:41:37.013]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[15:41:37.018]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[15:41:37.024]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[15:41:37.029]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:41:37.035]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:41:37.044]     INFO: enter test to run
[15:42:04.119]     INFO:   test: HighRate no parameter change
[15:42:04.119]     INFO:   running: highrate
[15:42:04.120]     INFO:    ----------------------------------------------------------------------
[15:42:04.120]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:42:04.121]     INFO:    ----------------------------------------------------------------------
[15:42:04.261]     INFO: Expecting 768 events.
[15:42:05.396]     INFO: 768 events read in total (419ms).
[15:42:05.396]     INFO: Test took 1268ms.
[15:42:06.199]     INFO: Expecting 41600 events.
[15:42:09.302]     INFO: 41600 events read in total (2576ms).
[15:42:09.303]     INFO: Test took 3901ms.
[15:42:09.333]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:10.060]     INFO: Expecting 41600 events.
[15:42:13.232]     INFO: 41600 events read in total (2646ms).
[15:42:13.233]     INFO: Test took 3884ms.
[15:42:13.265]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:13.991]     INFO: Expecting 41600 events.
[15:42:17.298]     INFO: 41600 events read in total (2780ms).
[15:42:17.299]     INFO: Test took 4017ms.
[15:42:17.331]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:18.052]     INFO: Expecting 41600 events.
[15:42:21.296]     INFO: 41600 events read in total (2717ms).
[15:42:21.297]     INFO: Test took 3950ms.
[15:42:21.329]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:22.053]     INFO: Expecting 41600 events.
[15:42:25.323]     INFO: 41600 events read in total (2743ms).
[15:42:25.323]     INFO: Test took 3978ms.
[15:42:25.355]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:26.083]     INFO: Expecting 41600 events.
[15:42:29.363]     INFO: 41600 events read in total (2753ms).
[15:42:29.364]     INFO: Test took 3992ms.
[15:42:29.396]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:30.125]     INFO: Expecting 41600 events.
[15:42:33.391]     INFO: 41600 events read in total (2740ms).
[15:42:33.392]     INFO: Test took 3979ms.
[15:42:33.424]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:34.146]     INFO: Expecting 41600 events.
[15:42:37.431]     INFO: 41600 events read in total (2758ms).
[15:42:37.432]     INFO: Test took 3992ms.
[15:42:37.464]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:38.175]     INFO: Expecting 41600 events.
[15:42:41.454]     INFO: 41600 events read in total (2752ms).
[15:42:41.455]     INFO: Test took 3975ms.
[15:42:41.487]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:42.207]     INFO: Expecting 41600 events.
[15:42:45.427]     INFO: 41600 events read in total (2693ms).
[15:42:45.428]     INFO: Test took 3925ms.
[15:42:45.460]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:46.187]     INFO: Expecting 41600 events.
[15:42:49.390]     INFO: 41600 events read in total (2676ms).
[15:42:49.391]     INFO: Test took 3915ms.
[15:42:49.422]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:50.152]     INFO: Expecting 41600 events.
[15:42:53.352]     INFO: 41600 events read in total (2673ms).
[15:42:53.353]     INFO: Test took 3914ms.
[15:42:53.384]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:54.115]     INFO: Expecting 41600 events.
[15:42:57.346]     INFO: 41600 events read in total (2704ms).
[15:42:57.347]     INFO: Test took 3945ms.
[15:42:57.378]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:58.108]     INFO: Expecting 41600 events.
[15:43:01.328]     INFO: 41600 events read in total (2693ms).
[15:43:01.329]     INFO: Test took 3936ms.
[15:43:01.359]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:02.086]     INFO: Expecting 41600 events.
[15:43:05.291]     INFO: 41600 events read in total (2678ms).
[15:43:05.292]     INFO: Test took 3916ms.
[15:43:05.322]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:06.054]     INFO: Expecting 41600 events.
[15:43:09.251]     INFO: 41600 events read in total (2670ms).
[15:43:09.252]     INFO: Test took 3912ms.
[15:43:09.283]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:10.014]     INFO: Expecting 41600 events.
[15:43:13.220]     INFO: 41600 events read in total (2679ms).
[15:43:13.221]     INFO: Test took 3920ms.
[15:43:13.252]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:13.982]     INFO: Expecting 41600 events.
[15:43:17.191]     INFO: 41600 events read in total (2682ms).
[15:43:17.192]     INFO: Test took 3923ms.
[15:43:17.223]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:17.951]     INFO: Expecting 41600 events.
[15:43:21.130]     INFO: 41600 events read in total (2652ms).
[15:43:21.131]     INFO: Test took 3890ms.
[15:43:21.162]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:21.894]     INFO: Expecting 41600 events.
[15:43:24.940]     INFO: 41600 events read in total (2519ms).
[15:43:24.941]     INFO: Test took 3762ms.
[15:43:24.970]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:25.342]     INFO: enter test to run
[15:43:29.719]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[15:43:29.719]     INFO:   running: xray
[15:43:29.720]     INFO:    ----------------------------------------------------------------------
[15:43:29.720]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[15:43:29.720]     INFO:    ----------------------------------------------------------------------
[15:43:30.683]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[15:43:42.604]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:44:11.971]     INFO: Resuming triggers.
[15:44:23.896]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:44:52.931]     INFO: Resuming triggers.
[15:45:04.855]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:45:34.100]     INFO: Resuming triggers.
[15:45:46.026]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:46:15.301]     INFO: Resuming triggers.
[15:46:27.228]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:46:56.519]     INFO: Resuming triggers.
[15:47:08.448]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:47:37.738]     INFO: Resuming triggers.
[15:47:49.660]     INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:48:18.885]     INFO: Resuming triggers.
[15:48:30.813]     INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:48:59.997]     INFO: Resuming triggers.
[15:49:04.907]     INFO: data taking finished, elapsed time: 100 seconds.
[15:49:17.222]     INFO: PixTest::       pg_setup set to default.
[15:49:17.226]     INFO: PixTestXray::doPhRun() done
[15:49:17.361]     INFO: enter test to run
[15:50:00.020]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[15:50:00.020]     INFO:   running: xray
[15:50:00.021]     INFO:    ----------------------------------------------------------------------
[15:50:00.021]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[15:50:00.021]     INFO:    ----------------------------------------------------------------------
[15:50:00.985]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[15:50:08.221]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:50:38.511]     INFO: Resuming triggers.
[15:50:45.750]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[15:51:16.920]     INFO: Resuming triggers.
[15:51:24.155]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:51:54.953]     INFO: Resuming triggers.
[15:52:02.194]     INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[15:52:33.228]     INFO: Resuming triggers.
[15:52:40.461]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:53:11.986]     INFO: Resuming triggers.
[15:53:19.220]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:53:50.538]     INFO: Resuming triggers.
[15:53:57.774]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[15:54:28.462]     INFO: Resuming triggers.
[15:54:35.696]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:55:05.001]     INFO: Resuming triggers.
[15:55:13.235]     INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[15:55:43.415]     INFO: Resuming triggers.
[15:55:50.653]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:56:20.992]     INFO: Resuming triggers.
[15:56:28.228]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:56:58.551]     INFO: Resuming triggers.
[15:57:05.790]     INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:57:35.950]     INFO: Resuming triggers.
[15:57:43.181]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:58:13.193]     INFO: Resuming triggers.
[15:58:19.461]     INFO: data taking finished, elapsed time: 100 seconds.
[15:58:45.916]     INFO: PixTest::       pg_setup set to default.
[15:58:45.919]     INFO: PixTestXray::doPhRun() done
[15:58:46.069]     INFO: enter test to run
[15:59:08.440]     INFO:   test: HighRate no parameter change
[15:59:08.440]     INFO:   running: highrate
[15:59:08.442]     INFO:    ----------------------------------------------------------------------
[15:59:08.442]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:59:08.442]     INFO:    ----------------------------------------------------------------------
[15:59:08.583]     INFO: Expecting 768 events.
[15:59:09.716]     INFO: 768 events read in total (418ms).
[15:59:09.716]     INFO: Test took 1267ms.
[15:59:10.520]     INFO: Expecting 41600 events.
[15:59:13.581]     INFO: 41600 events read in total (2534ms).
[15:59:13.582]     INFO: Test took 3858ms.
[15:59:13.612]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:14.347]     INFO: Expecting 41600 events.
[15:59:17.514]     INFO: 41600 events read in total (2641ms).
[15:59:17.515]     INFO: Test took 3885ms.
[15:59:17.547]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:18.273]     INFO: Expecting 41600 events.
[15:59:21.469]     INFO: 41600 events read in total (2669ms).
[15:59:21.470]     INFO: Test took 3905ms.
[15:59:21.502]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:22.232]     INFO: Expecting 41600 events.
[15:59:25.447]     INFO: 41600 events read in total (2688ms).
[15:59:25.448]     INFO: Test took 3929ms.
[15:59:25.479]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:26.205]     INFO: Expecting 41600 events.
[15:59:29.410]     INFO: 41600 events read in total (2678ms).
[15:59:29.411]     INFO: Test took 3914ms.
[15:59:29.443]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:30.172]     INFO: Expecting 41600 events.
[15:59:33.380]     INFO: 41600 events read in total (2681ms).
[15:59:33.381]     INFO: Test took 3921ms.
[15:59:33.412]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:34.139]     INFO: Expecting 41600 events.
[15:59:37.376]     INFO: 41600 events read in total (2710ms).
[15:59:37.377]     INFO: Test took 3948ms.
[15:59:37.408]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:38.134]     INFO: Expecting 41600 events.
[15:59:41.340]     INFO: 41600 events read in total (2679ms).
[15:59:41.341]     INFO: Test took 3916ms.
[15:59:41.372]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:42.102]     INFO: Expecting 41600 events.
[15:59:45.331]     INFO: 41600 events read in total (2702ms).
[15:59:45.332]     INFO: Test took 3942ms.
[15:59:45.363]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:46.090]     INFO: Expecting 41600 events.
[15:59:49.283]     INFO: 41600 events read in total (2666ms).
[15:59:49.283]     INFO: Test took 3902ms.
[15:59:49.314]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:50.046]     INFO: Expecting 41600 events.
[15:59:53.218]     INFO: 41600 events read in total (2645ms).
[15:59:53.219]     INFO: Test took 3886ms.
[15:59:53.250]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:53.980]     INFO: Expecting 41600 events.
[15:59:57.211]     INFO: 41600 events read in total (2704ms).
[15:59:57.212]     INFO: Test took 3945ms.
[15:59:57.244]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:57.971]     INFO: Expecting 41600 events.
[16:00:01.162]     INFO: 41600 events read in total (2664ms).
[16:00:01.163]     INFO: Test took 3902ms.
[16:00:01.195]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:01.924]     INFO: Expecting 41600 events.
[16:00:05.100]     INFO: 41600 events read in total (2649ms).
[16:00:05.101]     INFO: Test took 3888ms.
[16:00:05.133]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:05.863]     INFO: Expecting 41600 events.
[16:00:09.081]     INFO: 41600 events read in total (2691ms).
[16:00:09.082]     INFO: Test took 3930ms.
[16:00:09.113]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:09.841]     INFO: Expecting 41600 events.
[16:00:12.993]     INFO: 41600 events read in total (2625ms).
[16:00:12.994]     INFO: Test took 3862ms.
[16:00:13.026]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:13.753]     INFO: Expecting 41600 events.
[16:00:16.965]     INFO: 41600 events read in total (2685ms).
[16:00:16.966]     INFO: Test took 3923ms.
[16:00:16.998]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:17.726]     INFO: Expecting 41600 events.
[16:00:20.913]     INFO: 41600 events read in total (2660ms).
[16:00:20.914]     INFO: Test took 3898ms.
[16:00:20.945]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:21.677]     INFO: Expecting 41600 events.
[16:00:24.885]     INFO: 41600 events read in total (2682ms).
[16:00:24.886]     INFO: Test took 3923ms.
[16:00:24.917]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:25.647]     INFO: Expecting 41600 events.
[16:00:28.687]     INFO: 41600 events read in total (2513ms).
[16:00:28.688]     INFO: Test took 3753ms.
[16:00:28.718]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:29.095]     INFO: enter test to run
[16:01:36.447]     INFO:   test: HighRate no parameter change
[16:01:36.447]     INFO:   running: highrate
[16:01:36.448]     INFO:    ----------------------------------------------------------------------
[16:01:36.448]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:01:36.449]     INFO:    ----------------------------------------------------------------------
[16:01:37.063]     INFO: Expecting 208000 events.
[16:01:48.794]     INFO: 208000 events read in total (11204ms).
[16:01:48.797]     INFO: Test took 12340ms.
[16:01:48.929]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:49.177]     INFO: number of dead pixels (per ROC):     1    0    0    0    0    0    0    1    0    0    0    0    0    0    0    0
[16:01:49.177]     INFO: number of red-efficiency pixels:    56   41   81  110  140  136  123   87   71  105  108   81   76   46   17   23
[16:01:49.177]     INFO: number of X-ray hits detected:    57448 35434 57304 92078 100514 104073 103639 75683 69305 97736 95705 80629 77674 48159 17223 18908
[16:01:49.177]     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:01:49.177]     INFO: number of Vcal hits detected:  207894 207956 207919 207886 207858 207860 207872 207857 207928 207893 207884 207919 207922 207954 207983 207977
[16:01:49.177]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[16:01:49.177]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[16:01:49.177]     INFO: X-ray hit rate [MHz/cm2]:  16.8 10.4 16.8 27.0 29.5 30.5 30.4 22.2 20.3 28.6 28.1 23.6 22.8 14.1 5.0 5.5
[16:01:49.177]     INFO: PixTestHighRate::doXPixelAlive() done
[16:01:49.227]     INFO: PixTest::       pg_setup set to default.
[16:01:49.239]     INFO: enter test to run
[16:02:53.559]     INFO:   test: HighRate no parameter change
[16:02:53.559]     INFO:   running: highrate
[16:02:53.560]     INFO:    ----------------------------------------------------------------------
[16:02:53.560]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:53.560]     INFO:    ----------------------------------------------------------------------
[16:02:54.181]     INFO: Expecting 208000 events.
[16:03:07.801]     INFO: 208000 events read in total (13093ms).
[16:03:07.805]     INFO: Test took 14236ms.
[16:03:08.075]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:08.372]     INFO: number of dead pixels (per ROC):     1    0    0    0    0    0    0    1    0    0    0    0    0    0    0    0
[16:03:08.372]     INFO: number of red-efficiency pixels:   177   97  181  303  387  458  429  261  192  318  275  285  194  129   37   39
[16:03:08.372]     INFO: number of X-ray hits detected:    115542 71750 113929 185146 201570 208822 208731 152551 138546 194547 190887 161429 157812 95310 34806 38012
[16:03:08.372]     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:03:08.372]     INFO: number of Vcal hits detected:  207759 207901 207809 207687 207584 207509 207532 207669 207807 207667 207701 207703 207800 207867 207963 207961
[16:03:08.372]     INFO: Vcal hit fiducial efficiency (%):  99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:03:08.372]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:03:08.372]     INFO: X-ray hit rate [MHz/cm2]:  33.9 21.0 33.4 54.3 59.1 61.2 61.2 44.7 40.6 57.0 56.0 47.3 46.3 27.9 10.2 11.1
[16:03:08.372]     INFO: PixTestHighRate::doXPixelAlive() done
[16:03:08.419]     INFO: PixTest::       pg_setup set to default.
[16:03:08.432]     INFO: enter test to run
[16:03:41.655]     INFO:   test: HighRate no parameter change
[16:03:41.655]     INFO:   running: highrate
[16:03:41.656]     INFO:    ----------------------------------------------------------------------
[16:03:41.656]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:03:41.656]     INFO:    ----------------------------------------------------------------------
[16:03:42.275]     INFO: Expecting 208000 events.
[16:03:57.223]     INFO: 208000 events read in total (14421ms).
[16:03:57.230]     INFO: Test took 15565ms.
[16:03:57.639]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:57.982]     INFO: number of dead pixels (per ROC):     1    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[16:03:57.982]     INFO: number of red-efficiency pixels:   378  222  385  840  988 1058 1076  669  388  755  647  636  449  281   54   75
[16:03:57.982]     INFO: number of X-ray hits detected:    178843 112673 176700 287201 313226 325053 322889 235836 215419 303308 297592 250046 244348 149238 54384 59613
[16:03:57.982]     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:03:57.982]     INFO: number of Vcal hits detected:  207515 207767 207568 207018 206794 206711 206672 207148 207581 207143 207219 207261 207508 207699 207946 207925
[16:03:57.982]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.8 99.6 99.5 99.4 99.4 99.6 99.8 99.6 99.7 99.7 99.8 99.9 100.0 100.0
[16:03:57.982]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.8 99.5 99.4 99.4 99.4 99.6 99.8 99.6 99.6 99.6 99.8 99.9 100.0 100.0
[16:03:57.982]     INFO: X-ray hit rate [MHz/cm2]:  52.4 33.0 51.8 84.2 91.8 95.3 94.6 69.1 63.1 88.9 87.2 73.3 71.6 43.7 15.9 17.5
[16:03:57.982]     INFO: PixTestHighRate::doXPixelAlive() done
[16:03:58.029]     INFO: PixTest::       pg_setup set to default.
[16:03:58.044]     INFO: enter test to run
[16:04:02.127]     INFO:   test: exit no parameter change
[16:04:02.442]    QUIET: Connection to board 33 closed.
[16:04:02.457]     INFO: pXar: this is the end, my friend