[14:32:30.703]     INFO: *** Welcome to pxar ***
[14:32:30.703]     INFO: *** Today: 2016/04/26
[14:32:30.822]     INFO: *** Version: v1.9.0-796-gef167-dirty
[14:32:30.822]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//dacParameters35_C15.dat
[14:32:30.871]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:32:30.871]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//defaultMaskFile.dat
[14:32:30.877]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C15.dat
[14:32:30.975]     INFO:         clk: 4
[14:32:30.975]     INFO:         ctr: 4
[14:32:30.975]     INFO:         sda: 19
[14:32:30.975]     INFO:         tin: 9
[14:32:30.975]     INFO:         level: 15
[14:32:30.975]     INFO:         triggerdelay: 0
[14:32:30.975]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:32:30.975]     INFO: Log level: INFO
[14:32:30.993]    QUIET: Connection to board DTB_WREKRL opened.
[14:32:30.996]     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:     
------------------------------------------------------
[14:32:30.999]     INFO: RPC call hashes of host and DTB match: 398089610
[14:32:32.532]     INFO: DUT info: 
[14:32:32.532]     INFO: The DUT currently contains the following objects:
[14:32:32.532]     INFO:  2 TBM Cores tbm08c (2 ON)
[14:32:32.532]     INFO: 	TBM Core alpha (0): 7 registers set
[14:32:32.532]     INFO: 	TBM Core beta  (1): 7 registers set
[14:32:32.532]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:32:32.532]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.532]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.532]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.532]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.533]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:32.936]     INFO: enter 'restricted' command line mode
[14:32:32.936]     INFO: enter test to run
[14:32:52.567]     INFO:   test: PixelAlive no parameter change
[14:32:52.567]     INFO:   running: pixelalive
[14:32:52.577]     INFO:    ----------------------------------------------------------------------
[14:32:52.577]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:32:52.577]     INFO:    ----------------------------------------------------------------------
[14:32:52.895]     INFO: Expecting 41600 events.
[14:32:57.225]     INFO: 41600 events read in total (3612ms).
[14:32:57.395]     INFO: Test took 4815ms.
[14:32:57.405]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:57.667]     INFO: PixTestAlive::aliveTest() done
[14:32:57.667]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:32:57.699]     INFO: enter test to run
[14:33:39.247]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:33:39.247]     INFO:   running: highrate
[14:33:39.247]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:33:39.486]     INFO:    ----------------------------------------------------------------------
[14:33:39.486]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:33:39.486]     INFO:    ----------------------------------------------------------------------
[14:33:39.487]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:33:39.487]     INFO: edge/corner pixel THR is adjusted
[14:33:39.487]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:33:40.446]     INFO: Collecting data for 5 seconds...
[14:33:45.462]     INFO: Done with hot pixel readout
[14:33:57.257]     INFO: PixTest::       pg_setup set to default.
[14:33:57.258]     INFO: 7 hot pixels found in step 0
[14:33:58.272]     INFO: Collecting data for 5 seconds...
[14:34:03.288]     INFO: Done with hot pixel readout
[14:34:15.069]     INFO: PixTest::       pg_setup set to default.
[14:34:15.070]     INFO: 7 hot pixels found in step 1
[14:34:16.065]     INFO: Collecting data for 5 seconds...
[14:34:21.082]     INFO: Done with hot pixel readout
[14:34:32.695]     INFO: PixTest::       pg_setup set to default.
[14:34:32.696]     INFO: 6 hot pixels found in step 2
[14:34:33.688]     INFO: Collecting data for 5 seconds...
[14:34:38.700]     INFO: Done with hot pixel readout
[14:34:47.576]     INFO: PixTest::       pg_setup set to default.
[14:34:47.577]     INFO: 6 hot pixels found in step 3
[14:34:48.569]     INFO: Collecting data for 5 seconds...
[14:34:53.585]     INFO: Done with hot pixel readout
[14:35:05.304]     INFO: PixTest::       pg_setup set to default.
[14:35:05.305]     INFO: 4 hot pixels found in step 4
[14:35:06.298]     INFO: Collecting data for 5 seconds...
[14:35:11.314]     INFO: Done with hot pixel readout
[14:35:23.025]     INFO: PixTest::       pg_setup set to default.
[14:35:23.026]     INFO: 2 hot pixels found in step 5
[14:35:24.018]     INFO: Collecting data for 5 seconds...
[14:35:29.034]     INFO: Done with hot pixel readout
[14:35:40.771]     INFO: PixTest::       pg_setup set to default.
[14:35:40.772]     INFO: 3 hot pixels found in step 6
[14:35:41.764]     INFO: Collecting data for 5 seconds...
[14:35:46.781]     INFO: Done with hot pixel readout
[14:35:58.604]     INFO: PixTest::       pg_setup set to default.
[14:35:58.605]     INFO: 4 hot pixels found in step 7
[14:35:59.598]     INFO: Collecting data for 5 seconds...
[14:36:04.614]     INFO: Done with hot pixel readout
[14:36:16.329]     INFO: PixTest::       pg_setup set to default.
[14:36:16.330]     INFO: 0 hot pixels found in step 8
[14:36:16.366]     INFO: 0 hot pixels could not be trimmed and have been masked.
[14:36:16.370]     INFO: PixTest::trimHotPixels() done
[14:36:16.370]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C0.dat
[14:36:16.375]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C1.dat
[14:36:16.382]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C2.dat
[14:36:16.388]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C3.dat
[14:36:16.393]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C4.dat
[14:36:16.398]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C5.dat
[14:36:16.403]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C6.dat
[14:36:16.408]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C7.dat
[14:36:16.413]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C8.dat
[14:36:16.419]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C9.dat
[14:36:16.424]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C10.dat
[14:36:16.429]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C11.dat
[14:36:16.434]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C12.dat
[14:36:16.440]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C13.dat
[14:36:16.445]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C14.dat
[14:36:16.450]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C15.dat
[14:36:16.455]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//defaultMaskFile.dat
[14:36:16.465]     INFO: enter test to run
[14:36:55.109]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:36:55.110]     INFO:   running: highrate
[14:36:55.114]     INFO:    ----------------------------------------------------------------------
[14:36:55.114]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:36:55.114]     INFO:    ----------------------------------------------------------------------
[14:36:55.114]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:36:55.114]     INFO: edge/corner pixel THR is adjusted
[14:36:55.114]     INFO: PixTestHighRate::trimHotPixels: step 0...
[14:36:56.072]     INFO: Collecting data for 1 seconds...
[14:36:57.076]     INFO: Done with hot pixel readout
[14:37:01.160]     INFO: PixTest::       pg_setup set to default.
[14:37:01.161]     INFO: 0 hot pixels found in step 0
[14:37:01.166]     INFO: 0 hot pixels could not be trimmed and have been masked.
[14:37:01.255]     INFO: PixTest::trimHotPixels() done
[14:37:01.255]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C0.dat
[14:37:01.267]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C1.dat
[14:37:01.272]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C2.dat
[14:37:01.277]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C3.dat
[14:37:01.283]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C4.dat
[14:37:01.288]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C5.dat
[14:37:01.293]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C6.dat
[14:37:01.299]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C7.dat
[14:37:01.304]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C8.dat
[14:37:01.309]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C9.dat
[14:37:01.315]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C10.dat
[14:37:01.321]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C11.dat
[14:37:01.326]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C12.dat
[14:37:01.331]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C13.dat
[14:37:01.336]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C14.dat
[14:37:01.341]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//trimParameters35_C15.dat
[14:37:01.347]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-2-09_FPIXTest-17C-FNAL-160421-1034_2016-04-21_10h34m_1461252897/000_FPIXTest_p17//defaultMaskFile.dat
[14:37:01.357]     INFO: enter test to run
[14:37:27.165]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[14:37:27.165]     INFO:   running: xray
[14:37:27.166]     INFO:    ----------------------------------------------------------------------
[14:37:27.166]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:37:27.167]     INFO:    ----------------------------------------------------------------------
[14:37:28.130]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:37:39.601]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:38:09.002]     INFO: Resuming triggers.
[14:38:20.476]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:38:49.832]     INFO: Resuming triggers.
[14:39:01.310]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:39:30.624]     INFO: Resuming triggers.
[14:39:42.101]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:40:11.431]     INFO: Resuming triggers.
[14:40:22.906]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:40:52.344]     INFO: Resuming triggers.
[14:41:03.818]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:41:33.198]     INFO: Resuming triggers.
[14:41:44.672]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:42:14.105]     INFO: Resuming triggers.
[14:42:25.575]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:42:54.930]     INFO: Resuming triggers.
[14:43:03.468]     INFO: data taking finished, elapsed time: 100 seconds.
[14:43:25.512]     INFO: PixTest::       pg_setup set to default.
[14:43:25.515]     INFO: PixTestXray::doPhRun() done
[14:43:25.687]     INFO: enter test to run
[14:44:26.242]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[14:44:26.242]     INFO:   running: xray
[14:44:26.243]     INFO:    ----------------------------------------------------------------------
[14:44:26.243]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[14:44:26.243]     INFO:    ----------------------------------------------------------------------
[14:44:27.207]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[14:44:33.789]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:44:59.889]     INFO: Resuming triggers.
[14:45:06.472]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:45:36.435]     INFO: Resuming triggers.
[14:45:43.012]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:46:13.005]     INFO: Resuming triggers.
[14:46:19.583]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:46:49.590]     INFO: Resuming triggers.
[14:46:56.174]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:47:26.209]     INFO: Resuming triggers.
[14:47:32.793]     INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:48:02.909]     INFO: Resuming triggers.
[14:48:09.487]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:48:39.591]     INFO: Resuming triggers.
[14:48:46.172]     INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:49:16.163]     INFO: Resuming triggers.
[14:49:22.745]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:49:52.799]     INFO: Resuming triggers.
[14:49:59.382]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:50:29.397]     INFO: Resuming triggers.
[14:50:35.975]     INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:51:06.042]     INFO: Resuming triggers.
[14:51:12.620]     INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:51:42.630]     INFO: Resuming triggers.
[14:51:49.212]     INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:52:19.354]     INFO: Resuming triggers.
[14:52:25.934]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:52:55.982]     INFO: Resuming triggers.
[14:53:02.562]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:53:32.608]     INFO: Resuming triggers.
[14:53:34.228]     INFO: data taking finished, elapsed time: 100 seconds.
[14:53:41.955]     INFO: PixTest::       pg_setup set to default.
[14:53:41.958]     INFO: PixTestXray::doPhRun() done
[14:53:42.108]     INFO: enter test to run
[14:54:06.894]     INFO:   test: HighRate no parameter change
[14:54:06.894]     INFO:   running: highrate
[14:54:06.895]     INFO:    ----------------------------------------------------------------------
[14:54:06.895]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:54:06.895]     INFO:    ----------------------------------------------------------------------
[14:54:07.035]     INFO: Expecting 768 events.
[14:54:08.169]     INFO: 768 events read in total (418ms).
[14:54:08.170]     INFO: Test took 1269ms.
[14:54:08.973]     INFO: Expecting 41600 events.
[14:54:12.107]     INFO: 41600 events read in total (2608ms).
[14:54:12.108]     INFO: Test took 3932ms.
[14:54:12.141]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:12.865]     INFO: Expecting 41600 events.
[14:54:16.072]     INFO: 41600 events read in total (2680ms).
[14:54:16.073]     INFO: Test took 3913ms.
[14:54:16.108]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:16.833]     INFO: Expecting 41600 events.
[14:54:20.067]     INFO: 41600 events read in total (2707ms).
[14:54:20.068]     INFO: Test took 3944ms.
[14:54:20.103]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:20.827]     INFO: Expecting 41600 events.
[14:54:24.052]     INFO: 41600 events read in total (2699ms).
[14:54:24.053]     INFO: Test took 3933ms.
[14:54:24.088]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:24.812]     INFO: Expecting 41600 events.
[14:54:28.037]     INFO: 41600 events read in total (2698ms).
[14:54:28.038]     INFO: Test took 3931ms.
[14:54:28.073]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:28.797]     INFO: Expecting 41600 events.
[14:54:32.043]     INFO: 41600 events read in total (2719ms).
[14:54:32.044]     INFO: Test took 3954ms.
[14:54:32.079]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:32.803]     INFO: Expecting 41600 events.
[14:54:36.054]     INFO: 41600 events read in total (2724ms).
[14:54:36.055]     INFO: Test took 3958ms.
[14:54:36.089]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:36.814]     INFO: Expecting 41600 events.
[14:54:40.048]     INFO: 41600 events read in total (2707ms).
[14:54:40.049]     INFO: Test took 3943ms.
[14:54:40.083]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:40.807]     INFO: Expecting 41600 events.
[14:54:44.053]     INFO: 41600 events read in total (2719ms).
[14:54:44.054]     INFO: Test took 3952ms.
[14:54:44.088]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:44.811]     INFO: Expecting 41600 events.
[14:54:47.623]     INFO: 41600 events read in total (2285ms).
[14:54:47.624]     INFO: Test took 3518ms.
[14:54:47.658]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:48.385]     INFO: Expecting 41600 events.
[14:54:51.482]     INFO: 41600 events read in total (2571ms).
[14:54:51.483]     INFO: Test took 3807ms.
[14:54:51.518]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:52.236]     INFO: Expecting 41600 events.
[14:54:55.081]     INFO: 41600 events read in total (2318ms).
[14:54:55.081]     INFO: Test took 3544ms.
[14:54:55.116]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:55.843]     INFO: Expecting 41600 events.
[14:54:58.664]     INFO: 41600 events read in total (2294ms).
[14:54:58.665]     INFO: Test took 3530ms.
[14:54:58.700]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:59.426]     INFO: Expecting 41600 events.
[14:55:02.619]     INFO: 41600 events read in total (2666ms).
[14:55:02.620]     INFO: Test took 3901ms.
[14:55:02.654]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:03.372]     INFO: Expecting 41600 events.
[14:55:06.607]     INFO: 41600 events read in total (2708ms).
[14:55:06.608]     INFO: Test took 3936ms.
[14:55:06.642]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:07.367]     INFO: Expecting 41600 events.
[14:55:10.611]     INFO: 41600 events read in total (2717ms).
[14:55:10.612]     INFO: Test took 3951ms.
[14:55:10.646]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:11.368]     INFO: Expecting 41600 events.
[14:55:14.606]     INFO: 41600 events read in total (2711ms).
[14:55:14.607]     INFO: Test took 3943ms.
[14:55:14.641]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:15.361]     INFO: Expecting 41600 events.
[14:55:18.583]     INFO: 41600 events read in total (2695ms).
[14:55:18.584]     INFO: Test took 3926ms.
[14:55:18.618]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:19.344]     INFO: Expecting 41600 events.
[14:55:22.552]     INFO: 41600 events read in total (2681ms).
[14:55:22.553]     INFO: Test took 3917ms.
[14:55:22.587]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:23.312]     INFO: Expecting 41600 events.
[14:55:26.364]     INFO: 41600 events read in total (2525ms).
[14:55:26.365]     INFO: Test took 3759ms.
[14:55:26.398]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:26.762]     INFO: enter test to run
[14:55:41.181]     INFO:   test: HighRate no parameter change
[14:55:41.181]     INFO:   running: highrate
[14:55:41.182]     INFO:    ----------------------------------------------------------------------
[14:55:41.182]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:55:41.182]     INFO:    ----------------------------------------------------------------------
[14:55:41.803]     INFO: Expecting 208000 events.
[14:55:53.649]     INFO: 208000 events read in total (11319ms).
[14:55:53.653]     INFO: Test took 12461ms.
[14:55:53.801]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:54.053]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:55:54.053]     INFO: number of red-efficiency pixels:    68   65   81  135  140  136  142  105   86  115  131   82  102   60   24   29
[14:55:54.053]     INFO: number of X-ray hits detected:    68280 45355 69923 114203 118583 114905 111714 74921 69198 91549 97741 83935 91286 54513 24101 27044
[14:55:54.053]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:55:54.053]     INFO: number of Vcal hits detected:  207930 207933 207918 207856 207855 207861 207853 207892 207914 207885 207867 207917 207894 207939 207976 207971
[14:55:54.053]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:55:54.053]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:55:54.053]     INFO: X-ray hit rate [MHz/cm2]:  20.0 13.3 20.5 33.5 34.8 33.7 32.7 22.0 20.3 26.8 28.6 24.6 26.8 16.0 7.1 7.9
[14:55:54.053]     INFO: PixTestHighRate::doXPixelAlive() done
[14:55:54.100]     INFO: PixTest::       pg_setup set to default.
[14:55:54.115]     INFO: enter test to run
[14:56:12.229]     INFO:   test: HighRate no parameter change
[14:56:12.229]     INFO:   running: highrate
[14:56:12.230]     INFO:    ----------------------------------------------------------------------
[14:56:12.230]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:56:12.230]     INFO:    ----------------------------------------------------------------------
[14:56:12.843]     INFO: Expecting 208000 events.
[14:56:26.534]     INFO: 208000 events read in total (13164ms).
[14:56:26.539]     INFO: Test took 14298ms.
[14:56:26.836]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:27.137]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:56:27.137]     INFO: number of red-efficiency pixels:   199  135  270  393  566  417  525  262  248  370  415  329  282  170   68   64
[14:56:27.137]     INFO: number of X-ray hits detected:    143788 96129 148170 241228 250497 242814 234978 158976 146619 193852 206077 177167 193245 115332 51433 57152
[14:56:27.137]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:56:27.137]     INFO: number of Vcal hits detected:  207789 207863 207715 207581 207377 207557 207426 207716 207741 207613 207551 207657 207706 207822 207929 207934
[14:56:27.137]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:56:27.137]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:56:27.137]     INFO: X-ray hit rate [MHz/cm2]:  42.1 28.2 43.4 70.7 73.4 71.2 68.9 46.6 43.0 56.8 60.4 51.9 56.6 33.8 15.1 16.8
[14:56:27.137]     INFO: PixTestHighRate::doXPixelAlive() done
[14:56:27.181]     INFO: PixTest::       pg_setup set to default.
[14:56:27.192]     INFO: enter test to run
[14:56:45.253]     INFO:   test: HighRate no parameter change
[14:56:45.253]     INFO:   running: highrate
[14:56:45.254]     INFO:    ----------------------------------------------------------------------
[14:56:45.254]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:56:45.254]     INFO:    ----------------------------------------------------------------------
[14:56:45.867]     INFO: Expecting 208000 events.
[14:57:01.434]     INFO: 208000 events read in total (15040ms).
[14:57:01.442]     INFO: Test took 16178ms.
[14:57:01.905]     INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:02.257]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[14:57:02.257]     INFO: number of red-efficiency pixels:   390  305  590  995 1398  919 1252  533  450  862  964  795  603  389  113  132
[14:57:02.257]     INFO: number of X-ray hits detected:    215181 144199 222007 362470 375601 363638 353466 239691 220838 290996 310730 265839 289575 172495 77412 86267
[14:57:02.257]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:57:02.257]     INFO: number of Vcal hits detected:  207556 207664 207218 206761 206116 206891 206384 207396 207517 207001 206847 207066 207324 207570 207882 207867
[14:57:02.257]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.7 99.5 99.2 99.5 99.3 99.7 99.8 99.6 99.5 99.6 99.7 99.8 99.9 99.9
[14:57:02.257]     INFO: Vcal hit overall efficiency (%):  99.8 99.8 99.6 99.4 99.1 99.5 99.2 99.7 99.8 99.5 99.4 99.6 99.7 99.8 99.9 99.9
[14:57:02.257]     INFO: X-ray hit rate [MHz/cm2]:  63.1 42.3 65.1 106.2 110.1 106.6 103.6 70.3 64.7 85.3 91.1 77.9 84.9 50.6 22.7 25.3
[14:57:02.257]     INFO: PixTestHighRate::doXPixelAlive() done
[14:57:02.307]     INFO: PixTest::       pg_setup set to default.
[14:57:02.322]     INFO: enter test to run
[14:57:09.981]     INFO:   test: exit no parameter change
[14:57:10.341]    QUIET: Connection to board 33 closed.
[14:57:10.341]     INFO: pXar: this is the end, my friend