[13:27:57.000]     INFO: *** Welcome to pxar ***
[13:27:57.000]     INFO: *** Today: 2016/07/08
[13:28:01.171]     INFO: *** Version: v1.9.0-814-g7497
[13:28:01.171]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//dacParameters35_C15.dat
[13:28:01.172]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:28:01.172]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[13:28:01.172]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[13:28:01.253]     INFO:         clk: 4
[13:28:01.253]     INFO:         ctr: 4
[13:28:01.253]     INFO:         sda: 19
[13:28:01.253]     INFO:         tin: 9
[13:28:01.253]     INFO:         level: 15
[13:28:01.253]     INFO:         triggerdelay: 0
[13:28:01.253]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:28:01.253]     INFO: Log level: INFO
[13:28:01.268]    QUIET: Connection to board DTB_WREKRL opened.
[13:28:01.271]     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:     
------------------------------------------------------
[13:28:01.288]     INFO: RPC call hashes of host and DTB match: 398089610
[13:28:02.879]     INFO: DUT info: 
[13:28:02.879]     INFO: The DUT currently contains the following objects:
[13:28:02.879]     INFO:  2 TBM Cores tbm08c (2 ON)
[13:28:02.879]     INFO: 	TBM Core alpha (0): 7 registers set
[13:28:02.879]     INFO: 	TBM Core beta  (1): 7 registers set
[13:28:02.879]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:28:02.879]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.879]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:02.880]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:03.283]     INFO: enter 'restricted' command line mode
[13:28:03.283]     INFO: enter test to run
[13:28:06.433]     INFO:   test: PixelAlive no parameter change
[13:28:06.434]     INFO:   running: pixelalive
[13:28:06.465]     INFO:    ----------------------------------------------------------------------
[13:28:06.465]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:28:06.465]     INFO:    ----------------------------------------------------------------------
[13:28:06.792]     INFO: Expecting 41600 events.
[13:28:10.929]     INFO: 41600 events read in total (3419ms).
[13:28:11.099]     INFO: Test took 4632ms.
[13:28:11.106]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:11.371]     INFO: PixTestAlive::aliveTest() done
[13:28:11.371]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[13:28:11.406]     INFO: enter test to run
[13:28:24.361]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:28:24.361]     INFO:   running: highrate
[13:28:24.361]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:28:24.544]     INFO:    ----------------------------------------------------------------------
[13:28:24.544]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:28:24.544]     INFO:    ----------------------------------------------------------------------
[13:28:24.544]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:28:24.544]     INFO: edge/corner pixel THR is adjusted
[13:28:24.544]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:28:25.524]     INFO: Collecting data for 5 seconds...
[13:28:30.540]     INFO: Done with hot pixel readout
[13:28:40.358]     INFO: PixTest::       pg_setup set to default.
[13:28:40.359]     INFO: 2 hot pixels found in step 0
[13:28:41.378]     INFO: Collecting data for 5 seconds...
[13:28:46.394]     INFO: Done with hot pixel readout
[13:28:56.632]     INFO: PixTest::       pg_setup set to default.
[13:28:56.633]     INFO: 2 hot pixels found in step 1
[13:28:57.628]     INFO: Collecting data for 5 seconds...
[13:29:02.644]     INFO: Done with hot pixel readout
[13:29:12.718]     INFO: PixTest::       pg_setup set to default.
[13:29:12.719]     INFO: 2 hot pixels found in step 2
[13:29:13.719]     INFO: Collecting data for 5 seconds...
[13:29:18.737]     INFO: Done with hot pixel readout
[13:29:28.858]     INFO: PixTest::       pg_setup set to default.
[13:29:28.859]     INFO: 1 hot pixels found in step 3
[13:29:29.856]     INFO: Collecting data for 5 seconds...
[13:29:34.872]     INFO: Done with hot pixel readout
[13:29:46.827]     INFO: PixTest::       pg_setup set to default.
[13:29:46.828]     INFO: 4 hot pixels found in step 4
[13:29:47.820]     INFO: Collecting data for 5 seconds...
[13:29:52.838]     INFO: Done with hot pixel readout
[13:30:04.270]     INFO: PixTest::       pg_setup set to default.
[13:30:04.271]     INFO: 1 hot pixels found in step 5
[13:30:05.264]     INFO: Collecting data for 5 seconds...
[13:30:10.283]     INFO: Done with hot pixel readout
[13:30:21.733]     INFO: PixTest::       pg_setup set to default.
[13:30:21.734]     INFO: 0 hot pixels found in step 6
[13:30:21.770]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:30:21.774]     INFO: PixTest::trimHotPixels() done
[13:30:21.774]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat
[13:30:21.780]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C1.dat
[13:30:21.785]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C2.dat
[13:30:21.791]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C3.dat
[13:30:21.796]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C4.dat
[13:30:21.802]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C5.dat
[13:30:21.807]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C6.dat
[13:30:21.812]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C7.dat
[13:30:21.818]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C8.dat
[13:30:21.823]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C9.dat
[13:30:21.829]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C10.dat
[13:30:21.834]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C11.dat
[13:30:21.839]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C12.dat
[13:30:21.845]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C13.dat
[13:30:21.850]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C14.dat
[13:30:21.856]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[13:30:21.861]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[13:30:21.871]     INFO: enter test to run
[13:30:56.064]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:30:56.064]     INFO:   running: highrate
[13:30:56.069]     INFO:    ----------------------------------------------------------------------
[13:30:56.069]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:30:56.069]     INFO:    ----------------------------------------------------------------------
[13:30:56.069]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:30:56.069]     INFO: edge/corner pixel THR is adjusted
[13:30:56.069]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:30:57.025]     INFO: Collecting data for 1 seconds...
[13:30:58.029]     INFO: Done with hot pixel readout
[13:31:02.118]     INFO: PixTest::       pg_setup set to default.
[13:31:02.119]     INFO: 0 hot pixels found in step 0
[13:31:02.124]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:31:02.213]     INFO: PixTest::trimHotPixels() done
[13:31:02.214]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C0.dat
[13:31:02.224]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C1.dat
[13:31:02.229]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C2.dat
[13:31:02.234]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C3.dat
[13:31:02.240]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C4.dat
[13:31:02.245]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C5.dat
[13:31:02.251]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C6.dat
[13:31:02.256]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C7.dat
[13:31:02.262]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C8.dat
[13:31:02.267]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C9.dat
[13:31:02.272]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C10.dat
[13:31:02.278]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C11.dat
[13:31:02.284]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C12.dat
[13:31:02.289]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C13.dat
[13:31:02.294]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C14.dat
[13:31:02.300]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//trimParameters35_C15.dat
[13:31:02.306]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-05_FPIXTest-17C-FNAL-160706-1218_2016-07-06_12h18m_1467825531/000_FPIXTest_p17//defaultMaskFile.dat
[13:31:02.315]     INFO: enter test to run
[13:32:59.127]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[13:32:59.127]     INFO:   running: xray
[13:32:59.129]     INFO:    ----------------------------------------------------------------------
[13:32:59.129]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:32:59.129]     INFO:    ----------------------------------------------------------------------
[13:33:00.091]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:33:11.511]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:33:40.852]     INFO: Resuming triggers.
[13:33:52.273]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:34:21.731]     INFO: Resuming triggers.
[13:34:33.151]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:35:02.488]     INFO: Resuming triggers.
[13:35:13.906]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:35:43.354]     INFO: Resuming triggers.
[13:35:54.769]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:36:24.164]     INFO: Resuming triggers.
[13:36:35.584]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:37:04.963]     INFO: Resuming triggers.
[13:37:16.383]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:37:45.801]     INFO: Resuming triggers.
[13:37:57.223]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:38:26.580]     INFO: Resuming triggers.
[13:38:35.564]     INFO: data taking finished, elapsed time: 100 seconds.
[13:38:58.884]     INFO: PixTest::       pg_setup set to default.
[13:38:58.887]     INFO: PixTestXray::doPhRun() done
[13:38:59.090]     INFO: enter test to run
[13:39:32.245]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[13:39:32.245]     INFO:   running: xray
[13:39:32.246]     INFO:    ----------------------------------------------------------------------
[13:39:32.246]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:39:32.246]     INFO:    ----------------------------------------------------------------------
[13:39:33.210]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:39:39.885]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:40:10.119]     INFO: Resuming triggers.
[13:40:16.800]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:40:46.964]     INFO: Resuming triggers.
[13:40:53.645]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:41:24.982]     INFO: Resuming triggers.
[13:41:31.661]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:42:02.894]     INFO: Resuming triggers.
[13:42:09.575]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:42:40.131]     INFO: Resuming triggers.
[13:42:46.808]     INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:43:18.475]     INFO: Resuming triggers.
[13:43:25.155]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:43:56.841]     INFO: Resuming triggers.
[13:44:03.517]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:44:34.856]     INFO: Resuming triggers.
[13:44:41.529]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:45:11.807]     INFO: Resuming triggers.
[13:45:18.481]     INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:45:48.748]     INFO: Resuming triggers.
[13:45:55.422]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:46:25.631]     INFO: Resuming triggers.
[13:46:32.305]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:47:02.539]     INFO: Resuming triggers.
[13:47:09.212]     INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:47:39.541]     INFO: Resuming triggers.
[13:47:46.214]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:48:16.362]     INFO: Resuming triggers.
[13:48:23.035]     INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:48:53.274]     INFO: Resuming triggers.
[13:48:53.475]     INFO: data taking finished, elapsed time: 100 seconds.
[13:48:54.760]     INFO: PixTest::       pg_setup set to default.
[13:48:54.763]     INFO: PixTestXray::doPhRun() done
[13:48:54.927]     INFO: enter test to run
[13:49:49.889]     INFO:   test: HighRate no parameter change
[13:49:49.889]     INFO:   running: highrate
[13:49:49.907]     INFO:    ----------------------------------------------------------------------
[13:49:49.907]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:49:49.907]     INFO:    ----------------------------------------------------------------------
[13:49:50.064]     INFO: Expecting 768 events.
[13:49:51.204]     INFO: 768 events read in total (418ms).
[13:49:51.205]     INFO: Test took 1277ms.
[13:49:52.008]     INFO: Expecting 41600 events.
[13:49:55.028]     INFO: 41600 events read in total (2493ms).
[13:49:55.029]     INFO: Test took 3798ms.
[13:49:55.062]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:55.793]     INFO: Expecting 41600 events.
[13:49:58.969]     INFO: 41600 events read in total (2649ms).
[13:49:58.970]     INFO: Test took 3890ms.
[13:49:59.005]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:59.731]     INFO: Expecting 41600 events.
[13:50:02.967]     INFO: 41600 events read in total (2709ms).
[13:50:02.968]     INFO: Test took 3944ms.
[13:50:03.002]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:03.727]     INFO: Expecting 41600 events.
[13:50:06.950]     INFO: 41600 events read in total (2696ms).
[13:50:06.951]     INFO: Test took 3930ms.
[13:50:06.986]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:07.711]     INFO: Expecting 41600 events.
[13:50:10.944]     INFO: 41600 events read in total (2706ms).
[13:50:10.945]     INFO: Test took 3941ms.
[13:50:10.979]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:11.703]     INFO: Expecting 41600 events.
[13:50:14.942]     INFO: 41600 events read in total (2712ms).
[13:50:14.943]     INFO: Test took 3947ms.
[13:50:14.978]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:15.702]     INFO: Expecting 41600 events.
[13:50:18.951]     INFO: 41600 events read in total (2722ms).
[13:50:18.952]     INFO: Test took 3956ms.
[13:50:18.986]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:19.712]     INFO: Expecting 41600 events.
[13:50:22.945]     INFO: 41600 events read in total (2706ms).
[13:50:22.946]     INFO: Test took 3942ms.
[13:50:22.981]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:23.705]     INFO: Expecting 41600 events.
[13:50:26.939]     INFO: 41600 events read in total (2707ms).
[13:50:26.940]     INFO: Test took 3940ms.
[13:50:26.975]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:27.698]     INFO: Expecting 41600 events.
[13:50:30.946]     INFO: 41600 events read in total (2722ms).
[13:50:30.947]     INFO: Test took 3954ms.
[13:50:30.982]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:31.701]     INFO: Expecting 41600 events.
[13:50:34.930]     INFO: 41600 events read in total (2702ms).
[13:50:34.931]     INFO: Test took 3929ms.
[13:50:34.966]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:35.687]     INFO: Expecting 41600 events.
[13:50:38.926]     INFO: 41600 events read in total (2712ms).
[13:50:38.927]     INFO: Test took 3944ms.
[13:50:38.962]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:39.681]     INFO: Expecting 41600 events.
[13:50:42.947]     INFO: 41600 events read in total (2739ms).
[13:50:42.948]     INFO: Test took 3967ms.
[13:50:42.983]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:43.703]     INFO: Expecting 41600 events.
[13:50:46.920]     INFO: 41600 events read in total (2690ms).
[13:50:46.921]     INFO: Test took 3919ms.
[13:50:46.955]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:47.678]     INFO: Expecting 41600 events.
[13:50:50.907]     INFO: 41600 events read in total (2703ms).
[13:50:50.908]     INFO: Test took 3934ms.
[13:50:50.942]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:51.667]     INFO: Expecting 41600 events.
[13:50:54.915]     INFO: 41600 events read in total (2721ms).
[13:50:54.916]     INFO: Test took 3955ms.
[13:50:54.950]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:55.675]     INFO: Expecting 41600 events.
[13:50:58.930]     INFO: 41600 events read in total (2728ms).
[13:50:58.931]     INFO: Test took 3963ms.
[13:50:58.966]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:59.687]     INFO: Expecting 41600 events.
[13:51:02.919]     INFO: 41600 events read in total (2705ms).
[13:51:02.920]     INFO: Test took 3935ms.
[13:51:02.955]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:03.680]     INFO: Expecting 41600 events.
[13:51:06.910]     INFO: 41600 events read in total (2703ms).
[13:51:06.911]     INFO: Test took 3938ms.
[13:51:06.945]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:07.666]     INFO: Expecting 41600 events.
[13:51:10.834]     INFO: 41600 events read in total (2641ms).
[13:51:10.835]     INFO: Test took 3872ms.
[13:51:10.869]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:11.223]     INFO: enter test to run
[13:51:59.752]     INFO:   test: HighRate no parameter change
[13:51:59.752]     INFO:   running: highrate
[13:51:59.753]     INFO:    ----------------------------------------------------------------------
[13:51:59.753]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:51:59.753]     INFO:    ----------------------------------------------------------------------
[13:52:00.370]     INFO: Expecting 208000 events.
[13:52:12.175]     INFO: 208000 events read in total (11278ms).
[13:52:12.178]     INFO: Test took 12415ms.
[13:52:12.325]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:12.579]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[13:52:12.579]     INFO: number of red-efficiency pixels:    80   56   69  113  115  122  114   90   96  138  149  109  128   68   29   28
[13:52:12.579]     INFO: number of X-ray hits detected:    67371 44337 61323 94873 100027 103568 106662 77253 88700 112487 112179 93856 103533 58156 22631 27447
[13:52:12.579]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:52:12.579]     INFO: number of Vcal hits detected:  207919 207944 207929 207886 207881 207877 207884 207907 207902 207855 207849 207889 207868 207883 207971 207972
[13:52:12.579]     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
[13:52:12.579]     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
[13:52:12.579]     INFO: X-ray hit rate [MHz/cm2]:  19.7 13.0 18.0 27.8 29.3 30.4 31.3 22.6 26.0 33.0 32.9 27.5 30.3 17.0 6.6 8.0
[13:52:12.579]     INFO: PixTestHighRate::doXPixelAlive() done
[13:52:12.629]     INFO: PixTest::       pg_setup set to default.
[13:52:12.642]     INFO: enter test to run
[13:53:17.343]     INFO:   test: HighRate no parameter change
[13:53:17.343]     INFO:   running: highrate
[13:53:17.344]     INFO:    ----------------------------------------------------------------------
[13:53:17.344]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:53:17.344]     INFO:    ----------------------------------------------------------------------
[13:53:17.965]     INFO: Expecting 208000 events.
[13:53:31.651]     INFO: 208000 events read in total (13159ms).
[13:53:31.659]     INFO: Test took 14305ms.
[13:53:31.966]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:32.270]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[13:53:32.270]     INFO: number of red-efficiency pixels:   164  156  194  397  334  336  360  289  293  405  418  323  357  245   75   67
[13:53:32.270]     INFO: number of X-ray hits detected:    136366 88758 124588 190520 201182 209061 214038 155940 178052 225142 225114 189491 207664 116931 45818 55185
[13:53:32.270]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:53:32.271]     INFO: number of Vcal hits detected:  207827 207836 207793 207573 207649 207648 207609 207697 207681 207572 207545 207653 207613 207692 207925 207930
[13:53:32.271]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:53:32.271]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:53:32.271]     INFO: X-ray hit rate [MHz/cm2]:  40.0 26.0 36.5 55.8 59.0 61.3 62.7 45.7 52.2 66.0 66.0 55.5 60.9 34.3 13.4 16.2
[13:53:32.271]     INFO: PixTestHighRate::doXPixelAlive() done
[13:53:32.317]     INFO: PixTest::       pg_setup set to default.
[13:53:32.334]     INFO: enter test to run
[13:53:47.007]     INFO:   test: HighRate no parameter change
[13:53:47.007]     INFO:   running: highrate
[13:53:47.008]     INFO:    ----------------------------------------------------------------------
[13:53:47.008]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:53:47.008]     INFO:    ----------------------------------------------------------------------
[13:53:47.648]     INFO: Expecting 208000 events.
[13:54:02.208]     INFO: 208000 events read in total (14033ms).
[13:54:02.217]     INFO: Test took 15202ms.
[13:54:02.677]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:03.032]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    0    0
[13:54:03.032]     INFO: number of red-efficiency pixels:   430  300  426  922  726  789  859  629  682  947  972  770  877  550  117   99
[13:54:03.032]     INFO: number of X-ray hits detected:    207328 135068 189568 290453 307849 317542 326828 237394 272793 343164 341775 287841 315890 178904 69704 84908
[13:54:03.032]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:54:03.032]     INFO: number of Vcal hits detected:  207498 207669 207503 206921 207166 207102 206980 207253 207210 206856 206823 207082 206954 207280 207878 207898
[13:54:03.032]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.8 99.5 99.6 99.6 99.6 99.7 99.7 99.5 99.5 99.6 99.5 99.7 99.9 100.0
[13:54:03.032]     INFO: Vcal hit overall efficiency (%):  99.8 99.8 99.8 99.5 99.6 99.6 99.5 99.6 99.6 99.5 99.4 99.6 99.5 99.7 99.9 100.0
[13:54:03.033]     INFO: X-ray hit rate [MHz/cm2]:  60.8 39.6 55.6 85.1 90.2 93.1 95.8 69.6 80.0 100.6 100.2 84.4 92.6 52.4 20.4 24.9
[13:54:03.033]     INFO: PixTestHighRate::doXPixelAlive() done
[13:54:03.077]     INFO: PixTest::       pg_setup set to default.
[13:54:03.091]     INFO: enter test to run
[13:54:38.663]     INFO:   test: exit no parameter change
[13:54:38.991]    QUIET: Connection to board 33 closed.
[13:54:39.002]     INFO: pXar: this is the end, my friend