[15:07:25.823]     INFO: *** Welcome to pxar ***
[15:07:25.823]     INFO: *** Today: 2016/08/11
[15:07:25.844]     INFO: *** Version: v1.9.0-818-g96727
[15:07:25.844]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//dacParameters35_C15.dat
[15:07:26.157]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:07:26.157]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//defaultMaskFile.dat
[15:07:26.186]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C15.dat
[15:07:27.551]     INFO:         clk: 4
[15:07:27.551]     INFO:         ctr: 4
[15:07:27.551]     INFO:         sda: 19
[15:07:27.551]     INFO:         tin: 9
[15:07:27.551]     INFO:         level: 15
[15:07:27.551]     INFO:         triggerdelay: 0
[15:07:27.551]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:07:27.551]     INFO: Log level: INFO
[15:07:27.568]    QUIET: Connection to board DTB_WREKRL opened.
[15:07:27.571]     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:     
------------------------------------------------------
[15:07:27.574]     INFO: RPC call hashes of host and DTB match: 398089610
[15:07:29.109]     INFO: DUT info: 
[15:07:29.109]     INFO: The DUT currently contains the following objects:
[15:07:29.109]     INFO:  2 TBM Cores tbm08c (2 ON)
[15:07:29.109]     INFO: 	TBM Core alpha (0): 7 registers set
[15:07:29.109]     INFO: 	TBM Core beta  (1): 7 registers set
[15:07:29.109]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:07:29.110]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.110]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.111]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.111]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.111]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.111]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.111]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:29.584]     INFO: enter 'restricted' command line mode
[15:07:29.584]     INFO: enter test to run
[15:07:37.591]     INFO:   test: PixelAlive no parameter change
[15:07:37.591]     INFO:   running: pixelalive
[15:07:37.600]     INFO:    ----------------------------------------------------------------------
[15:07:37.600]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:07:37.600]     INFO:    ----------------------------------------------------------------------
[15:07:37.921]     INFO: Expecting 41600 events.
[15:07:42.217]     INFO: 41600 events read in total (3578ms).
[15:07:42.381]     INFO: Test took 4778ms.
[15:07:42.392]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:42.657]     INFO: PixTestAlive::aliveTest() done
[15:07:42.657]     INFO: number of dead pixels (per ROC):     2    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[15:07:42.686]     INFO: enter test to run
[15:08:08.671]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:08:08.671]     INFO:   running: highrate
[15:08:08.671]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:08:08.893]     INFO:    ----------------------------------------------------------------------
[15:08:08.893]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:08:08.893]     INFO:    ----------------------------------------------------------------------
[15:08:08.893]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:08:08.893]     INFO: edge/corner pixel THR is adjusted
[15:08:08.893]     INFO: PixTestHighRate::trimHotPixels: step 0...
[15:08:09.851]     INFO: Collecting data for 5 seconds...
[15:08:14.873]     INFO: Done with hot pixel readout
[15:08:26.232]     INFO: PixTest::       pg_setup set to default.
[15:08:26.233]     INFO: 2 hot pixels found in step 0
[15:08:27.238]     INFO: Collecting data for 5 seconds...
[15:08:32.256]     INFO: Done with hot pixel readout
[15:08:43.216]     INFO: PixTest::       pg_setup set to default.
[15:08:43.217]     INFO: 2 hot pixels found in step 1
[15:08:44.205]     INFO: Collecting data for 5 seconds...
[15:08:49.222]     INFO: Done with hot pixel readout
[15:09:00.552]     INFO: PixTest::       pg_setup set to default.
[15:09:00.553]     INFO: 1 hot pixels found in step 2
[15:09:01.543]     INFO: Collecting data for 5 seconds...
[15:09:06.561]     INFO: Done with hot pixel readout
[15:09:17.985]     INFO: PixTest::       pg_setup set to default.
[15:09:17.986]     INFO: 1 hot pixels found in step 3
[15:09:18.975]     INFO: Collecting data for 5 seconds...
[15:09:23.994]     INFO: Done with hot pixel readout
[15:09:35.196]     INFO: PixTest::       pg_setup set to default.
[15:09:35.196]     INFO: 1 hot pixels found in step 4
[15:09:36.185]     INFO: Collecting data for 5 seconds...
[15:09:41.202]     INFO: Done with hot pixel readout
[15:09:52.566]     INFO: PixTest::       pg_setup set to default.
[15:09:52.566]     INFO: 1 hot pixels found in step 5
[15:09:53.556]     INFO: Collecting data for 5 seconds...
[15:09:58.573]     INFO: Done with hot pixel readout
[15:10:09.792]     INFO: PixTest::       pg_setup set to default.
[15:10:09.793]     INFO: 0 hot pixels found in step 6
[15:10:09.827]     INFO: 0 hot pixels could not be trimmed and have been masked.
[15:10:09.830]     INFO: PixTest::trimHotPixels() done
[15:10:09.830]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C0.dat
[15:10:09.837]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C1.dat
[15:10:09.843]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C2.dat
[15:10:09.848]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C3.dat
[15:10:09.853]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C4.dat
[15:10:09.859]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C5.dat
[15:10:09.864]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C6.dat
[15:10:09.869]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C7.dat
[15:10:09.875]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C8.dat
[15:10:09.880]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C9.dat
[15:10:09.885]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C10.dat
[15:10:09.890]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C11.dat
[15:10:09.896]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C12.dat
[15:10:09.901]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C13.dat
[15:10:09.906]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C14.dat
[15:10:09.912]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C15.dat
[15:10:09.917]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//defaultMaskFile.dat
[15:10:09.927]     INFO: enter test to run
[15:11:57.909]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:11:57.910]     INFO:   running: highrate
[15:11:57.914]     INFO:    ----------------------------------------------------------------------
[15:11:57.914]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:11:57.914]     INFO:    ----------------------------------------------------------------------
[15:11:57.914]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:11:57.914]     INFO: edge/corner pixel THR is adjusted
[15:11:57.914]     INFO: PixTestHighRate::trimHotPixels: step 0...
[15:11:58.872]     INFO: Collecting data for 1 seconds...
[15:11:59.876]     INFO: Done with hot pixel readout
[15:12:03.618]     INFO: PixTest::       pg_setup set to default.
[15:12:03.619]     INFO: 0 hot pixels found in step 0
[15:12:03.625]     INFO: 0 hot pixels could not be trimmed and have been masked.
[15:12:03.726]     INFO: PixTest::trimHotPixels() done
[15:12:03.726]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C0.dat
[15:12:03.736]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C1.dat
[15:12:03.741]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C2.dat
[15:12:03.747]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C3.dat
[15:12:03.752]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C4.dat
[15:12:03.757]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C5.dat
[15:12:03.763]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C6.dat
[15:12:03.768]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C7.dat
[15:12:03.773]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C8.dat
[15:12:03.779]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C9.dat
[15:12:03.784]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C10.dat
[15:12:03.789]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C11.dat
[15:12:03.794]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C12.dat
[15:12:03.800]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C13.dat
[15:12:03.805]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C14.dat
[15:12:03.813]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//trimParameters35_C15.dat
[15:12:03.818]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-46_FPIXTest-17C-FNAL-160804-0915_2016-08-04_09h15m_1470320140/000_FPIXTest_p17//defaultMaskFile.dat
[15:12:03.827]     INFO: enter test to run
[15:12:27.533]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[15:12:27.533]     INFO:   running: xray
[15:12:27.535]     INFO:    ----------------------------------------------------------------------
[15:12:27.535]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[15:12:27.535]     INFO:    ----------------------------------------------------------------------
[15:12:28.498]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[15:12:40.729]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:13:09.999]     INFO: Resuming triggers.
[15:13:22.233]     INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[15:13:51.508]     INFO: Resuming triggers.
[15:14:03.743]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:14:32.987]     INFO: Resuming triggers.
[15:14:45.230]     INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:15:14.489]     INFO: Resuming triggers.
[15:15:26.728]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[15:15:56.237]     INFO: Resuming triggers.
[15:16:08.477]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:16:37.755]     INFO: Resuming triggers.
[15:16:49.999]     INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:17:19.276]     INFO: Resuming triggers.
[15:17:31.518]     INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:18:00.954]     INFO: Resuming triggers.
[15:18:03.381]     INFO: data taking finished, elapsed time: 100 seconds.
[15:18:09.404]     INFO: PixTest::       pg_setup set to default.
[15:18:09.407]     INFO: PixTestXray::doPhRun() done
[15:18:09.544]     INFO: enter test to run
[15:18:30.531]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[15:18:30.531]     INFO:   running: xray
[15:18:30.532]     INFO:    ----------------------------------------------------------------------
[15:18:30.532]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[15:18:30.532]     INFO:    ----------------------------------------------------------------------
[15:18:31.503]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[15:18:38.850]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:19:09.421]     INFO: Resuming triggers.
[15:19:16.772]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[15:19:48.209]     INFO: Resuming triggers.
[15:19:55.563]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:20:26.686]     INFO: Resuming triggers.
[15:20:34.039]     INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[15:21:04.327]     INFO: Resuming triggers.
[15:21:11.683]     INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:21:41.762]     INFO: Resuming triggers.
[15:21:49.121]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:22:19.307]     INFO: Resuming triggers.
[15:22:26.665]     INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:22:56.962]     INFO: Resuming triggers.
[15:23:04.325]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:23:34.488]     INFO: Resuming triggers.
[15:23:41.851]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:24:12.012]     INFO: Resuming triggers.
[15:24:19.380]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:24:49.583]     INFO: Resuming triggers.
[15:24:56.953]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:25:27.140]     INFO: Resuming triggers.
[15:25:34.510]     INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:26:04.678]     INFO: Resuming triggers.
[15:26:12.050]     INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:26:42.190]     INFO: Resuming triggers.
[15:26:46.847]     INFO: data taking finished, elapsed time: 100 seconds.
[15:27:06.148]     INFO: PixTest::       pg_setup set to default.
[15:27:06.152]     INFO: PixTestXray::doPhRun() done
[15:27:06.298]     INFO: enter test to run
[15:27:29.503]     INFO:   test: HighRate no parameter change
[15:27:29.503]     INFO:   running: highrate
[15:27:29.504]     INFO:    ----------------------------------------------------------------------
[15:27:29.504]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:27:29.504]     INFO:    ----------------------------------------------------------------------
[15:27:29.645]     INFO: Expecting 768 events.
[15:27:30.779]     INFO: 768 events read in total (419ms).
[15:27:30.779]     INFO: Test took 1268ms.
[15:27:31.582]     INFO: Expecting 41600 events.
[15:27:34.651]     INFO: 41600 events read in total (2542ms).
[15:27:34.652]     INFO: Test took 3866ms.
[15:27:34.683]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:35.416]     INFO: Expecting 41600 events.
[15:27:38.578]     INFO: 41600 events read in total (2635ms).
[15:27:38.579]     INFO: Test took 3878ms.
[15:27:38.610]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:39.342]     INFO: Expecting 41600 events.
[15:27:42.547]     INFO: 41600 events read in total (2677ms).
[15:27:42.548]     INFO: Test took 3921ms.
[15:27:42.578]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:43.306]     INFO: Expecting 41600 events.
[15:27:46.507]     INFO: 41600 events read in total (2674ms).
[15:27:46.508]     INFO: Test took 3914ms.
[15:27:46.538]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:47.268]     INFO: Expecting 41600 events.
[15:27:50.467]     INFO: 41600 events read in total (2673ms).
[15:27:50.468]     INFO: Test took 3914ms.
[15:27:50.498]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:51.226]     INFO: Expecting 41600 events.
[15:27:54.347]     INFO: 41600 events read in total (2594ms).
[15:27:54.348]     INFO: Test took 3832ms.
[15:27:54.378]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:55.110]     INFO: Expecting 41600 events.
[15:27:58.320]     INFO: 41600 events read in total (2683ms).
[15:27:58.321]     INFO: Test took 3925ms.
[15:27:58.352]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:59.085]     INFO: Expecting 41600 events.
[15:28:02.276]     INFO: 41600 events read in total (2664ms).
[15:28:02.277]     INFO: Test took 3908ms.
[15:28:02.307]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:03.038]     INFO: Expecting 41600 events.
[15:28:06.236]     INFO: 41600 events read in total (2672ms).
[15:28:06.237]     INFO: Test took 3914ms.
[15:28:06.267]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:06.995]     INFO: Expecting 41600 events.
[15:28:10.207]     INFO: 41600 events read in total (2685ms).
[15:28:10.208]     INFO: Test took 3925ms.
[15:28:10.239]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:10.967]     INFO: Expecting 41600 events.
[15:28:14.167]     INFO: 41600 events read in total (2673ms).
[15:28:14.168]     INFO: Test took 3911ms.
[15:28:14.199]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:14.926]     INFO: Expecting 41600 events.
[15:28:18.127]     INFO: 41600 events read in total (2674ms).
[15:28:18.128]     INFO: Test took 3913ms.
[15:28:18.158]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:18.886]     INFO: Expecting 41600 events.
[15:28:22.088]     INFO: 41600 events read in total (2675ms).
[15:28:22.089]     INFO: Test took 3915ms.
[15:28:22.120]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:22.851]     INFO: Expecting 41600 events.
[15:28:26.059]     INFO: 41600 events read in total (2681ms).
[15:28:26.060]     INFO: Test took 3922ms.
[15:28:26.090]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:26.818]     INFO: Expecting 41600 events.
[15:28:30.019]     INFO: 41600 events read in total (2674ms).
[15:28:30.019]     INFO: Test took 3913ms.
[15:28:30.050]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:30.778]     INFO: Expecting 41600 events.
[15:28:33.982]     INFO: 41600 events read in total (2677ms).
[15:28:33.983]     INFO: Test took 3915ms.
[15:28:34.014]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:34.745]     INFO: Expecting 41600 events.
[15:28:37.964]     INFO: 41600 events read in total (2692ms).
[15:28:37.965]     INFO: Test took 3933ms.
[15:28:37.996]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:38.725]     INFO: Expecting 41600 events.
[15:28:41.926]     INFO: 41600 events read in total (2674ms).
[15:28:41.926]     INFO: Test took 3912ms.
[15:28:41.956]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:42.689]     INFO: Expecting 41600 events.
[15:28:45.873]     INFO: 41600 events read in total (2657ms).
[15:28:45.874]     INFO: Test took 3901ms.
[15:28:45.904]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:46.636]     INFO: Expecting 41600 events.
[15:28:49.699]     INFO: 41600 events read in total (2536ms).
[15:28:49.700]     INFO: Test took 3778ms.
[15:28:49.731]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:50.095]     INFO: enter test to run
[15:29:03.631]     INFO:   test: HighRate no parameter change
[15:29:03.631]     INFO:   running: highrate
[15:29:03.653]     INFO:    ----------------------------------------------------------------------
[15:29:03.653]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:29:03.653]     INFO:    ----------------------------------------------------------------------
[15:29:04.273]     INFO: Expecting 208000 events.
[15:29:15.920]     INFO: 208000 events read in total (11120ms).
[15:29:15.923]     INFO: Test took 12261ms.
[15:29:16.053]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:16.302]     INFO: number of dead pixels (per ROC):     2    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[15:29:16.302]     INFO: number of red-efficiency pixels:    79   37   60   99  110  100  122  105   89  102  110   83   88   54   21   24
[15:29:16.302]     INFO: number of X-ray hits detected:    53491 34962 52994 85334 90733 96841 98655 73841 75271 87367 88070 75190 79033 46726 18471 20996
[15:29:16.302]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:29:16.302]     INFO: number of Vcal hits detected:  207822 207963 207940 207900 207888 207893 207877 207890 207911 207897 207890 207917 207909 207946 207979 207976
[15:29:16.302]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:29:16.302]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:29:16.302]     INFO: X-ray hit rate [MHz/cm2]:  15.7 10.2 15.5 25.0 26.6 28.4 28.9 21.6 22.1 25.6 25.8 22.0 23.2 13.7 5.4 6.2
[15:29:16.302]     INFO: PixTestHighRate::doXPixelAlive() done
[15:29:16.348]     INFO: PixTest::       pg_setup set to default.
[15:29:16.364]     INFO: enter test to run
[15:29:30.870]     INFO:   test: HighRate no parameter change
[15:29:30.870]     INFO:   running: highrate
[15:29:30.872]     INFO:    ----------------------------------------------------------------------
[15:29:30.872]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:29:30.872]     INFO:    ----------------------------------------------------------------------
[15:29:31.496]     INFO: Expecting 208000 events.
[15:29:44.948]     INFO: 208000 events read in total (12925ms).
[15:29:44.952]     INFO: Test took 14072ms.
[15:29:45.221]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:45.513]     INFO: number of dead pixels (per ROC):     2    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[15:29:45.513]     INFO: number of red-efficiency pixels:   161  112  156  314  284  329  438  243  207  306  286  252  291  168   36   50
[15:29:45.513]     INFO: number of X-ray hits detected:    110870 71934 110774 179311 189414 202516 205288 156024 157683 183698 183141 157412 166182 99525 39160 43649
[15:29:45.513]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:29:45.513]     INFO: number of Vcal hits detected:  207734 207884 207832 207663 207708 207630 207535 207745 207784 207681 207702 207738 207698 207822 207963 207950
[15:29:45.513]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[15:29:45.514]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[15:29:45.514]     INFO: X-ray hit rate [MHz/cm2]:  32.5 21.1 32.5 52.6 55.5 59.4 60.2 45.7 46.2 53.8 53.7 46.1 48.7 29.2 11.5 12.8
[15:29:45.514]     INFO: PixTestHighRate::doXPixelAlive() done
[15:29:45.567]     INFO: PixTest::       pg_setup set to default.
[15:29:45.582]     INFO: enter test to run
[15:30:00.614]     INFO:   test: HighRate no parameter change
[15:30:00.614]     INFO:   running: highrate
[15:30:00.615]     INFO:    ----------------------------------------------------------------------
[15:30:00.615]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:30:00.615]     INFO:    ----------------------------------------------------------------------
[15:30:01.234]     INFO: Expecting 208000 events.
[15:30:15.867]     INFO: 208000 events read in total (14106ms).
[15:30:15.873]     INFO: Test took 15249ms.
[15:30:16.249]     INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:16.578]     INFO: number of dead pixels (per ROC):     2    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[15:30:16.578]     INFO: number of red-efficiency pixels:   340  186  307  707  560  614  897  611  386  621  607  532  588  331   71   71
[15:30:16.578]     INFO: number of X-ray hits detected:    160567 104335 161496 260779 273672 293404 297720 225939 228645 265020 265120 228365 240135 143395 57326 63444
[15:30:16.578]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:30:16.578]     INFO: number of Vcal hits detected:  207526 207806 207657 207203 207390 207295 206929 207278 207580 207307 207323 207401 207345 207627 207928 207928
[15:30:16.578]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.8 99.6 99.7 99.7 99.5 99.7 99.8 99.7 99.7 99.7 99.7 99.8 100.0 100.0
[15:30:16.578]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.8 99.6 99.7 99.7 99.5 99.7 99.8 99.7 99.7 99.7 99.7 99.8 100.0 100.0
[15:30:16.578]     INFO: X-ray hit rate [MHz/cm2]:  47.1 30.6 47.3 76.4 80.2 86.0 87.3 66.2 67.0 77.7 77.7 66.9 70.4 42.0 16.8 18.6
[15:30:16.578]     INFO: PixTestHighRate::doXPixelAlive() done
[15:30:16.625]     INFO: PixTest::       pg_setup set to default.
[15:30:16.647]     INFO: enter test to run
[15:30:24.454]     INFO:   test: exit no parameter change
[15:30:24.772]    QUIET: Connection to board 33 closed.
[15:30:24.773]     INFO: pXar: this is the end, my friend