[16:34:39.087]     INFO: *** Welcome to pxar ***
[16:34:39.087]     INFO: *** Today: 2016/05/06
[16:34:39.105]     INFO: *** Version: v1.9.0-796-gef167-dirty
[16:34:39.105]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//dacParameters35_C15.dat
[16:34:39.146]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:34:39.147]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[16:34:39.147]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[16:34:39.255]     INFO:         clk: 4
[16:34:39.255]     INFO:         ctr: 4
[16:34:39.255]     INFO:         sda: 19
[16:34:39.256]     INFO:         tin: 9
[16:34:39.256]     INFO:         level: 15
[16:34:39.256]     INFO:         triggerdelay: 0
[16:34:39.256]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:34:39.256]     INFO: Log level: INFO
[16:34:39.273]    QUIET: Connection to board DTB_WREKRL opened.
[16:34:39.277]     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:34:39.280]     INFO: RPC call hashes of host and DTB match: 398089610
[16:34:40.804]     INFO: DUT info: 
[16:34:40.804]     INFO: The DUT currently contains the following objects:
[16:34:40.804]     INFO:  2 TBM Cores tbm08c (2 ON)
[16:34:40.804]     INFO: 	TBM Core alpha (0): 7 registers set
[16:34:40.804]     INFO: 	TBM Core beta  (1): 7 registers set
[16:34:40.804]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:34:40.804]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.804]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.804]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.804]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.804]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:40.805]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:41.208]     INFO: enter 'restricted' command line mode
[16:34:41.208]     INFO: enter test to run
[16:34:49.747]     INFO:   test: PixelAlive no parameter change
[16:34:49.747]     INFO:   running: pixelalive
[16:34:49.756]     INFO:    ----------------------------------------------------------------------
[16:34:49.756]     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:34:49.756]     INFO:    ----------------------------------------------------------------------
[16:34:50.073]     INFO: Expecting 41600 events.
[16:34:54.412]     INFO: 41600 events read in total (3621ms).
[16:34:54.582]     INFO: Test took 4823ms.
[16:34:54.592]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:34:54.853]     INFO: PixTestAlive::aliveTest() done
[16:34:54.853]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    1    0    0    1    0    0
[16:34:54.887]     INFO: enter test to run
[16:35:44.042]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:35:44.042]     INFO:   running: highrate
[16:35:44.043]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:35:44.276]     INFO:    ----------------------------------------------------------------------
[16:35:44.276]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:35:44.276]     INFO:    ----------------------------------------------------------------------
[16:35:44.276]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:35:44.276]     INFO: edge/corner pixel THR is adjusted
[16:35:44.276]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:35:45.234]     INFO: Collecting data for 5 seconds...
[16:35:50.252]     INFO: Done with hot pixel readout
[16:36:01.856]     INFO: PixTest::       pg_setup set to default.
[16:36:01.857]     INFO: 0 hot pixels found in step 0
[16:36:01.869]     INFO: 0 hot pixels could not be trimmed and have been masked.
[16:36:01.918]     INFO: PixTest::trimHotPixels() done
[16:36:01.918]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[16:36:01.924]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[16:36:01.929]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[16:36:01.934]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[16:36:01.939]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[16:36:01.945]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[16:36:01.950]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[16:36:01.955]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[16:36:01.960]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[16:36:01.966]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[16:36:01.971]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[16:36:01.976]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[16:36:01.981]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[16:36:01.987]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[16:36:01.992]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[16:36:01.997]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[16:36:01.002]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[16:36:02.013]     INFO: enter test to run
[16:36:36.138]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:36:36.138]     INFO:   running: highrate
[16:36:36.142]     INFO:    ----------------------------------------------------------------------
[16:36:36.142]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:36:36.142]     INFO:    ----------------------------------------------------------------------
[16:36:36.142]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:36:36.142]     INFO: edge/corner pixel THR is adjusted
[16:36:36.142]     INFO: PixTestHighRate::trimHotPixels: step 0...
[16:36:37.100]     INFO: Collecting data for 1 seconds...
[16:36:38.103]     INFO: Done with hot pixel readout
[16:36:42.333]     INFO: PixTest::       pg_setup set to default.
[16:36:42.334]     INFO: 1 hot pixels found in step 0
[16:36:43.379]     INFO: Collecting data for 1 seconds...
[16:36:44.383]     INFO: Done with hot pixel readout
[16:36:48.632]     INFO: PixTest::       pg_setup set to default.
[16:36:48.633]     INFO: 1 hot pixels found in step 1
[16:36:49.677]     INFO: Collecting data for 1 seconds...
[16:36:50.680]     INFO: Done with hot pixel readout
[16:36:54.930]     INFO: PixTest::       pg_setup set to default.
[16:36:54.931]     INFO: 1 hot pixels found in step 2
[16:36:55.973]     INFO: Collecting data for 1 seconds...
[16:36:56.976]     INFO: Done with hot pixel readout
[16:37:01.223]     INFO: PixTest::       pg_setup set to default.
[16:37:01.223]     INFO: 0 hot pixels found in step 3
[16:37:01.229]     INFO: 0 hot pixels could not be trimmed and have been masked.
[16:37:01.316]     INFO: PixTest::trimHotPixels() done
[16:37:01.316]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C0.dat
[16:37:01.324]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C1.dat
[16:37:01.329]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C2.dat
[16:37:01.335]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C3.dat
[16:37:01.340]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C4.dat
[16:37:01.345]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C5.dat
[16:37:01.350]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C6.dat
[16:37:01.355]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C7.dat
[16:37:01.360]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C8.dat
[16:37:01.365]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C9.dat
[16:37:01.371]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C10.dat
[16:37:01.376]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C11.dat
[16:37:01.381]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C12.dat
[16:37:01.386]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C13.dat
[16:37:01.391]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C14.dat
[16:37:01.396]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//trimParameters35_C15.dat
[16:37:01.402]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-27_FPIXTest-17C-FNAL-160429-1423_2016-04-29_14h23m_1461957819/000_FPIXTest_p17//defaultMaskFile.dat
[16:37:01.412]     INFO: enter test to run
[16:37:23.601]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[16:37:23.601]     INFO:   running: xray
[16:37:23.603]     INFO:    ----------------------------------------------------------------------
[16:37:23.603]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:37:23.603]     INFO:    ----------------------------------------------------------------------
[16:37:24.566]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:37:35.242]     INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:38:04.915]     INFO: Resuming triggers.
[16:38:15.590]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[16:38:45.484]     INFO: Resuming triggers.
[16:38:56.166]     INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[16:39:24.919]     INFO: Resuming triggers.
[16:39:35.597]     INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[16:40:05.288]     INFO: Resuming triggers.
[16:40:15.970]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:40:45.549]     INFO: Resuming triggers.
[16:40:56.231]     INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:41:25.895]     INFO: Resuming triggers.
[16:41:36.578]     INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:42:06.754]     INFO: Resuming triggers.
[16:42:17.435]     INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:42:47.687]     INFO: Resuming triggers.
[16:42:58.368]     INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:43:28.460]     INFO: Resuming triggers.
[16:43:32.697]     INFO: data taking finished, elapsed time: 100 seconds.
[16:43:44.774]     INFO: PixTest::       pg_setup set to default.
[16:43:44.777]     INFO: PixTestXray::doPhRun() done
[16:43:44.916]     INFO: enter test to run
[16:44:30.062]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[16:44:30.062]     INFO:   running: xray
[16:44:30.063]     INFO:    ----------------------------------------------------------------------
[16:44:30.063]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[16:44:30.064]     INFO:    ----------------------------------------------------------------------
[16:44:31.028]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[16:44:37.359]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:45:07.430]     INFO: Resuming triggers.
[16:45:13.762]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:45:43.841]     INFO: Resuming triggers.
[16:45:50.173]     INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[16:46:20.186]     INFO: Resuming triggers.
[16:46:26.518]     INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[16:46:56.572]     INFO: Resuming triggers.
[16:47:02.903]     INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[16:47:32.937]     INFO: Resuming triggers.
[16:47:39.267]     INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[16:48:09.303]     INFO: Resuming triggers.
[16:48:15.633]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:48:45.711]     INFO: Resuming triggers.
[16:48:52.042]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:49:22.541]     INFO: Resuming triggers.
[16:49:28.872]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:49:59.471]     INFO: Resuming triggers.
[16:50:05.800]     INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:50:35.497]     INFO: Resuming triggers.
[16:50:41.827]     INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:51:11.940]     INFO: Resuming triggers.
[16:51:18.267]     INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[16:51:48.408]     INFO: Resuming triggers.
[16:51:54.739]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:52:24.783]     INFO: Resuming triggers.
[16:52:31.114]     INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[16:53:02.500]     INFO: Resuming triggers.
[16:53:08.830]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:53:39.995]     INFO: Resuming triggers.
[16:53:45.388]     INFO: data taking finished, elapsed time: 100 seconds.
[16:54:12.102]     INFO: PixTest::       pg_setup set to default.
[16:54:12.105]     INFO: PixTestXray::doPhRun() done
[16:54:12.255]     INFO: enter test to run
[16:54:28.754]     INFO:   test: HighRate no parameter change
[16:54:28.754]     INFO:   running: highrate
[16:54:28.755]     INFO:    ----------------------------------------------------------------------
[16:54:28.755]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:54:28.755]     INFO:    ----------------------------------------------------------------------
[16:54:28.895]     INFO: Expecting 768 events.
[16:54:30.027]     INFO: 768 events read in total (417ms).
[16:54:30.028]     INFO: Test took 1267ms.
[16:54:30.831]     INFO: Expecting 41600 events.
[16:54:33.969]     INFO: 41600 events read in total (2611ms).
[16:54:33.970]     INFO: Test took 3936ms.
[16:54:34.006]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:34.725]     INFO: Expecting 41600 events.
[16:54:37.967]     INFO: 41600 events read in total (2715ms).
[16:54:37.968]     INFO: Test took 3943ms.
[16:54:37.004]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:38.722]     INFO: Expecting 41600 events.
[16:54:41.978]     INFO: 41600 events read in total (2729ms).
[16:54:41.979]     INFO: Test took 3956ms.
[16:54:42.016]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:42.736]     INFO: Expecting 41600 events.
[16:54:45.995]     INFO: 41600 events read in total (2732ms).
[16:54:45.996]     INFO: Test took 3961ms.
[16:54:46.032]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:46.748]     INFO: Expecting 41600 events.
[16:54:50.005]     INFO: 41600 events read in total (2731ms).
[16:54:50.006]     INFO: Test took 3954ms.
[16:54:50.044]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:50.761]     INFO: Expecting 41600 events.
[16:54:54.014]     INFO: 41600 events read in total (2726ms).
[16:54:54.015]     INFO: Test took 3952ms.
[16:54:54.051]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:54.770]     INFO: Expecting 41600 events.
[16:54:58.043]     INFO: 41600 events read in total (2746ms).
[16:54:58.044]     INFO: Test took 3974ms.
[16:54:58.080]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:58.797]     INFO: Expecting 41600 events.
[16:55:02.066]     INFO: 41600 events read in total (2742ms).
[16:55:02.067]     INFO: Test took 3967ms.
[16:55:02.104]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:02.823]     INFO: Expecting 41600 events.
[16:55:06.096]     INFO: 41600 events read in total (2746ms).
[16:55:06.097]     INFO: Test took 3975ms.
[16:55:06.133]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:06.850]     INFO: Expecting 41600 events.
[16:55:10.118]     INFO: 41600 events read in total (2741ms).
[16:55:10.119]     INFO: Test took 3966ms.
[16:55:10.156]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:10.875]     INFO: Expecting 41600 events.
[16:55:14.149]     INFO: 41600 events read in total (2747ms).
[16:55:14.150]     INFO: Test took 3974ms.
[16:55:14.187]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:14.905]     INFO: Expecting 41600 events.
[16:55:18.182]     INFO: 41600 events read in total (2750ms).
[16:55:18.183]     INFO: Test took 3977ms.
[16:55:18.220]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:18.938]     INFO: Expecting 41600 events.
[16:55:22.187]     INFO: 41600 events read in total (2722ms).
[16:55:22.188]     INFO: Test took 3948ms.
[16:55:22.226]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:22.941]     INFO: Expecting 41600 events.
[16:55:26.199]     INFO: 41600 events read in total (2731ms).
[16:55:26.200]     INFO: Test took 3955ms.
[16:55:26.237]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:26.957]     INFO: Expecting 41600 events.
[16:55:30.229]     INFO: 41600 events read in total (2745ms).
[16:55:30.231]     INFO: Test took 3974ms.
[16:55:30.267]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:30.985]     INFO: Expecting 41600 events.
[16:55:34.248]     INFO: 41600 events read in total (2736ms).
[16:55:34.249]     INFO: Test took 3962ms.
[16:55:34.286]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:34.002]     INFO: Expecting 41600 events.
[16:55:38.269]     INFO: 41600 events read in total (2740ms).
[16:55:38.270]     INFO: Test took 3964ms.
[16:55:38.307]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:39.025]     INFO: Expecting 41600 events.
[16:55:42.292]     INFO: 41600 events read in total (2740ms).
[16:55:42.293]     INFO: Test took 3967ms.
[16:55:42.330]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:43.049]     INFO: Expecting 41600 events.
[16:55:46.297]     INFO: 41600 events read in total (2722ms).
[16:55:46.298]     INFO: Test took 3949ms.
[16:55:46.335]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:47.051]     INFO: Expecting 41600 events.
[16:55:50.099]     INFO: 41600 events read in total (2521ms).
[16:55:50.100]     INFO: Test took 3745ms.
[16:55:50.136]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:50.496]     INFO: enter test to run
[16:56:15.897]     INFO:   test: HighRate no parameter change
[16:56:15.897]     INFO:   running: highrate
[16:56:15.898]     INFO:    ----------------------------------------------------------------------
[16:56:15.898]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:56:15.898]     INFO:    ----------------------------------------------------------------------
[16:56:16.510]     INFO: Expecting 208000 events.
[16:56:28.533]     INFO: 208000 events read in total (11496ms).
[16:56:28.536]     INFO: Test took 12628ms.
[16:56:28.695]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:56:28.952]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[16:56:28.952]     INFO: number of red-efficiency pixels:    73   63   82  138  165  197  156  103   96  113  141  110  110   73   27   26
[16:56:28.952]     INFO: number of X-ray hits detected:    70860 46868 73353 122485 131938 135749 132764 90232 78321 103610 107924 92235 91607 56787 24243 26755
[16:56:28.952]     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:56:28.952]     INFO: number of Vcal hits detected:  207924 207937 207914 207859 207832 207796 207843 207896 207903 207886 207857 207890 207889 207876 207973 207974
[16:56:28.952]     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 100.0 100.0 100.0 100.0
[16:56:28.952]     INFO: Vcal hit overall 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 99.9 100.0 100.0
[16:56:28.953]     INFO: X-ray hit rate [MHz/cm2]:  20.8 13.7 21.5 35.9 38.7 39.8 38.9 26.4 23.0 30.4 31.6 27.0 26.9 16.6 7.1 7.8
[16:56:28.953]     INFO: PixTestHighRate::doXPixelAlive() done
[16:56:28.000]     INFO: PixTest::       pg_setup set to default.
[16:56:29.011]     INFO: enter test to run
[16:56:49.489]     INFO:   test: HighRate no parameter change
[16:56:49.489]     INFO:   running: highrate
[16:56:49.490]     INFO:    ----------------------------------------------------------------------
[16:56:49.490]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:56:49.490]     INFO:    ----------------------------------------------------------------------
[16:56:50.105]     INFO: Expecting 208000 events.
[16:57:04.402]     INFO: 208000 events read in total (13770ms).
[16:57:04.408]     INFO: Test took 14910ms.
[16:57:04.761]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:57:05.079]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[16:57:05.079]     INFO: number of red-efficiency pixels:   287  150  310  653  659  956  631  466  318  389  479  453  396  245   76   76
[16:57:05.079]     INFO: number of X-ray hits detected:    156462 102983 161425 269699 293086 299027 291809 199150 174475 229828 240432 203440 202282 125358 54102 59699
[16:57:05.079]     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:57:05.079]     INFO: number of Vcal hits detected:  207687 207838 207663 207270 207245 206860 207288 207472 207656 207597 207482 207516 207577 207683 207921 207922
[16:57:05.079]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.7 99.7 99.5 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:57:05.079]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.8 99.6 99.6 99.5 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 100.0 100.0
[16:57:05.079]     INFO: X-ray hit rate [MHz/cm2]:  45.9 30.2 47.3 79.1 85.9 87.6 85.5 58.4 51.1 67.4 70.5 59.6 59.3 36.7 15.9 17.5
[16:57:05.079]     INFO: PixTestHighRate::doXPixelAlive() done
[16:57:05.127]     INFO: PixTest::       pg_setup set to default.
[16:57:05.142]     INFO: enter test to run
[16:57:31.777]     INFO:   test: HighRate no parameter change
[16:57:31.777]     INFO:   running: highrate
[16:57:31.778]     INFO:    ----------------------------------------------------------------------
[16:57:31.778]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:57:31.778]     INFO:    ----------------------------------------------------------------------
[16:57:32.393]     INFO: Expecting 208000 events.
[16:57:48.743]     INFO: 208000 events read in total (15824ms).
[16:57:48.751]     INFO: Test took 16965ms.
[16:57:49.265]     INFO: Fetched DAQ statistics. Counters are being reset now.
[16:57:49.633]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[16:57:49.633]     INFO: number of red-efficiency pixels:   593  321  639 1431 1490 2026 1380 1022  683  908  965  933  941  532  117   92
[16:57:49.633]     INFO: number of X-ray hits detected:    227152 149755 236291 391555 426569 435042 423079 289255 253947 331383 348142 295246 294464 183238 79203 86708
[16:57:49.633]     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:57:49.633]     INFO: number of Vcal hits detected:  207227 207641 207168 206074 205933 204759 206120 206547 207194 206933 206822 206836 206881 207285 207876 207905
[16:57:49.633]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.8 99.7 99.2 99.1 98.6 99.2 99.4 99.6 99.5 99.5 99.5 99.5 99.7 99.9 100.0
[16:57:49.633]     INFO: Vcal hit overall efficiency (%):  99.6 99.8 99.6 99.1 99.0 98.4 99.1 99.3 99.6 99.5 99.4 99.4 99.5 99.7 99.9 100.0
[16:57:49.633]     INFO: X-ray hit rate [MHz/cm2]:  66.6 43.9 69.3 114.8 125.0 127.5 124.0 84.8 74.4 97.1 102.0 86.5 86.3 53.7 23.2 25.4
[16:57:49.633]     INFO: PixTestHighRate::doXPixelAlive() done
[16:57:49.681]     INFO: PixTest::       pg_setup set to default.
[16:57:49.698]     INFO: enter test to run
[16:57:52.256]     INFO:   test: exit no parameter change
[16:57:52.588]    QUIET: Connection to board 33 closed.
[16:57:52.589]     INFO: pXar: this is the end, my friend