[16:05:12.225]     INFO: *** Welcome to pxar ***
[16:05:12.225]     INFO: *** Today: 2016/09/15
[16:05:14.412]     INFO: *** Version: v1.9.0-818-g96727
[16:05:14.412]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//dacParameters35_C15.dat
[16:05:14.498]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:05:14.498]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//defaultMaskFile.dat
[16:05:14.501]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C15.dat
[16:05:14.634]     INFO:         clk: 4
[16:05:14.634]     INFO:         ctr: 4
[16:05:14.634]     INFO:         sda: 19
[16:05:14.634]     INFO:         tin: 9
[16:05:14.634]     INFO:         level: 15
[16:05:14.634]     INFO:         triggerdelay: 0
[16:05:14.634]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:05:14.634]     INFO: Log level: INFO
[16:05:14.678]    QUIET: Connection to board DTB_WREKRL opened.
[16:05:14.681]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[16:05:14.684]     INFO: RPC call hashes of host and DTB match: 398089610
[16:05:16.236]     INFO: DUT info: 
[16:05:16.236]     INFO: The DUT currently contains the following objects:
[16:05:16.237]     INFO:  2 TBM Cores tbm08c (2 ON)
[16:05:16.237]     INFO: 	TBM Core alpha (0): 7 registers set
[16:05:16.237]     INFO: 	TBM Core beta  (1): 7 registers set
[16:05:16.237]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:05:16.237]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.237]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:05:16.728]     INFO: enter 'restricted' command line mode
[16:05:16.728]     INFO: enter test to run
[16:05:20.830]     INFO:   test: PixelAlive no parameter change
[16:05:20.830]     INFO:   running: pixelalive
[16:05:20.915]     INFO:    ----------------------------------------------------------------------
[16:05:20.915]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:05:20.915]     INFO:    ----------------------------------------------------------------------
[16:05:21.237]     INFO: Expecting 41600 events.
[16:05:25.711]     INFO: 41600 events read in total (3755ms).
[16:05:25.875]     INFO: Test took 4956ms.
[16:05:25.888]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:26.699]     INFO: PixTestAlive::aliveTest() done
[16:05:26.700]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    2    0    0    2    0    0    0    0    0    0
[16:05:26.948]     INFO: enter test to run
[16:07:04.413]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:07:04.413]     INFO:   running: highrate
[16:07:04.476]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:07:04.933]     INFO:    ----------------------------------------------------------------------
[16:07:04.933]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:07:04.933]     INFO:    ----------------------------------------------------------------------
[16:07:04.933]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:07:04.933]     INFO: edge/corner pixel THR is adjusted
[16:07:04.933]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:07:05.891]     INFO: Collecting data for 5 seconds...
[16:07:10.911]     INFO: Done with hot pixel readout
[16:07:23.057]     INFO: PixTest::       pg_setup set to default.
[16:07:23.057]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:23.058]     INFO: 17 hot pixels found in step 0
[16:07:24.052]     INFO: Collecting data for 5 seconds...
[16:07:29.070]     INFO: Done with hot pixel readout
[16:07:41.196]     INFO: PixTest::       pg_setup set to default.
[16:07:41.197]     INFO: 23 hot pixels found in step 1
[16:07:42.196]     INFO: Collecting data for 5 seconds...
[16:07:47.214]     INFO: Done with hot pixel readout
[16:07:59.435]     INFO: PixTest::       pg_setup set to default.
[16:07:59.435]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:07:59.435]     INFO: 17 hot pixels found in step 2
[16:08:00.430]     INFO: Collecting data for 5 seconds...
[16:08:05.448]     INFO: Done with hot pixel readout
[16:08:17.485]     INFO: PixTest::       pg_setup set to default.
[16:08:17.486]     INFO: 16 hot pixels found in step 3
[16:08:18.480]     INFO: Collecting data for 5 seconds...
[16:08:23.498]     INFO: Done with hot pixel readout
[16:08:35.899]     INFO: PixTest::       pg_setup set to default.
[16:08:35.900]     INFO: 16 hot pixels found in step 4
[16:08:36.895]     INFO: Collecting data for 5 seconds...
[16:08:41.914]     INFO: Done with hot pixel readout
[16:08:54.563]     INFO: PixTest::       pg_setup set to default.
[16:08:54.564]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:08:54.564]     INFO: 13 hot pixels found in step 5
[16:08:55.559]     INFO: Collecting data for 5 seconds...
[16:09:00.578]     INFO: Done with hot pixel readout
[16:09:13.124]     INFO: PixTest::       pg_setup set to default.
[16:09:13.124]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:09:13.124]     INFO: 20 hot pixels found in step 6
[16:09:14.119]     INFO: Collecting data for 5 seconds...
[16:09:19.138]     INFO: Done with hot pixel readout
[16:09:31.432]     INFO: PixTest::       pg_setup set to default.
[16:09:31.433]     INFO: 11 hot pixels found in step 7
[16:09:32.426]     INFO: Collecting data for 5 seconds...
[16:09:37.443]     INFO: Done with hot pixel readout
[16:09:49.505]     INFO: PixTest::       pg_setup set to default.
[16:09:49.506]     INFO: 14 hot pixels found in step 8
[16:09:50.500]     INFO: Collecting data for 5 seconds...
[16:09:55.517]     INFO: Done with hot pixel readout
[16:10:07.865]     INFO: PixTest::       pg_setup set to default.
[16:10:07.865]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:10:07.866]     INFO: 11 hot pixels found in step 9
[16:10:08.860]     INFO: Collecting data for 5 seconds...
[16:10:13.880]     INFO: Done with hot pixel readout
[16:10:26.335]     INFO: PixTest::       pg_setup set to default.
[16:10:26.336]     INFO: 10 hot pixels found in step 10
[16:10:27.331]     INFO: Collecting data for 5 seconds...
[16:10:32.351]     INFO: Done with hot pixel readout
[16:10:44.808]     INFO: PixTest::       pg_setup set to default.
[16:10:44.808]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:10:44.808]     INFO: 11 hot pixels found in step 11
[16:10:45.803]     INFO: Collecting data for 5 seconds...
[16:10:50.823]     INFO: Done with hot pixel readout
[16:11:03.083]     INFO: PixTest::       pg_setup set to default.
[16:11:03.084]     INFO: 12 hot pixels found in step 12
[16:11:04.080]     INFO: Collecting data for 5 seconds...
[16:11:09.096]     INFO: Done with hot pixel readout
[16:11:21.234]     INFO: PixTest::       pg_setup set to default.
[16:11:21.234]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:11:21.235]     INFO: 12 hot pixels found in step 13
[16:11:22.229]     INFO: Collecting data for 5 seconds...
[16:11:27.245]     INFO: Done with hot pixel readout
[16:11:39.378]     INFO: PixTest::       pg_setup set to default.
[16:11:39.378]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[16:11:39.379]     INFO: 15 hot pixels found in step 14
[16:11:39.417]     INFO: 15 hot pixels could not be trimmed and have been masked.
[16:11:39.430]     INFO: PixTest::trimHotPixels() done
[16:11:39.430]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C0.dat
[16:11:39.442]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C1.dat
[16:11:39.450]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C2.dat
[16:11:39.455]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C3.dat
[16:11:39.460]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C4.dat
[16:11:39.465]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C5.dat
[16:11:39.471]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C6.dat
[16:11:39.476]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C7.dat
[16:11:39.481]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C8.dat
[16:11:39.486]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C9.dat
[16:11:39.492]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C10.dat
[16:11:39.497]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C11.dat
[16:11:39.502]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C12.dat
[16:11:39.507]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C13.dat
[16:11:39.513]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C14.dat
[16:11:39.518]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C15.dat
[16:11:39.523]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//defaultMaskFile.dat
[16:11:39.533]     INFO: enter test to run
[16:14:02.250]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:14:02.250]     INFO:   running: highrate
[16:14:02.255]     INFO:    ----------------------------------------------------------------------
[16:14:02.255]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:14:02.255]     INFO:    ----------------------------------------------------------------------
[16:14:02.255]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:14:02.255]     INFO: edge/corner pixel THR is adjusted
[16:14:02.255]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:14:03.213]     INFO: Collecting data for 1 seconds...
[16:14:04.217]     INFO: Done with hot pixel readout
[16:14:08.358]     INFO: PixTest::       pg_setup set to default.
[16:14:08.359]     INFO: 0 hot pixels found in step 0
[16:14:08.364]     INFO: 0 hot pixels could not be trimmed and have been masked.
[16:14:08.452]     INFO: PixTest::trimHotPixels() done
[16:14:08.452]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C0.dat
[16:14:08.479]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C1.dat
[16:14:08.486]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C2.dat
[16:14:08.491]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C3.dat
[16:14:08.497]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C4.dat
[16:14:08.502]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C5.dat
[16:14:08.507]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C6.dat
[16:14:08.512]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C7.dat
[16:14:08.518]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C8.dat
[16:14:08.523]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C9.dat
[16:14:08.528]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C10.dat
[16:14:08.533]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C11.dat
[16:14:08.538]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C12.dat
[16:14:08.544]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C13.dat
[16:14:08.549]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C14.dat
[16:14:08.555]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//trimParameters35_C15.dat
[16:14:08.560]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-24_FPIXTest-17C-FNAL-160913-1217-150V_2016-09-13_12h17m_1473787067/000_FPIXTest_p17//defaultMaskFile.dat
[16:14:08.569]     INFO: enter test to run
[16:14:39.434]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[16:14:39.434]     INFO:   running: xray
[16:14:39.435]     INFO:    ----------------------------------------------------------------------
[16:14:39.435]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:14:39.435]     INFO:    ----------------------------------------------------------------------
[16:14:40.413]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:14:51.668]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:15:21.456]     INFO: Resuming triggers.
[16:15:32.716]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:16:02.762]     INFO: Resuming triggers.
[16:16:14.020]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:16:43.917]     INFO: Resuming triggers.
[16:16:55.177]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:17:25.012]     INFO: Resuming triggers.
[16:17:36.269]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:18:06.215]     INFO: Resuming triggers.
[16:18:17.471]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:18:48.076]     INFO: Resuming triggers.
[16:18:59.333]     INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:19:28.860]     INFO: Resuming triggers.
[16:19:40.116]     INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:20:10.207]     INFO: Resuming triggers.
[16:20:20.486]     INFO: data taking finished, elapsed time: 100 seconds.
[16:20:48.410]     INFO: PixTest::       pg_setup set to default.
[16:20:48.413]     INFO: PixTestXray::doPhRun() done
[16:20:48.622]     INFO: enter test to run
[16:21:49.687]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[16:21:49.688]     INFO:   running: xray
[16:21:49.689]     INFO:    ----------------------------------------------------------------------
[16:21:49.689]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:21:49.689]     INFO:    ----------------------------------------------------------------------
[16:21:50.652]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:21:57.131]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:22:29.085]     INFO: Resuming triggers.
[16:22:35.559]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:23:07.521]     INFO: Resuming triggers.
[16:23:13.997]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:23:45.925]     INFO: Resuming triggers.
[16:23:52.402]     INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[16:24:23.119]     INFO: Resuming triggers.
[16:24:29.596]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:25:00.361]     INFO: Resuming triggers.
[16:25:06.846]     INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[16:25:37.631]     INFO: Resuming triggers.
[16:25:44.111]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:26:14.824]     INFO: Resuming triggers.
[16:26:21.307]     INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[16:26:52.361]     INFO: Resuming triggers.
[16:26:58.846]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[16:27:29.534]     INFO: Resuming triggers.
[16:27:36.016]     INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[16:28:06.736]     INFO: Resuming triggers.
[16:28:13.215]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[16:28:44.191]     INFO: Resuming triggers.
[16:28:50.674]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[16:29:21.422]     INFO: Resuming triggers.
[16:29:27.900]     INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:29:58.552]     INFO: Resuming triggers.
[16:30:05.029]     INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:30:35.767]     INFO: Resuming triggers.
[16:30:42.242]     INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[16:31:13.018]     INFO: Resuming triggers.
[16:31:16.170]     INFO: data taking finished, elapsed time: 100 seconds.
[16:31:31.682]     INFO: PixTest::       pg_setup set to default.
[16:31:31.685]     INFO: PixTestXray::doPhRun() done
[16:31:31.837]     INFO: enter test to run
[16:32:35.227]     INFO:   test: HighRate no parameter change
[16:32:35.227]     INFO:   running: highrate
[16:32:35.245]     INFO:    ----------------------------------------------------------------------
[16:32:35.245]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:32:35.245]     INFO:    ----------------------------------------------------------------------
[16:32:35.400]     INFO: Expecting 768 events.
[16:32:36.572]     INFO: 768 events read in total (457ms).
[16:32:36.572]     INFO: Test took 1306ms.
[16:32:37.375]     INFO: Expecting 41600 events.
[16:32:40.501]     INFO: 41600 events read in total (2599ms).
[16:32:40.502]     INFO: Test took 3908ms.
[16:32:40.539]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:41.264]     INFO: Expecting 41600 events.
[16:32:44.482]     INFO: 41600 events read in total (2691ms).
[16:32:44.483]     INFO: Test took 3924ms.
[16:32:44.520]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:45.234]     INFO: Expecting 41600 events.
[16:32:48.545]     INFO: 41600 events read in total (2784ms).
[16:32:48.546]     INFO: Test took 4008ms.
[16:32:48.584]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:49.283]     INFO: Expecting 41600 events.
[16:32:52.604]     INFO: 41600 events read in total (2794ms).
[16:32:52.605]     INFO: Test took 4003ms.
[16:32:52.643]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:53.358]     INFO: Expecting 41600 events.
[16:32:56.637]     INFO: 41600 events read in total (2753ms).
[16:32:56.638]     INFO: Test took 3977ms.
[16:32:56.675]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:57.382]     INFO: Expecting 41600 events.
[16:33:00.718]     INFO: 41600 events read in total (2809ms).
[16:33:00.719]     INFO: Test took 4026ms.
[16:33:00.756]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:01.465]     INFO: Expecting 41600 events.
[16:33:04.763]     INFO: 41600 events read in total (2771ms).
[16:33:04.764]     INFO: Test took 3989ms.
[16:33:04.807]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:05.515]     INFO: Expecting 41600 events.
[16:33:08.853]     INFO: 41600 events read in total (2811ms).
[16:33:08.854]     INFO: Test took 4028ms.
[16:33:08.890]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:09.605]     INFO: Expecting 41600 events.
[16:33:12.996]     INFO: 41600 events read in total (2864ms).
[16:33:12.997]     INFO: Test took 4088ms.
[16:33:13.034]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:13.751]     INFO: Expecting 41600 events.
[16:33:17.071]     INFO: 41600 events read in total (2793ms).
[16:33:17.072]     INFO: Test took 4019ms.
[16:33:17.109]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:17.813]     INFO: Expecting 41600 events.
[16:33:21.127]     INFO: 41600 events read in total (2788ms).
[16:33:21.128]     INFO: Test took 4000ms.
[16:33:21.166]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:21.870]     INFO: Expecting 41600 events.
[16:33:25.191]     INFO: 41600 events read in total (2794ms).
[16:33:25.192]     INFO: Test took 4007ms.
[16:33:25.230]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:25.946]     INFO: Expecting 41600 events.
[16:33:29.255]     INFO: 41600 events read in total (2782ms).
[16:33:29.256]     INFO: Test took 4008ms.
[16:33:29.292]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:29.005]     INFO: Expecting 41600 events.
[16:33:33.312]     INFO: 41600 events read in total (2780ms).
[16:33:33.313]     INFO: Test took 4001ms.
[16:33:33.350]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:34.066]     INFO: Expecting 41600 events.
[16:33:37.329]     INFO: 41600 events read in total (2737ms).
[16:33:37.330]     INFO: Test took 3961ms.
[16:33:37.367]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:38.077]     INFO: Expecting 41600 events.
[16:33:41.404]     INFO: 41600 events read in total (2800ms).
[16:33:41.405]     INFO: Test took 4020ms.
[16:33:41.441]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:42.161]     INFO: Expecting 41600 events.
[16:33:45.342]     INFO: 41600 events read in total (2654ms).
[16:33:45.343]     INFO: Test took 3883ms.
[16:33:45.382]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:46.090]     INFO: Expecting 41600 events.
[16:33:49.314]     INFO: 41600 events read in total (2697ms).
[16:33:49.315]     INFO: Test took 3915ms.
[16:33:49.353]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:50.071]     INFO: Expecting 41600 events.
[16:33:53.414]     INFO: 41600 events read in total (2816ms).
[16:33:53.415]     INFO: Test took 4044ms.
[16:33:53.451]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:54.169]     INFO: Expecting 41600 events.
[16:33:57.383]     INFO: 41600 events read in total (2687ms).
[16:33:57.384]     INFO: Test took 3914ms.
[16:33:57.421]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:33:57.777]     INFO: enter test to run
[16:34:06.906]     INFO:   test: HighRate no parameter change
[16:34:06.906]     INFO:   running: highrate
[16:34:06.907]     INFO:    ----------------------------------------------------------------------
[16:34:06.907]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:34:06.907]     INFO:    ----------------------------------------------------------------------
[16:34:07.524]     INFO: Expecting 208000 events.
[16:34:19.650]     INFO: 208000 events read in total (11599ms).
[16:34:19.653]     INFO: Test took 12739ms.
[16:34:19.810]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:34:20.066]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    2    0    0    2    0    0    0    0    0    0
[16:34:20.066]     INFO: number of red-efficiency pixels:    90   44   83  125  170  195  151  102  101  136  166  110  115   63   31   38
[16:34:20.066]     INFO: number of X-ray hits detected:    69736 41785 67374 105434 113341 118733 113507 81938 83829 112838 117273 94432 98905 60695 24365 26776
[16:34:20.066]     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:34:20.066]     INFO: number of Vcal hits detected:  207909 207956 207917 207873 207825 207801 207746 207897 207891 207762 207832 207887 207880 207936 207969 207962
[16:34:20.067]     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 99.9 99.9 100.0 100.0 100.0
[16:34:20.067]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:34:20.067]     INFO: X-ray hit rate [MHz/cm2]:  20.4 12.2 19.7 30.9 33.2 34.8 33.3 24.0 24.6 33.1 34.4 27.7 29.0 17.8 7.1 7.8
[16:34:20.067]     INFO: PixTestHighRate::doXPixelAlive() done
[16:34:20.111]     INFO: PixTest::       pg_setup set to default.
[16:34:20.128]     INFO: enter test to run
[16:34:48.906]     INFO:   test: HighRate no parameter change
[16:34:48.906]     INFO:   running: highrate
[16:34:48.907]     INFO:    ----------------------------------------------------------------------
[16:34:48.907]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:34:48.907]     INFO:    ----------------------------------------------------------------------
[16:34:49.527]     INFO: Expecting 208000 events.
[16:35:03.811]     INFO: 208000 events read in total (13757ms).
[16:35:03.817]     INFO: Test took 14901ms.
[16:35:04.137]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:04.449]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    2    0    0    2    0    0    0    0    0    0
[16:35:04.449]     INFO: number of red-efficiency pixels:   259  114  267  446  561  627  540  308  362  410  615  398  332  186   57   59
[16:35:04.449]     INFO: number of X-ray hits detected:    143435 86522 139273 216730 233187 245810 234719 169569 174120 231986 240805 194742 203010 125053 51084 56356
[16:35:04.449]     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:35:04.449]     INFO: number of Vcal hits detected:  207722 207885 207707 207513 207392 207284 207304 207671 207617 207457 207304 207566 207643 207808 207940 207941
[16:35:04.449]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[16:35:04.449]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[16:35:04.449]     INFO: X-ray hit rate [MHz/cm2]:  42.0 25.4 40.8 63.5 68.3 72.0 68.8 49.7 51.0 68.0 70.6 57.1 59.5 36.7 15.0 16.5
[16:35:04.449]     INFO: PixTestHighRate::doXPixelAlive() done
[16:35:04.495]     INFO: PixTest::       pg_setup set to default.
[16:35:04.508]     INFO: enter test to run
[16:35:59.089]     INFO:   test: HighRate no parameter change
[16:35:59.089]     INFO:   running: highrate
[16:35:59.090]     INFO:    ----------------------------------------------------------------------
[16:35:59.090]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:35:59.090]     INFO:    ----------------------------------------------------------------------
[16:35:59.711]     INFO: Expecting 208000 events.
[16:36:16.278]     INFO: 208000 events read in total (16040ms).
[16:36:16.286]     INFO: Test took 17186ms.
[16:36:16.770]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:17.132]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    2    0    0    2    0    0    0    0    0    0
[16:36:17.132]     INFO: number of red-efficiency pixels:   539  255  666 1015 1323 1410 1307  614  724  898 1447  942  784  455   85  133
[16:36:17.132]     INFO: number of X-ray hits detected:    216465 130008 208719 324024 347859 369751 350915 253880 260275 348387 360426 293265 305505 187848 76357 84311
[16:36:17.132]     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:36:17.132]     INFO: number of Vcal hits detected:  207328 207725 207103 206735 206314 206078 206191 207257 207122 206819 206040 206829 207067 207464 207913 207867
[16:36:17.132]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.9 99.6 99.5 99.3 99.2 99.3 99.7 99.6 99.5 99.1 99.5 99.6 99.8 100.0 99.9
[16:36:17.132]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.6 99.4 99.2 99.1 99.1 99.6 99.6 99.4 99.1 99.4 99.6 99.7 100.0 99.9
[16:36:17.132]     INFO: X-ray hit rate [MHz/cm2]:  63.4 38.1 61.2 95.0 102.0 108.4 102.9 74.4 76.3 102.1 105.6 86.0 89.5 55.1 22.4 24.7
[16:36:17.132]     INFO: PixTestHighRate::doXPixelAlive() done
[16:36:17.177]     INFO: PixTest::       pg_setup set to default.
[16:36:17.191]     INFO: enter test to run
[16:37:01.513]     INFO:   test: exit no parameter change
[16:37:01.874]    QUIET: Connection to board 33 closed.
[16:37:01.906]     INFO: pXar: this is the end, my friend