[11:46:43.368]     INFO: *** Welcome to pxar ***
[11:46:43.368]     INFO: *** Today: 2016/05/31
[11:46:43.385]     INFO: *** Version: v1.9.0-796-gef167-dirty
[11:46:43.385]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//dacParameters35_C15.dat
[11:46:43.428]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:46:43.428]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//defaultMaskFile.dat
[11:46:43.435]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C15.dat
[11:46:43.533]     INFO:         clk: 4
[11:46:43.533]     INFO:         ctr: 4
[11:46:43.533]     INFO:         sda: 19
[11:46:43.533]     INFO:         tin: 9
[11:46:43.533]     INFO:         level: 15
[11:46:43.533]     INFO:         triggerdelay: 0
[11:46:43.533]    QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:46:43.533]     INFO: Log level: INFO
[11:46:43.551]    QUIET: Connection to board DTB_WREKRL opened.
[11:46:43.554]     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:     
------------------------------------------------------
[11:46:43.557]     INFO: RPC call hashes of host and DTB match: 398089610
[11:46:45.085]     INFO: DUT info: 
[11:46:45.085]     INFO: The DUT currently contains the following objects:
[11:46:45.085]     INFO:  2 TBM Cores tbm08c (2 ON)
[11:46:45.085]     INFO: 	TBM Core alpha (0): 7 registers set
[11:46:45.085]     INFO: 	TBM Core beta  (1): 7 registers set
[11:46:45.085]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:46:45.085]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.085]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.085]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.085]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.085]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.086]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:46:45.489]     INFO: enter 'restricted' command line mode
[11:46:45.489]     INFO: enter test to run
[11:47:07.457]     INFO:   test: PixelAlive no parameter change
[11:47:07.457]     INFO:   running: pixelalive
[11:47:07.466]     INFO:    ----------------------------------------------------------------------
[11:47:07.466]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:47:07.467]     INFO:    ----------------------------------------------------------------------
[11:47:07.780]     INFO: Expecting 41600 events.
[11:47:12.103]     INFO: 41600 events read in total (3604ms).
[11:47:12.267]     INFO: Test took 4798ms.
[11:47:12.277]     INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:12.540]     INFO: PixTestAlive::aliveTest() done
[11:47:12.540]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[11:47:12.571]     INFO: enter test to run
[11:48:18.993]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:48:18.993]     INFO:   running: highrate
[11:48:18.993]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:48:19.199]     INFO:    ----------------------------------------------------------------------
[11:48:19.199]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:48:19.199]     INFO:    ----------------------------------------------------------------------
[11:48:19.199]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:48:19.200]     INFO: edge/corner pixel THR is adjusted
[11:48:19.200]     INFO: PixTestHighRate::trimHotPixels: step 0...
[11:48:20.161]     INFO: Collecting data for 5 seconds...
[11:48:25.176]     INFO: Done with hot pixel readout
[11:48:36.794]     INFO: PixTest::       pg_setup set to default.
[11:48:36.795]     INFO: 16 hot pixels found in step 0
[11:48:37.806]     INFO: Collecting data for 5 seconds...
[11:48:42.821]     INFO: Done with hot pixel readout
[11:48:54.463]     INFO: PixTest::       pg_setup set to default.
[11:48:54.464]     INFO: 12 hot pixels found in step 1
[11:48:55.452]     INFO: Collecting data for 5 seconds...
[11:49:00.467]     INFO: Done with hot pixel readout
[11:49:12.091]     INFO: PixTest::       pg_setup set to default.
[11:49:12.092]     INFO: 12 hot pixels found in step 2
[11:49:13.080]     INFO: Collecting data for 5 seconds...
[11:49:18.094]     INFO: Done with hot pixel readout
[11:49:29.752]     INFO: PixTest::       pg_setup set to default.
[11:49:29.753]     INFO: 10 hot pixels found in step 3
[11:49:30.741]     INFO: Collecting data for 5 seconds...
[11:49:35.757]     INFO: Done with hot pixel readout
[11:49:47.374]     INFO: PixTest::       pg_setup set to default.
[11:49:47.375]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[11:49:47.375]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[11:49:47.375]     INFO: 10 hot pixels found in step 4
[11:49:48.362]     INFO: Collecting data for 5 seconds...
[11:49:53.377]     INFO: Done with hot pixel readout
[11:50:04.982]     INFO: PixTest::       pg_setup set to default.
[11:50:04.983]     INFO: 9 hot pixels found in step 5
[11:50:05.971]     INFO: Collecting data for 5 seconds...
[11:50:10.987]     INFO: Done with hot pixel readout
[11:50:22.579]     INFO: PixTest::       pg_setup set to default.
[11:50:22.580]     INFO: 7 hot pixels found in step 6
[11:50:23.568]     INFO: Collecting data for 5 seconds...
[11:50:28.583]     INFO: Done with hot pixel readout
[11:50:40.202]     INFO: PixTest::       pg_setup set to default.
[11:50:40.203]     INFO: 9 hot pixels found in step 7
[11:50:41.191]     INFO: Collecting data for 5 seconds...
[11:50:46.207]     INFO: Done with hot pixel readout
[11:50:57.828]     INFO: PixTest::       pg_setup set to default.
[11:50:57.829]     INFO: 4 hot pixels found in step 8
[11:50:58.817]     INFO: Collecting data for 5 seconds...
[11:51:03.833]     INFO: Done with hot pixel readout
[11:51:15.444]     INFO: PixTest::       pg_setup set to default.
[11:51:15.445]     INFO: 4 hot pixels found in step 9
[11:51:16.433]     INFO: Collecting data for 5 seconds...
[11:51:21.449]     INFO: Done with hot pixel readout
[11:51:33.077]     INFO: PixTest::       pg_setup set to default.
[11:51:33.077]     INFO: 4 hot pixels found in step 10
[11:51:34.064]     INFO: Collecting data for 5 seconds...
[11:51:39.080]     INFO: Done with hot pixel readout
[11:51:50.680]     INFO: PixTest::       pg_setup set to default.
[11:51:50.681]     INFO: 4 hot pixels found in step 11
[11:51:51.669]     INFO: Collecting data for 5 seconds...
[11:51:56.684]     INFO: Done with hot pixel readout
[11:52:08.295]     INFO: PixTest::       pg_setup set to default.
[11:52:08.295]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[11:52:08.296]     INFO: 1 hot pixels found in step 12
[11:52:08.327]     INFO: 1 hot pixels could not be trimmed and have been masked.
[11:52:08.331]     INFO: PixTest::trimHotPixels() done
[11:52:08.334]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C0.dat
[11:52:08.340]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C1.dat
[11:52:08.346]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C2.dat
[11:52:08.352]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C3.dat
[11:52:08.357]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C4.dat
[11:52:08.362]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C5.dat
[11:52:08.367]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C6.dat
[11:52:08.373]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C7.dat
[11:52:08.378]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C8.dat
[11:52:08.383]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C9.dat
[11:52:08.388]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C10.dat
[11:52:08.393]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C11.dat
[11:52:08.399]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C12.dat
[11:52:08.404]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C13.dat
[11:52:08.409]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C14.dat
[11:52:08.414]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C15.dat
[11:52:08.419]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//defaultMaskFile.dat
[11:52:08.429]     INFO: enter test to run
[11:52:40.175]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:52:40.175]     INFO:   running: highrate
[11:52:40.179]     INFO:    ----------------------------------------------------------------------
[11:52:40.179]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:52:40.179]     INFO:    ----------------------------------------------------------------------
[11:52:40.179]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:52:40.179]     INFO: edge/corner pixel THR is adjusted
[11:52:40.179]     INFO: PixTestHighRate::trimHotPixels: step 0...
[11:52:41.137]     INFO: Collecting data for 1 seconds...
[11:52:42.140]     INFO: Done with hot pixel readout
[11:52:46.121]     INFO: PixTest::       pg_setup set to default.
[11:52:46.122]     INFO: 0 hot pixels found in step 0
[11:52:46.127]     INFO: 0 hot pixels could not be trimmed and have been masked.
[11:52:46.217]     INFO: PixTest::trimHotPixels() done
[11:52:46.217]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C0.dat
[11:52:46.229]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C1.dat
[11:52:46.237]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C2.dat
[11:52:46.242]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C3.dat
[11:52:46.247]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C4.dat
[11:52:46.252]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C5.dat
[11:52:46.258]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C6.dat
[11:52:46.263]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C7.dat
[11:52:46.268]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C8.dat
[11:52:46.273]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C9.dat
[11:52:46.278]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C10.dat
[11:52:46.284]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C11.dat
[11:52:46.289]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C12.dat
[11:52:46.294]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C13.dat
[11:52:46.299]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C14.dat
[11:52:46.305]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//trimParameters35_C15.dat
[11:52:46.310]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-18_FPIXTest-17C-FNAL-160525-1405_2016-05-25_14h05m_1464203134/000_FPIXTest_p17//defaultMaskFile.dat
[11:52:46.327]     INFO: enter test to run
[11:53:15.630]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[11:53:15.630]     INFO:   running: xray
[11:53:15.632]     INFO:    ----------------------------------------------------------------------
[11:53:15.632]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[11:53:15.632]     INFO:    ----------------------------------------------------------------------
[11:53:16.595]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[11:53:28.127]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:53:57.567]     INFO: Resuming triggers.
[11:54:09.103]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:54:38.487]     INFO: Resuming triggers.
[11:54:50.025]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:55:19.500]     INFO: Resuming triggers.
[11:55:31.034]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:56:00.439]     INFO: Resuming triggers.
[11:56:11.971]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:56:41.373]     INFO: Resuming triggers.
[11:56:52.907]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:57:22.316]     INFO: Resuming triggers.
[11:57:33.846]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[11:58:03.254]     INFO: Resuming triggers.
[11:58:14.785]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:58:44.166]     INFO: Resuming triggers.
[11:58:52.205]     INFO: data taking finished, elapsed time: 100 seconds.
[11:59:13.050]     INFO: PixTest::       pg_setup set to default.
[11:59:13.053]     INFO: PixTestXray::doPhRun() done
[11:59:13.226]     INFO: enter test to run
[11:59:49.475]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[11:59:49.475]     INFO:   running: xray
[11:59:49.476]     INFO:    ----------------------------------------------------------------------
[11:59:49.476]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[11:59:49.476]     INFO:    ----------------------------------------------------------------------
[11:59:50.439]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[11:59:57.176]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:00:27.443]     INFO: Resuming triggers.
[12:00:34.182]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:01:04.379]     INFO: Resuming triggers.
[12:01:11.121]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:01:41.184]     INFO: Resuming triggers.
[12:01:47.929]     INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:02:18.032]     INFO: Resuming triggers.
[12:02:24.775]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:02:54.931]     INFO: Resuming triggers.
[12:03:01.675]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:03:31.794]     INFO: Resuming triggers.
[12:03:38.541]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:04:08.611]     INFO: Resuming triggers.
[12:04:15.357]     INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:04:45.482]     INFO: Resuming triggers.
[12:04:52.226]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:05:22.393]     INFO: Resuming triggers.
[12:05:29.138]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:05:59.219]     INFO: Resuming triggers.
[12:06:05.962]     INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:06:36.028]     INFO: Resuming triggers.
[12:06:42.773]     INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:07:12.820]     INFO: Resuming triggers.
[12:07:19.562]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:07:49.627]     INFO: Resuming triggers.
[12:07:56.371]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:08:26.356]     INFO: Resuming triggers.
[12:08:32.254]     INFO: data taking finished, elapsed time: 100 seconds.
[12:08:58.731]     INFO: PixTest::       pg_setup set to default.
[12:08:58.734]     INFO: PixTestXray::doPhRun() done
[12:08:58.882]     INFO: enter test to run
[12:09:29.367]     INFO:   test: HighRate no parameter change
[12:09:29.367]     INFO:   running: highrate
[12:09:29.368]     INFO:    ----------------------------------------------------------------------
[12:09:29.368]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:09:29.368]     INFO:    ----------------------------------------------------------------------
[12:09:29.511]     INFO: Expecting 768 events.
[12:09:30.645]     INFO: 768 events read in total (418ms).
[12:09:30.645]     INFO: Test took 1269ms.
[12:09:31.448]     INFO: Expecting 41600 events.
[12:09:34.557]     INFO: 41600 events read in total (2582ms).
[12:09:34.558]     INFO: Test took 3904ms.
[12:09:34.590]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:35.322]     INFO: Expecting 41600 events.
[12:09:38.526]     INFO: 41600 events read in total (2677ms).
[12:09:38.527]     INFO: Test took 3919ms.
[12:09:38.560]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:39.285]     INFO: Expecting 41600 events.
[12:09:42.522]     INFO: 41600 events read in total (2710ms).
[12:09:42.523]     INFO: Test took 3946ms.
[12:09:42.556]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:43.280]     INFO: Expecting 41600 events.
[12:09:46.528]     INFO: 41600 events read in total (2721ms).
[12:09:46.529]     INFO: Test took 3954ms.
[12:09:46.563]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:47.286]     INFO: Expecting 41600 events.
[12:09:50.527]     INFO: 41600 events read in total (2715ms).
[12:09:50.528]     INFO: Test took 3947ms.
[12:09:50.560]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:51.288]     INFO: Expecting 41600 events.
[12:09:54.533]     INFO: 41600 events read in total (2718ms).
[12:09:54.534]     INFO: Test took 3957ms.
[12:09:54.568]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:55.291]     INFO: Expecting 41600 events.
[12:09:58.532]     INFO: 41600 events read in total (2714ms).
[12:09:58.533]     INFO: Test took 3948ms.
[12:09:58.566]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:59.292]     INFO: Expecting 41600 events.
[12:10:02.539]     INFO: 41600 events read in total (2720ms).
[12:10:02.540]     INFO: Test took 3955ms.
[12:10:02.572]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:03.298]     INFO: Expecting 41600 events.
[12:10:06.552]     INFO: 41600 events read in total (2727ms).
[12:10:06.553]     INFO: Test took 3962ms.
[12:10:06.587]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:07.314]     INFO: Expecting 41600 events.
[12:10:10.556]     INFO: 41600 events read in total (2715ms).
[12:10:10.557]     INFO: Test took 3953ms.
[12:10:10.591]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:11.318]     INFO: Expecting 41600 events.
[12:10:14.560]     INFO: 41600 events read in total (2715ms).
[12:10:14.561]     INFO: Test took 3951ms.
[12:10:14.594]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:15.318]     INFO: Expecting 41600 events.
[12:10:18.535]     INFO: 41600 events read in total (2690ms).
[12:10:18.536]     INFO: Test took 3924ms.
[12:10:18.569]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:19.294]     INFO: Expecting 41600 events.
[12:10:22.543]     INFO: 41600 events read in total (2722ms).
[12:10:22.544]     INFO: Test took 3956ms.
[12:10:22.577]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:23.302]     INFO: Expecting 41600 events.
[12:10:26.539]     INFO: 41600 events read in total (2710ms).
[12:10:26.540]     INFO: Test took 3945ms.
[12:10:26.573]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:27.299]     INFO: Expecting 41600 events.
[12:10:30.546]     INFO: 41600 events read in total (2720ms).
[12:10:30.547]     INFO: Test took 3955ms.
[12:10:30.580]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:31.305]     INFO: Expecting 41600 events.
[12:10:34.556]     INFO: 41600 events read in total (2724ms).
[12:10:34.557]     INFO: Test took 3959ms.
[12:10:34.590]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:35.318]     INFO: Expecting 41600 events.
[12:10:38.572]     INFO: 41600 events read in total (2727ms).
[12:10:38.573]     INFO: Test took 3965ms.
[12:10:38.606]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:39.330]     INFO: Expecting 41600 events.
[12:10:42.572]     INFO: 41600 events read in total (2715ms).
[12:10:42.573]     INFO: Test took 3948ms.
[12:10:42.607]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:43.333]     INFO: Expecting 41600 events.
[12:10:46.576]     INFO: 41600 events read in total (2716ms).
[12:10:46.577]     INFO: Test took 3953ms.
[12:10:46.610]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:47.334]     INFO: Expecting 41600 events.
[12:10:50.476]     INFO: 41600 events read in total (2615ms).
[12:10:50.477]     INFO: Test took 3850ms.
[12:10:50.509]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:50.874]     INFO: enter test to run
[12:11:38.678]     INFO:   test: HighRate no parameter change
[12:11:38.678]     INFO:   running: highrate
[12:11:38.679]     INFO:    ----------------------------------------------------------------------
[12:11:38.679]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:11:38.680]     INFO:    ----------------------------------------------------------------------
[12:11:39.293]     INFO: Expecting 208000 events.
[12:11:51.123]     INFO: 208000 events read in total (11303ms).
[12:11:51.125]     INFO: Test took 12439ms.
[12:11:51.267]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:51.517]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:11:51.517]     INFO: number of red-efficiency pixels:    80   44   82  131  151  168  133   78   63  108  117   79   94   47   25   29
[12:11:51.517]     INFO: number of X-ray hits detected:    63888 43241 68335 105921 113495 112287 111664 75239 70652 88819 88989 81639 83472 50219 21262 25597
[12:11:51.517]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:11:51.517]     INFO: number of Vcal hits detected:  207918 207956 207917 207868 207847 207830 207865 207920 207936 207889 207880 207920 207905 207951 207975 207971
[12:11:51.517]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[12:11:51.517]     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 100.0 100.0 100.0 100.0 100.0
[12:11:51.517]     INFO: X-ray hit rate [MHz/cm2]:  18.7 12.7 20.0 31.0 33.3 32.9 32.7 22.1 20.7 26.0 26.1 23.9 24.5 14.7 6.2 7.5
[12:11:51.517]     INFO: PixTestHighRate::doXPixelAlive() done
[12:11:51.566]     INFO: PixTest::       pg_setup set to default.
[12:11:51.577]     INFO: enter test to run
[12:12:11.510]     INFO:   test: HighRate no parameter change
[12:12:11.510]     INFO:   running: highrate
[12:12:11.511]     INFO:    ----------------------------------------------------------------------
[12:12:11.511]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:12:11.511]     INFO:    ----------------------------------------------------------------------
[12:12:12.130]     INFO: Expecting 208000 events.
[12:12:25.711]     INFO: 208000 events read in total (13054ms).
[12:12:25.717]     INFO: Test took 14198ms.
[12:12:26.008]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:26.306]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:12:26.306]     INFO: number of red-efficiency pixels:   196  113  311  505  564  608  491  329  240  316  357  250  329  155   56   57
[12:12:26.306]     INFO: number of X-ray hits detected:    136081 91171 144569 223867 238915 238129 234997 159817 149881 187731 188417 171404 176825 106401 44916 55210
[12:12:26.306]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:12:26.306]     INFO: number of Vcal hits detected:  207794 207878 207661 207451 207383 207324 207465 207625 207750 207664 207613 207733 207655 207841 207943 207942
[12:12:26.306]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[12:12:26.306]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[12:12:26.307]     INFO: X-ray hit rate [MHz/cm2]:  39.9 26.7 42.4 65.6 70.0 69.8 68.9 46.8 43.9 55.0 55.2 50.2 51.8 31.2 13.2 16.2
[12:12:26.307]     INFO: PixTestHighRate::doXPixelAlive() done
[12:12:26.359]     INFO: PixTest::       pg_setup set to default.
[12:12:26.375]     INFO: enter test to run
[12:12:44.558]     INFO:   test: HighRate no parameter change
[12:12:44.558]     INFO:   running: highrate
[12:12:44.559]     INFO:    ----------------------------------------------------------------------
[12:12:44.559]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:12:44.559]     INFO:    ----------------------------------------------------------------------
[12:12:45.173]     INFO: Expecting 208000 events.
[12:13:00.626]     INFO: 208000 events read in total (14926ms).
[12:13:00.633]     INFO: Test took 16064ms.
[12:13:01.070]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:01.416]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[12:13:01.416]     INFO: number of red-efficiency pixels:   450  285  694 1207 1309 1395 1019  755  508  850  854  538  728  369   99  119
[12:13:01.416]     INFO: number of X-ray hits detected:    206934 138514 219549 339990 363944 359882 358135 242058 228285 284332 286195 261073 267977 161925 69228 84017
[12:13:01.416]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:13:01.416]     INFO: number of Vcal hits detected:  207493 207693 207064 206494 206278 206080 206765 207036 207429 206986 206976 207383 207199 207564 207898 207879
[12:13:01.416]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.6 99.3 99.3 99.2 99.5 99.6 99.7 99.6 99.5 99.7 99.6 99.8 100.0 99.9
[12:13:01.416]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.6 99.3 99.2 99.1 99.4 99.5 99.7 99.5 99.5 99.7 99.6 99.8 100.0 99.9
[12:13:01.416]     INFO: X-ray hit rate [MHz/cm2]:  60.7 40.6 64.4 99.7 106.7 105.5 105.0 70.9 66.9 83.3 83.9 76.5 78.5 47.5 20.3 24.6
[12:13:01.416]     INFO: PixTestHighRate::doXPixelAlive() done
[12:13:01.461]     INFO: PixTest::       pg_setup set to default.
[12:13:01.478]     INFO: enter test to run
[12:13:08.846]     INFO:   test: exit no parameter change
[12:13:09.167]    QUIET: Connection to board 33 closed.
[12:13:09.168]     INFO: pXar: this is the end, my friend