[19:48:31.800]     INFO: *** Welcome to pxar ***
[19:48:31.800]     INFO: *** Today: 2016/09/07
[19:48:33.896]     INFO: *** Version: v1.9.0-818-g96727
[19:48:33.896]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//dacParameters35_C15.dat
[19:48:34.314]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//tbmParameters_C0b.dat
[19:48:34.315]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[19:48:34.315]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[19:48:35.373]     INFO:         clk: 4
[19:48:35.373]     INFO:         ctr: 4
[19:48:35.373]     INFO:         sda: 19
[19:48:35.373]     INFO:         tin: 9
[19:48:35.373]     INFO:         level: 15
[19:48:35.373]     INFO:         triggerdelay: 0
[19:48:35.373]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[19:48:35.373]     INFO: Log level: INFO
[19:48:35.391]    QUIET: Connection to board DTB_WREKRL opened.
[19:48:35.394]     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:     
------------------------------------------------------
[19:48:35.397]     INFO: RPC call hashes of host and DTB match: 398089610
[19:48:36.930]     INFO: DUT info: 
[19:48:36.930]     INFO: The DUT currently contains the following objects:
[19:48:36.930]     INFO:  2 TBM Cores tbm08c (2 ON)
[19:48:36.930]     INFO: 	TBM Core alpha (0): 7 registers set
[19:48:36.930]     INFO: 	TBM Core beta  (1): 7 registers set
[19:48:36.930]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[19:48:36.930]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:36.931]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[19:48:37.351]     INFO: enter 'restricted' command line mode
[19:48:37.351]     INFO: enter test to run
[19:48:52.270]     INFO:   test: PixelAlive no parameter change
[19:48:52.270]     INFO:   running: pixelalive
[19:48:52.300]     INFO:    ----------------------------------------------------------------------
[19:48:52.300]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[19:48:52.300]     INFO:    ----------------------------------------------------------------------
[19:48:52.630]     INFO: Expecting 41600 events.
[19:48:56.952]     INFO: 41600 events read in total (3605ms).
[19:48:57.117]     INFO: Test took 4807ms.
[19:48:57.127]     INFO: Fetched DAQ statistics. Counters are being reset now.
[19:48:57.389]     INFO: PixTestAlive::aliveTest() done
[19:48:57.389]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    0
[19:48:57.420]     INFO: enter test to run
[19:49:31.861]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[19:49:31.861]     INFO:   running: highrate
[19:49:31.869]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[19:49:32.101]     INFO:    ----------------------------------------------------------------------
[19:49:32.101]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[19:49:32.101]     INFO:    ----------------------------------------------------------------------
[19:49:32.101]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[19:49:32.101]     INFO: edge/corner pixel THR is adjusted
[19:49:32.101]     INFO: PixTestHighRate::trimHotPixels: step 0...
[19:49:33.082]     INFO: Collecting data for 5 seconds...
[19:49:38.098]     INFO: Done with hot pixel readout
[19:49:49.647]     INFO: PixTest::       pg_setup set to default.
[19:49:49.648]     INFO: 6 hot pixels found in step 0
[19:49:50.658]     INFO: Collecting data for 5 seconds...
[19:49:55.675]     INFO: Done with hot pixel readout
[19:50:07.150]     INFO: PixTest::       pg_setup set to default.
[19:50:07.151]     INFO: 5 hot pixels found in step 1
[19:50:08.141]     INFO: Collecting data for 5 seconds...
[19:50:13.157]     INFO: Done with hot pixel readout
[19:50:24.709]     INFO: PixTest::       pg_setup set to default.
[19:50:24.710]     INFO: 3 hot pixels found in step 2
[19:50:25.702]     INFO: Collecting data for 5 seconds...
[19:50:30.718]     INFO: Done with hot pixel readout
[19:50:42.212]     INFO: PixTest::       pg_setup set to default.
[19:50:42.213]     INFO: 1 hot pixels found in step 3
[19:50:43.205]     INFO: Collecting data for 5 seconds...
[19:50:48.222]     INFO: Done with hot pixel readout
[19:50:59.747]     INFO: PixTest::       pg_setup set to default.
[19:50:59.748]     INFO: 2 hot pixels found in step 4
[19:51:00.739]     INFO: Collecting data for 5 seconds...
[19:51:05.756]     INFO: Done with hot pixel readout
[19:51:17.277]     INFO: PixTest::       pg_setup set to default.
[19:51:17.278]     INFO: 1 hot pixels found in step 5
[19:51:18.269]     INFO: Collecting data for 5 seconds...
[19:51:23.287]     INFO: Done with hot pixel readout
[19:51:34.745]     INFO: PixTest::       pg_setup set to default.
[19:51:34.746]     INFO: 2 hot pixels found in step 6
[19:51:35.737]     INFO: Collecting data for 5 seconds...
[19:51:40.754]     INFO: Done with hot pixel readout
[19:51:52.224]     INFO: PixTest::       pg_setup set to default.
[19:51:52.225]     INFO: 3 hot pixels found in step 7
[19:51:53.217]     INFO: Collecting data for 5 seconds...
[19:51:58.234]     INFO: Done with hot pixel readout
[19:52:09.753]     INFO: PixTest::       pg_setup set to default.
[19:52:09.754]     INFO: 1 hot pixels found in step 8
[19:52:10.746]     INFO: Collecting data for 5 seconds...
[19:52:15.762]     INFO: Done with hot pixel readout
[19:52:27.267]     INFO: PixTest::       pg_setup set to default.
[19:52:27.267]     INFO: 1 hot pixels found in step 9
[19:52:28.260]     INFO: Collecting data for 5 seconds...
[19:52:33.277]     INFO: Done with hot pixel readout
[19:52:44.807]     INFO: PixTest::       pg_setup set to default.
[19:52:44.808]     INFO: 2 hot pixels found in step 10
[19:52:45.800]     INFO: Collecting data for 5 seconds...
[19:52:50.817]     INFO: Done with hot pixel readout
[19:53:02.288]     INFO: PixTest::       pg_setup set to default.
[19:53:02.289]     INFO: 0 hot pixels found in step 11
[19:53:02.324]     INFO: 0 hot pixels could not be trimmed and have been masked.
[19:53:02.328]     INFO: PixTest::trimHotPixels() done
[19:53:02.328]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat
[19:53:02.340]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C1.dat
[19:53:02.346]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C2.dat
[19:53:02.352]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C3.dat
[19:53:02.357]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C4.dat
[19:53:02.362]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C5.dat
[19:53:02.368]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C6.dat
[19:53:02.373]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C7.dat
[19:53:02.378]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C8.dat
[19:53:02.383]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C9.dat
[19:53:02.389]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C10.dat
[19:53:02.394]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C11.dat
[19:53:02.399]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C12.dat
[19:53:02.404]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C13.dat
[19:53:02.410]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C14.dat
[19:53:02.415]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[19:53:02.420]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[19:53:02.438]     INFO: enter test to run
[19:54:04.508]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[19:54:04.508]     INFO:   running: highrate
[19:54:04.512]     INFO:    ----------------------------------------------------------------------
[19:54:04.512]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[19:54:04.512]     INFO:    ----------------------------------------------------------------------
[19:54:04.512]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[19:54:04.512]     INFO: edge/corner pixel THR is adjusted
[19:54:04.512]     INFO: PixTestHighRate::trimHotPixels: step 0...
[19:54:05.471]     INFO: Collecting data for 1 seconds...
[19:54:06.476]     INFO: Done with hot pixel readout
[19:54:10.463]     INFO: PixTest::       pg_setup set to default.
[19:54:10.464]     INFO: 0 hot pixels found in step 0
[19:54:10.469]     INFO: 0 hot pixels could not be trimmed and have been masked.
[19:54:10.560]     INFO: PixTest::trimHotPixels() done
[19:54:10.560]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C0.dat
[19:54:10.572]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C1.dat
[19:54:10.579]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C2.dat
[19:54:10.584]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C3.dat
[19:54:10.589]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C4.dat
[19:54:10.595]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C5.dat
[19:54:10.600]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C6.dat
[19:54:10.605]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C7.dat
[19:54:10.611]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C8.dat
[19:54:10.616]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C9.dat
[19:54:10.621]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C10.dat
[19:54:10.627]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C11.dat
[19:54:10.632]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C12.dat
[19:54:10.637]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C13.dat
[19:54:10.642]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C14.dat
[19:54:10.648]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//trimParameters35_C15.dat
[19:54:10.653]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-07_FPIXTest-17C-FNAL-160906-1408-150V_2016-09-06_14h08m_1473188910/000_FPIXTest_p17//defaultMaskFile.dat
[19:54:10.663]     INFO: enter test to run
[19:54:38.379]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[19:54:38.379]     INFO:   running: xray
[19:54:38.381]     INFO:    ----------------------------------------------------------------------
[19:54:38.381]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[19:54:38.381]     INFO:    ----------------------------------------------------------------------
[19:54:39.344]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[19:54:50.933]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[19:55:20.688]     INFO: Resuming triggers.
[19:55:32.271]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[19:56:02.270]     INFO: Resuming triggers.
[19:56:13.856]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[19:56:43.790]     INFO: Resuming triggers.
[19:56:55.376]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[19:57:25.400]     INFO: Resuming triggers.
[19:57:36.986]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[19:58:06.014]     INFO: Resuming triggers.
[19:58:17.602]     INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[19:58:47.213]     INFO: Resuming triggers.
[19:58:58.804]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[19:59:29.414]     INFO: Resuming triggers.
[19:59:40.005]     INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[20:00:11.107]     INFO: Resuming triggers.
[20:00:18.771]     INFO: data taking finished, elapsed time: 100 seconds.
[20:00:38.875]     INFO: PixTest::       pg_setup set to default.
[20:00:38.878]     INFO: PixTestXray::doPhRun() done
[20:00:39.047]     INFO: enter test to run
[20:01:11.281]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[20:01:11.281]     INFO:   running: xray
[20:01:11.283]     INFO:    ----------------------------------------------------------------------
[20:01:11.283]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[20:01:11.283]     INFO:    ----------------------------------------------------------------------
[20:01:12.245]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[20:01:18.983]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[20:01:50.255]     INFO: Resuming triggers.
[20:01:56.992]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[20:02:27.270]     INFO: Resuming triggers.
[20:02:34.007]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[20:03:04.274]     INFO: Resuming triggers.
[20:03:11.010]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[20:03:41.263]     INFO: Resuming triggers.
[20:03:47.996]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[20:04:18.244]     INFO: Resuming triggers.
[20:04:24.980]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[20:04:55.196]     INFO: Resuming triggers.
[20:05:01.929]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[20:05:32.187]     INFO: Resuming triggers.
[20:05:38.920]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[20:06:09.159]     INFO: Resuming triggers.
[20:06:15.892]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[20:06:46.074]     INFO: Resuming triggers.
[20:06:52.809]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[20:07:23.098]     INFO: Resuming triggers.
[20:07:29.831]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[20:08:00.062]     INFO: Resuming triggers.
[20:08:06.796]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[20:08:37.057]     INFO: Resuming triggers.
[20:08:43.793]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[20:09:14.696]     INFO: Resuming triggers.
[20:09:21.432]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[20:09:52.281]     INFO: Resuming triggers.
[20:09:58.331]     INFO: data taking finished, elapsed time: 100 seconds.
[20:10:26.278]     INFO: PixTest::       pg_setup set to default.
[20:10:26.281]     INFO: PixTestXray::doPhRun() done
[20:10:26.433]     INFO: enter test to run
[20:11:06.596]     INFO:   test: HighRate no parameter change
[20:11:06.596]     INFO:   running: highrate
[20:11:06.616]     INFO:    ----------------------------------------------------------------------
[20:11:06.616]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[20:11:06.616]     INFO:    ----------------------------------------------------------------------
[20:11:06.762]     INFO: Expecting 768 events.
[20:11:07.891]     INFO: 768 events read in total (414ms).
[20:11:07.892]     INFO: Test took 1264ms.
[20:11:08.694]     INFO: Expecting 41600 events.
[20:11:11.841]     INFO: 41600 events read in total (2620ms).
[20:11:11.842]     INFO: Test took 3928ms.
[20:11:11.876]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:12.603]     INFO: Expecting 41600 events.
[20:11:15.867]     INFO: 41600 events read in total (2737ms).
[20:11:15.868]     INFO: Test took 3976ms.
[20:11:15.903]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:16.628]     INFO: Expecting 41600 events.
[20:11:19.810]     INFO: 41600 events read in total (2655ms).
[20:11:19.811]     INFO: Test took 3891ms.
[20:11:19.846]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:20.564]     INFO: Expecting 41600 events.
[20:11:23.821]     INFO: 41600 events read in total (2731ms).
[20:11:23.822]     INFO: Test took 3957ms.
[20:11:23.857]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:24.577]     INFO: Expecting 41600 events.
[20:11:27.732]     INFO: 41600 events read in total (2628ms).
[20:11:27.733]     INFO: Test took 3858ms.
[20:11:27.768]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:28.489]     INFO: Expecting 41600 events.
[20:11:31.726]     INFO: 41600 events read in total (2710ms).
[20:11:31.727]     INFO: Test took 3941ms.
[20:11:31.761]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:32.479]     INFO: Expecting 41600 events.
[20:11:35.722]     INFO: 41600 events read in total (2716ms).
[20:11:35.723]     INFO: Test took 3943ms.
[20:11:35.757]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:36.477]     INFO: Expecting 41600 events.
[20:11:39.698]     INFO: 41600 events read in total (2694ms).
[20:11:39.698]     INFO: Test took 3921ms.
[20:11:39.733]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:40.452]     INFO: Expecting 41600 events.
[20:11:43.631]     INFO: 41600 events read in total (2652ms).
[20:11:43.632]     INFO: Test took 3882ms.
[20:11:43.666]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:44.380]     INFO: Expecting 41600 events.
[20:11:47.523]     INFO: 41600 events read in total (2616ms).
[20:11:47.524]     INFO: Test took 3841ms.
[20:11:47.560]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:48.283]     INFO: Expecting 41600 events.
[20:11:51.460]     INFO: 41600 events read in total (2651ms).
[20:11:51.461]     INFO: Test took 3882ms.
[20:11:51.494]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:52.214]     INFO: Expecting 41600 events.
[20:11:55.476]     INFO: 41600 events read in total (2735ms).
[20:11:55.477]     INFO: Test took 3965ms.
[20:11:55.513]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:56.234]     INFO: Expecting 41600 events.
[20:11:59.506]     INFO: 41600 events read in total (2746ms).
[20:11:59.507]     INFO: Test took 3977ms.
[20:11:59.542]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:00.264]     INFO: Expecting 41600 events.
[20:12:03.542]     INFO: 41600 events read in total (2751ms).
[20:12:03.543]     INFO: Test took 3983ms.
[20:12:03.577]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:04.300]     INFO: Expecting 41600 events.
[20:12:07.485]     INFO: 41600 events read in total (2658ms).
[20:12:07.486]     INFO: Test took 3891ms.
[20:12:07.520]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:08.237]     INFO: Expecting 41600 events.
[20:12:11.579]     INFO: 41600 events read in total (2815ms).
[20:12:11.580]     INFO: Test took 4042ms.
[20:12:11.615]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:12.335]     INFO: Expecting 41600 events.
[20:12:15.610]     INFO: 41600 events read in total (2749ms).
[20:12:15.611]     INFO: Test took 3977ms.
[20:12:15.645]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:16.364]     INFO: Expecting 41600 events.
[20:12:19.744]     INFO: 41600 events read in total (2854ms).
[20:12:19.745]     INFO: Test took 4082ms.
[20:12:19.780]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:20.504]     INFO: Expecting 41600 events.
[20:12:23.760]     INFO: 41600 events read in total (2730ms).
[20:12:23.761]     INFO: Test took 3964ms.
[20:12:23.796]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:24.520]     INFO: Expecting 41600 events.
[20:12:27.656]     INFO: 41600 events read in total (2610ms).
[20:12:27.657]     INFO: Test took 3844ms.
[20:12:27.691]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:28.046]     INFO: enter test to run
[20:12:58.260]     INFO:   test: HighRate no parameter change
[20:12:58.260]     INFO:   running: highrate
[20:12:58.261]     INFO:    ----------------------------------------------------------------------
[20:12:58.261]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:12:58.261]     INFO:    ----------------------------------------------------------------------
[20:12:58.882]     INFO: Expecting 208000 events.
[20:13:10.876]     INFO: 208000 events read in total (11467ms).
[20:13:10.879]     INFO: Test took 12609ms.
[20:13:11.022]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:11.273]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    0
[20:13:11.273]     INFO: number of red-efficiency pixels:    93   32   76  117  110  129  123   87   97  115  116  113  118   79   28   32
[20:13:11.273]     INFO: number of X-ray hits detected:    62331 39547 63902 97624 104824 106029 103379 73301 76168 105315 102746 89075 95782 58146 22717 25539
[20:13:11.273]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:13:11.273]     INFO: number of Vcal hits detected:  207905 207967 207922 207882 207889 207870 207874 207909 207901 207885 207882 207886 207879 207870 207923 207968
[20:13:11.273]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[20:13:11.273]     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
[20:13:11.274]     INFO: X-ray hit rate [MHz/cm2]:  18.3 11.6 18.7 28.6 30.7 31.1 30.3 21.5 22.3 30.9 30.1 26.1 28.1 17.0 6.7 7.5
[20:13:11.274]     INFO: PixTestHighRate::doXPixelAlive() done
[20:13:11.327]     INFO: PixTest::       pg_setup set to default.
[20:13:11.343]     INFO: enter test to run
[20:13:47.284]     INFO:   test: HighRate no parameter change
[20:13:47.284]     INFO:   running: highrate
[20:13:47.285]     INFO:    ----------------------------------------------------------------------
[20:13:47.285]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:13:47.285]     INFO:    ----------------------------------------------------------------------
[20:13:47.903]     INFO: Expecting 208000 events.
[20:14:01.556]     INFO: 208000 events read in total (13126ms).
[20:14:01.561]     INFO: Test took 14267ms.
[20:14:01.857]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:14:02.160]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    0
[20:14:02.160]     INFO: number of red-efficiency pixels:   227  140  217  339  361  359  370  223  275  393  365  316  345  244   65   54
[20:14:02.160]     INFO: number of X-ray hits detected:    129273 81760 133587 204410 218614 219791 214898 153167 160692 218853 215022 185637 199733 121382 47114 53228
[20:14:02.160]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:14:02.160]     INFO: number of Vcal hits detected:  207758 207850 207764 207640 207620 207609 207598 207764 207699 207581 207609 207657 207645 207688 207886 207941
[20:14:02.160]     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.9 99.8 99.9 100.0 100.0
[20:14:02.160]     INFO: Vcal hit overall 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 99.9 100.0
[20:14:02.161]     INFO: X-ray hit rate [MHz/cm2]:  37.9 24.0 39.2 59.9 64.1 64.4 63.0 44.9 47.1 64.1 63.0 54.4 58.5 35.6 13.8 15.6
[20:14:02.161]     INFO: PixTestHighRate::doXPixelAlive() done
[20:14:02.206]     INFO: PixTest::       pg_setup set to default.
[20:14:02.216]     INFO: enter test to run
[20:14:20.131]     INFO:   test: HighRate no parameter change
[20:14:20.131]     INFO:   running: highrate
[20:14:20.133]     INFO:    ----------------------------------------------------------------------
[20:14:20.133]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:14:20.133]     INFO:    ----------------------------------------------------------------------
[20:14:20.757]     INFO: Expecting 208000 events.
[20:14:36.620]     INFO: 208000 events read in total (15336ms).
[20:14:36.628]     INFO: Test took 16486ms.
[20:14:37.068]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:14:37.414]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    0
[20:14:37.414]     INFO: number of red-efficiency pixels:   509  236  465  697  868  888  896  530  583  938  859  656  724  541  100   87
[20:14:37.414]     INFO: number of X-ray hits detected:    193639 124148 199836 305466 328360 329886 322144 228547 239970 327026 322209 279041 299871 181453 71110 81619
[20:14:37.414]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:14:37.414]     INFO: number of Vcal hits detected:  207380 207745 207422 207202 206962 206951 206908 207382 207325 206886 206936 207221 207166 207289 207845 207909
[20:14:37.414]     INFO: Vcal hit fiducial efficiency (%):  99.7 99.9 99.8 99.7 99.5 99.5 99.5 99.7 99.7 99.5 99.5 99.7 99.6 99.7 100.0 100.0
[20:14:37.414]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 99.7 99.6 99.5 99.5 99.5 99.7 99.7 99.5 99.5 99.6 99.6 99.7 99.9 100.0
[20:14:37.414]     INFO: X-ray hit rate [MHz/cm2]:  56.8 36.4 58.6 89.5 96.2 96.7 94.4 67.0 70.3 95.9 94.4 81.8 87.9 53.2 20.8 23.9
[20:14:37.414]     INFO: PixTestHighRate::doXPixelAlive() done
[20:14:37.463]     INFO: PixTest::       pg_setup set to default.
[20:14:37.481]     INFO: enter test to run
[20:14:53.211]     INFO:   test: exit no parameter change
[20:14:53.631]    QUIET: Connection to board 33 closed.
[20:14:53.645]     INFO: pXar: this is the end, my friend