[13:18:39.509]     INFO: *** Welcome to pxar ***
[13:18:39.509]     INFO: *** Today: 2016/08/29
[13:18:40.398]     INFO: *** Version: v1.9.0-818-g96727
[13:18:40.398]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//dacParameters35_C15.dat
[13:18:40.416]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:18:40.416]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:18:40.420]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:18:40.527]     INFO:         clk: 4
[13:18:40.527]     INFO:         ctr: 4
[13:18:40.527]     INFO:         sda: 19
[13:18:40.527]     INFO:         tin: 9
[13:18:40.527]     INFO:         level: 15
[13:18:40.527]     INFO:         triggerdelay: 0
[13:18:40.527]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:18:40.527]     INFO: Log level: INFO
[13:18:40.543]    QUIET: Connection to board DTB_WREKRL opened.
[13:18:40.546]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[13:18:40.549]     INFO: RPC call hashes of host and DTB match: 398089610
[13:18:42.084]     INFO: DUT info: 
[13:18:42.084]     INFO: The DUT currently contains the following objects:
[13:18:42.084]     INFO:  2 TBM Cores tbm08c (2 ON)
[13:18:42.084]     INFO: 	TBM Core alpha (0): 7 registers set
[13:18:42.084]     INFO: 	TBM Core beta  (1): 7 registers set
[13:18:42.084]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:18:42.084]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.488]     INFO: enter 'restricted' command line mode
[13:18:42.488]     INFO: enter test to run
[13:19:03.609]     INFO:   test: PixelAlive no parameter change
[13:19:03.609]     INFO:   running: pixelalive
[13:19:03.632]     INFO:    ----------------------------------------------------------------------
[13:19:03.632]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:19:03.632]     INFO:    ----------------------------------------------------------------------
[13:19:03.959]     INFO: Expecting 41600 events.
[13:19:08.161]     INFO: 41600 events read in total (3484ms).
[13:19:08.326]     INFO: Test took 4686ms.
[13:19:08.335]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:08.599]     INFO: PixTestAlive::aliveTest() done
[13:19:08.599]     INFO: number of dead pixels (per ROC):     1    0    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[13:19:08.629]     INFO: enter test to run
[13:19:42.625]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:19:42.625]     INFO:   running: highrate
[13:19:42.625]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:19:42.879]     INFO:    ----------------------------------------------------------------------
[13:19:42.879]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:19:42.879]     INFO:    ----------------------------------------------------------------------
[13:19:42.879]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:19:42.879]     INFO: edge/corner pixel THR is adjusted
[13:19:42.879]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:19:43.837]     INFO: Collecting data for 5 seconds...
[13:19:48.859]     INFO: Done with hot pixel readout
[13:20:00.816]     INFO: PixTest::       pg_setup set to default.
[13:20:00.817]     INFO: 1 hot pixels found in step 0
[13:20:01.806]     INFO: Collecting data for 5 seconds...
[13:20:06.826]     INFO: Done with hot pixel readout
[13:20:18.768]     INFO: PixTest::       pg_setup set to default.
[13:20:18.769]     INFO: 7 hot pixels found in step 1
[13:20:19.763]     INFO: Collecting data for 5 seconds...
[13:20:24.781]     INFO: Done with hot pixel readout
[13:20:36.719]     INFO: PixTest::       pg_setup set to default.
[13:20:36.719]     INFO: 2 hot pixels found in step 2
[13:20:37.712]     INFO: Collecting data for 5 seconds...
[13:20:42.733]     INFO: Done with hot pixel readout
[13:20:54.671]     INFO: PixTest::       pg_setup set to default.
[13:20:54.672]     INFO: 3 hot pixels found in step 3
[13:20:55.665]     INFO: Collecting data for 5 seconds...
[13:21:00.686]     INFO: Done with hot pixel readout
[13:21:12.686]     INFO: PixTest::       pg_setup set to default.
[13:21:12.687]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687]     INFO: 3 hot pixels found in step 4
[13:21:12.724]     INFO: 3 hot pixels could not be trimmed and have been masked.
[13:21:12.728]     INFO: PixTest::trimHotPixels() done
[13:21:12.728]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:12.733]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:12.739]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:12.746]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:12.751]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:12.757]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:12.762]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:12.767]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:12.773]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:12.778]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:12.783]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:12.789]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:12.794]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:12.799]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:12.805]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:12.810]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:12.815]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:12.843]     INFO: enter test to run
[13:21:51.976]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:21:51.976]     INFO:   running: highrate
[13:21:51.980]     INFO:    ----------------------------------------------------------------------
[13:21:51.981]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:21:51.981]     INFO:    ----------------------------------------------------------------------
[13:21:51.981]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:21:51.981]     INFO: edge/corner pixel THR is adjusted
[13:21:51.981]     INFO: PixTestHighRate::trimHotPixels: step 0...
[13:21:52.939]     INFO: Collecting data for 1 seconds...
[13:21:53.942]     INFO: Done with hot pixel readout
[13:21:58.060]     INFO: PixTest::       pg_setup set to default.
[13:21:58.061]     INFO: 0 hot pixels found in step 0
[13:21:58.066]     INFO: 0 hot pixels could not be trimmed and have been masked.
[13:21:58.152]     INFO: PixTest::trimHotPixels() done
[13:21:58.152]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:58.164]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:58.170]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:58.176]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:58.181]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:58.186]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:58.191]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:58.215]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:58.226]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:58.231]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:58.237]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:58.242]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:58.247]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:58.252]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:58.258]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:58.263]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:58.268]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:58.285]     INFO: enter test to run
[13:22:59.856]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[13:22:59.856]     INFO:   running: xray
[13:22:59.857]     INFO:    ----------------------------------------------------------------------
[13:22:59.857]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:22:59.857]     INFO:    ----------------------------------------------------------------------
[13:23:00.821]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:23:12.235]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:23:41.640]     INFO: Resuming triggers.
[13:23:53.063]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:24:22.529]     INFO: Resuming triggers.
[13:24:33.951]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:25:03.329]     INFO: Resuming triggers.
[13:25:14.753]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:25:44.142]     INFO: Resuming triggers.
[13:25:55.562]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:26:24.960]     INFO: Resuming triggers.
[13:26:36.381]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:27:05.763]     INFO: Resuming triggers.
[13:27:17.187]     INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:27:46.568]     INFO: Resuming triggers.
[13:27:57.989]     INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:28:27.129]     INFO: Resuming triggers.
[13:28:36.084]     INFO: data taking finished, elapsed time: 100 seconds.
[13:28:59.239]     INFO: PixTest::       pg_setup set to default.
[13:28:59.242]     INFO: PixTestXray::doPhRun() done
[13:28:59.379]     INFO: enter test to run
[13:29:46.277]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[13:29:46.277]     INFO:   running: xray
[13:29:46.278]     INFO:    ----------------------------------------------------------------------
[13:29:46.278]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[13:29:46.278]     INFO:    ----------------------------------------------------------------------
[13:29:47.244]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[13:29:53.727]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:30:24.711]     INFO: Resuming triggers.
[13:30:31.198]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:31:02.246]     INFO: Resuming triggers.
[13:31:08.729]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:31:39.404]     INFO: Resuming triggers.
[13:31:45.891]     INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[13:32:17.738]     INFO: Resuming triggers.
[13:32:24.225]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:32:55.556]     INFO: Resuming triggers.
[13:33:02.039]     INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:33:33.992]     INFO: Resuming triggers.
[13:33:40.478]     INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:34:10.724]     INFO: Resuming triggers.
[13:34:17.210]     INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:34:47.311]     INFO: Resuming triggers.
[13:34:53.799]     INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:35:23.915]     INFO: Resuming triggers.
[13:35:30.398]     INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:36:00.555]     INFO: Resuming triggers.
[13:36:07.042]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:36:37.151]     INFO: Resuming triggers.
[13:36:43.636]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:37:13.709]     INFO: Resuming triggers.
[13:37:20.196]     INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:37:50.334]     INFO: Resuming triggers.
[13:37:56.826]     INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:38:26.893]     INFO: Resuming triggers.
[13:38:33.380]     INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:39:03.403]     INFO: Resuming triggers.
[13:39:06.462]     INFO: data taking finished, elapsed time: 100 seconds.
[13:39:20.945]     INFO: PixTest::       pg_setup set to default.
[13:39:20.948]     INFO: PixTestXray::doPhRun() done
[13:39:21.096]     INFO: enter test to run
[13:39:46.745]     INFO:   test: HighRate no parameter change
[13:39:46.745]     INFO:   running: highrate
[13:39:46.766]     INFO:    ----------------------------------------------------------------------
[13:39:46.767]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:39:46.767]     INFO:    ----------------------------------------------------------------------
[13:39:46.913]     INFO: Expecting 768 events.
[13:39:48.047]     INFO: 768 events read in total (418ms).
[13:39:48.048]     INFO: Test took 1270ms.
[13:39:48.851]     INFO: Expecting 41600 events.
[13:39:51.957]     INFO: 41600 events read in total (2579ms).
[13:39:51.958]     INFO: Test took 3904ms.
[13:39:51.991]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:52.718]     INFO: Expecting 41600 events.
[13:39:55.941]     INFO: 41600 events read in total (2696ms).
[13:39:55.942]     INFO: Test took 3934ms.
[13:39:55.976]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:56.699]     INFO: Expecting 41600 events.
[13:39:59.928]     INFO: 41600 events read in total (2702ms).
[13:39:59.929]     INFO: Test took 3936ms.
[13:39:59.963]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:00.686]     INFO: Expecting 41600 events.
[13:40:03.903]     INFO: 41600 events read in total (2690ms).
[13:40:03.904]     INFO: Test took 3924ms.
[13:40:03.938]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:04.664]     INFO: Expecting 41600 events.
[13:40:07.895]     INFO: 41600 events read in total (2704ms).
[13:40:07.896]     INFO: Test took 3940ms.
[13:40:07.929]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:08.653]     INFO: Expecting 41600 events.
[13:40:11.887]     INFO: 41600 events read in total (2708ms).
[13:40:11.888]     INFO: Test took 3940ms.
[13:40:11.922]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:12.639]     INFO: Expecting 41600 events.
[13:40:15.875]     INFO: 41600 events read in total (2710ms).
[13:40:15.876]     INFO: Test took 3936ms.
[13:40:15.911]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:16.632]     INFO: Expecting 41600 events.
[13:40:19.861]     INFO: 41600 events read in total (2702ms).
[13:40:19.861]     INFO: Test took 3933ms.
[13:40:19.896]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:20.620]     INFO: Expecting 41600 events.
[13:40:23.866]     INFO: 41600 events read in total (2719ms).
[13:40:23.867]     INFO: Test took 3953ms.
[13:40:23.900]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:24.623]     INFO: Expecting 41600 events.
[13:40:27.855]     INFO: 41600 events read in total (2705ms).
[13:40:27.856]     INFO: Test took 3937ms.
[13:40:27.890]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:28.616]     INFO: Expecting 41600 events.
[13:40:31.846]     INFO: 41600 events read in total (2703ms).
[13:40:31.847]     INFO: Test took 3940ms.
[13:40:31.881]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:32.605]     INFO: Expecting 41600 events.
[13:40:35.854]     INFO: 41600 events read in total (2722ms).
[13:40:35.855]     INFO: Test took 3956ms.
[13:40:35.891]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.610]     INFO: Expecting 41600 events.
[13:40:39.855]     INFO: 41600 events read in total (2718ms).
[13:40:39.856]     INFO: Test took 3945ms.
[13:40:39.890]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:40.616]     INFO: Expecting 41600 events.
[13:40:43.861]     INFO: 41600 events read in total (2718ms).
[13:40:43.862]     INFO: Test took 3953ms.
[13:40:43.896]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:44.621]     INFO: Expecting 41600 events.
[13:40:47.865]     INFO: 41600 events read in total (2717ms).
[13:40:47.866]     INFO: Test took 3952ms.
[13:40:47.900]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:48.621]     INFO: Expecting 41600 events.
[13:40:51.879]     INFO: 41600 events read in total (2731ms).
[13:40:51.880]     INFO: Test took 3961ms.
[13:40:51.914]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:52.639]     INFO: Expecting 41600 events.
[13:40:55.896]     INFO: 41600 events read in total (2730ms).
[13:40:55.897]     INFO: Test took 3966ms.
[13:40:55.931]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:56.654]     INFO: Expecting 41600 events.
[13:40:59.892]     INFO: 41600 events read in total (2711ms).
[13:40:59.893]     INFO: Test took 3944ms.
[13:40:59.927]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:00.651]     INFO: Expecting 41600 events.
[13:41:03.886]     INFO: 41600 events read in total (2708ms).
[13:41:03.887]     INFO: Test took 3942ms.
[13:41:03.922]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:04.644]     INFO: Expecting 41600 events.
[13:41:07.703]     INFO: 41600 events read in total (2532ms).
[13:41:07.704]     INFO: Test took 3765ms.
[13:41:07.736]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:08.101]     INFO: enter test to run
[13:41:45.312]     INFO:   test: HighRate no parameter change
[13:41:45.312]     INFO:   running: highrate
[13:41:45.313]     INFO:    ----------------------------------------------------------------------
[13:41:45.313]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:45.313]     INFO:    ----------------------------------------------------------------------
[13:41:45.928]     INFO: Expecting 208000 events.
[13:41:57.929]     INFO: 208000 events read in total (11474ms).
[13:41:57.932]     INFO: Test took 12610ms.
[13:41:58.078]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:58.332]     INFO: number of dead pixels (per ROC):     1    0    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[13:41:58.332]     INFO: number of red-efficiency pixels:    72   47   89  156  129  143  142  106   96  129  123  110  116   54   28   23
[13:41:58.332]     INFO: number of X-ray hits detected:    61435 39439 68018 108798 112446 117438 116720 79019 75949 99928 98877 84927 88029 51265 20215 24379
[13:41:58.332]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:41:58.332]     INFO: number of Vcal hits detected:  207878 207952 207859 207841 207868 207853 207855 207892 207903 207868 207875 207885 207880 207946 207972 207977
[13:41:58.332]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:41:58.332]     INFO: Vcal hit overall efficiency (%):  99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:41:58.333]     INFO: X-ray hit rate [MHz/cm2]:  18.0 11.6 19.9 31.9 33.0 34.4 34.2 23.2 22.3 29.3 29.0 24.9 25.8 15.0 5.9 7.1
[13:41:58.333]     INFO: PixTestHighRate::doXPixelAlive() done
[13:41:58.378]     INFO: PixTest::       pg_setup set to default.
[13:41:58.395]     INFO: enter test to run
[13:42:56.136]     INFO:   test: HighRate no parameter change
[13:42:56.136]     INFO:   running: highrate
[13:42:56.137]     INFO:    ----------------------------------------------------------------------
[13:42:56.137]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:42:56.137]     INFO:    ----------------------------------------------------------------------
[13:42:56.749]     INFO: Expecting 208000 events.
[13:43:10.641]     INFO: 208000 events read in total (13365ms).
[13:43:10.646]     INFO: Test took 14502ms.
[13:43:10.965]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:11.274]     INFO: number of dead pixels (per ROC):     1    0    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[13:43:11.274]     INFO: number of red-efficiency pixels:   222  146  315  600  487  549  489  417  343  524  450  412  402  145   51   57
[13:43:11.274]     INFO: number of X-ray hits detected:    134704 86764 149734 238434 247725 256297 255203 173101 167910 220837 217168 187442 192340 112763 43910 54187
[13:43:11.275]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:43:11.275]     INFO: number of Vcal hits detected:  207717 207849 207598 207327 207475 207391 207465 207524 207630 207441 207503 207564 207570 207846 207949 207940
[13:43:11.275]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:43:11.275]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:43:11.275]     INFO: X-ray hit rate [MHz/cm2]:  39.5 25.4 43.9 69.9 72.6 75.1 74.8 50.7 49.2 64.7 63.7 54.9 56.4 33.1 12.9 15.9
[13:43:11.275]     INFO: PixTestHighRate::doXPixelAlive() done
[13:43:11.320]     INFO: PixTest::       pg_setup set to default.
[13:43:11.335]     INFO: enter test to run
[13:44:08.487]     INFO:   test: HighRate no parameter change
[13:44:08.487]     INFO:   running: highrate
[13:44:08.488]     INFO:    ----------------------------------------------------------------------
[13:44:08.488]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:44:08.488]     INFO:    ----------------------------------------------------------------------
[13:44:09.107]     INFO: Expecting 208000 events.
[13:44:25.360]     INFO: 208000 events read in total (15727ms).
[13:44:25.367]     INFO: Test took 16870ms.
[13:44:25.865]     INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:26.231]     INFO: number of dead pixels (per ROC):     1    0    1    0    0    0    0    0    0    0    0    0    0    0    0    0
[13:44:26.231]     INFO: number of red-efficiency pixels:   386  249  662 1476 1198 1306 1133  886  738 1204 1129  915  933  411   83   78
[13:44:26.231]     INFO: number of X-ray hits detected:    205175 132422 226802 362941 375718 390261 387294 263183 255686 335205 330117 284306 291893 172557 67520 82701
[13:44:26.231]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:44:26.231]     INFO: number of Vcal hits detected:  207509 207729 207035 205957 206476 206227 206559 206759 207125 206454 206561 206854 206857 207520 207912 207922
[13:44:26.231]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.6 99.1 99.3 99.2 99.4 99.5 99.6 99.3 99.4 99.5 99.5 99.8 100.0 100.0
[13:44:26.231]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.5 99.0 99.3 99.1 99.3 99.4 99.6 99.3 99.3 99.4 99.5 99.8 100.0 100.0
[13:44:26.231]     INFO: X-ray hit rate [MHz/cm2]:  60.1 38.8 66.5 106.4 110.1 114.4 113.5 77.1 74.9 98.3 96.8 83.3 85.6 50.6 19.8 24.2
[13:44:26.231]     INFO: PixTestHighRate::doXPixelAlive() done
[13:44:26.282]     INFO: PixTest::       pg_setup set to default.
[13:44:26.298]     INFO: enter test to run
[13:44:43.879]     INFO:   test: exit no parameter change
[13:44:44.206]    QUIET: Connection to board 33 closed.
[13:44:44.219]     INFO: pXar: this is the end, my friend