[12:05:11.278]     INFO: *** Welcome to pxar ***
[12:05:11.278]     INFO: *** Today: 2016/06/30
[12:05:11.773]     INFO: *** Version: v1.9.0-814-g7497
[12:05:11.773]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//dacParameters35_C15.dat
[12:05:11.815]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:05:11.816]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[12:05:11.819]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[12:05:11.941]     INFO:         clk: 4
[12:05:11.941]     INFO:         ctr: 4
[12:05:11.941]     INFO:         sda: 19
[12:05:11.941]     INFO:         tin: 9
[12:05:11.941]     INFO:         level: 15
[12:05:11.941]     INFO:         triggerdelay: 0
[12:05:11.941]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:05:11.941]     INFO: Log level: INFO
[12:05:11.959]    QUIET: Connection to board DTB_WREKRL opened.
[12:05:11.963]     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:     
------------------------------------------------------
[12:05:11.965]     INFO: RPC call hashes of host and DTB match: 398089610
[12:05:13.499]     INFO: DUT info: 
[12:05:13.499]     INFO: The DUT currently contains the following objects:
[12:05:13.499]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:05:13.499]     INFO: 	TBM Core alpha (0): 7 registers set
[12:05:13.499]     INFO: 	TBM Core beta  (1): 7 registers set
[12:05:13.499]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:05:13.499]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.499]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.499]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.499]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.499]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.499]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.500]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:13.904]     INFO: enter 'restricted' command line mode
[12:05:13.904]     INFO: enter test to run
[12:05:19.533]     INFO:   test: PixelAlive no parameter change
[12:05:19.533]     INFO:   running: pixelalive
[12:05:19.542]     INFO:    ----------------------------------------------------------------------
[12:05:19.542]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:05:19.542]     INFO:    ----------------------------------------------------------------------
[12:05:19.859]     INFO: Expecting 41600 events.
[12:05:24.198]     INFO: 41600 events read in total (3621ms).
[12:05:24.366]     INFO: Test took 4822ms.
[12:05:24.377]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:24.639]     INFO: PixTestAlive::aliveTest() done
[12:05:24.639]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    3    3    0    0    0    0    0    0    0    1
[12:05:24.670]     INFO: enter test to run
[12:05:51.389]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:05:51.389]     INFO:   running: highrate
[12:05:51.389]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:05:51.659]     INFO:    ----------------------------------------------------------------------
[12:05:51.659]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:05:51.659]     INFO:    ----------------------------------------------------------------------
[12:05:51.659]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:05:51.660]     INFO: edge/corner pixel THR is adjusted
[12:05:51.660]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:05:52.618]     INFO: Collecting data for 5 seconds...
[12:05:57.635]     INFO: Done with hot pixel readout
[12:06:09.677]     INFO: PixTest::       pg_setup set to default.
[12:06:09.678]     INFO: 9 hot pixels found in step 0
[12:06:10.702]     INFO: Collecting data for 5 seconds...
[12:06:15.720]     INFO: Done with hot pixel readout
[12:06:27.893]     INFO: PixTest::       pg_setup set to default.
[12:06:27.894]     INFO: 13 hot pixels found in step 1
[12:06:28.891]     INFO: Collecting data for 5 seconds...
[12:06:33.907]     INFO: Done with hot pixel readout
[12:06:46.081]     INFO: PixTest::       pg_setup set to default.
[12:06:46.082]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:46.082]     INFO: 13 hot pixels found in step 2
[12:06:47.077]     INFO: Collecting data for 5 seconds...
[12:06:52.095]     INFO: Done with hot pixel readout
[12:07:04.374]     INFO: PixTest::       pg_setup set to default.
[12:07:04.375]     INFO: 15 hot pixels found in step 3
[12:07:05.370]     INFO: Collecting data for 5 seconds...
[12:07:10.387]     INFO: Done with hot pixel readout
[12:07:22.586]     INFO: PixTest::       pg_setup set to default.
[12:07:22.587]     INFO: 11 hot pixels found in step 4
[12:07:23.590]     INFO: Collecting data for 5 seconds...
[12:07:28.607]     INFO: Done with hot pixel readout
[12:07:40.648]     INFO: PixTest::       pg_setup set to default.
[12:07:40.649]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:40.649]     INFO: 6 hot pixels found in step 5
[12:07:41.645]     INFO: Collecting data for 5 seconds...
[12:07:46.662]     INFO: Done with hot pixel readout
[12:07:58.604]     INFO: PixTest::       pg_setup set to default.
[12:07:58.605]     INFO: 7 hot pixels found in step 6
[12:07:59.602]     INFO: Collecting data for 5 seconds...
[12:08:04.618]     INFO: Done with hot pixel readout
[12:08:16.536]     INFO: PixTest::       pg_setup set to default.
[12:08:16.537]     INFO: 11 hot pixels found in step 7
[12:08:17.533]     INFO: Collecting data for 5 seconds...
[12:08:22.550]     INFO: Done with hot pixel readout
[12:08:34.567]     INFO: PixTest::       pg_setup set to default.
[12:08:34.567]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:08:34.567]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:08:34.567]     INFO: 10 hot pixels found in step 8
[12:08:35.564]     INFO: Collecting data for 5 seconds...
[12:08:40.580]     INFO: Done with hot pixel readout
[12:08:52.710]     INFO: PixTest::       pg_setup set to default.
[12:08:52.710]     INFO: 5 hot pixels found in step 9
[12:08:53.707]     INFO: Collecting data for 5 seconds...
[12:08:58.723]     INFO: Done with hot pixel readout
[12:09:10.952]     INFO: PixTest::       pg_setup set to default.
[12:09:10.952]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:09:10.953]     INFO: 12 hot pixels found in step 10
[12:09:11.949]     INFO: Collecting data for 5 seconds...
[12:09:16.967]     INFO: Done with hot pixel readout
[12:09:29.104]     INFO: PixTest::       pg_setup set to default.
[12:09:29.105]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:09:29.105]     INFO: 8 hot pixels found in step 11
[12:09:30.102]     INFO: Collecting data for 5 seconds...
[12:09:35.120]     INFO: Done with hot pixel readout
[12:09:47.053]     INFO: PixTest::       pg_setup set to default.
[12:09:47.054]     INFO: 2 hot pixels found in step 12
[12:09:48.050]     INFO: Collecting data for 5 seconds...
[12:09:53.068]     INFO: Done with hot pixel readout
[12:10:04.775]     INFO: PixTest::       pg_setup set to default.
[12:10:04.776]     INFO: 15 hot pixels found in step 13
[12:10:05.772]     INFO: Collecting data for 5 seconds...
[12:10:10.789]     INFO: Done with hot pixel readout
[12:10:22.606]     INFO: PixTest::       pg_setup set to default.
[12:10:22.607]     INFO: 8 hot pixels found in step 14
[12:10:22.647]     INFO: 8 hot pixels could not be trimmed and have been masked.
[12:10:22.650]     INFO: PixTest::trimHotPixels() done
[12:10:22.651]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat
[12:10:22.658]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C1.dat
[12:10:22.665]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C2.dat
[12:10:22.672]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C3.dat
[12:10:22.679]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C4.dat
[12:10:22.685]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C5.dat
[12:10:22.691]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C6.dat
[12:10:22.698]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C7.dat
[12:10:22.704]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C8.dat
[12:10:22.710]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C9.dat
[12:10:22.715]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C10.dat
[12:10:22.721]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C11.dat
[12:10:22.726]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C12.dat
[12:10:22.731]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C13.dat
[12:10:22.737]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C14.dat
[12:10:22.742]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[12:10:22.748]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[12:10:22.762]     INFO: enter test to run
[12:10:55.195]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:10:55.195]     INFO:   running: highrate
[12:10:55.199]     INFO:    ----------------------------------------------------------------------
[12:10:55.200]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:10:55.200]     INFO:    ----------------------------------------------------------------------
[12:10:55.200]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:10:55.200]     INFO: edge/corner pixel THR is adjusted
[12:10:55.200]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:10:56.157]     INFO: Collecting data for 1 seconds...
[12:10:57.161]     INFO: Done with hot pixel readout
[12:11:01.247]     INFO: PixTest::       pg_setup set to default.
[12:11:01.248]     INFO: 0 hot pixels found in step 0
[12:11:01.253]     INFO: 0 hot pixels could not be trimmed and have been masked.
[12:11:01.335]     INFO: PixTest::trimHotPixels() done
[12:11:01.335]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat
[12:11:01.344]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C1.dat
[12:11:01.351]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C2.dat
[12:11:01.356]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C3.dat
[12:11:01.361]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C4.dat
[12:11:01.366]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C5.dat
[12:11:01.372]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C6.dat
[12:11:01.377]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C7.dat
[12:11:01.382]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C8.dat
[12:11:01.387]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C9.dat
[12:11:01.392]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C10.dat
[12:11:01.398]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C11.dat
[12:11:01.403]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C12.dat
[12:11:01.409]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C13.dat
[12:11:01.414]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C14.dat
[12:11:01.420]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[12:11:01.427]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-32_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[12:11:01.438]     INFO: enter test to run
[12:11:29.602]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:11:29.603]     INFO:   running: xray
[12:11:29.604]     INFO:    ----------------------------------------------------------------------
[12:11:29.604]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:11:29.604]     INFO:    ----------------------------------------------------------------------
[12:11:30.567]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:11:41.584]     INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:12:11.823]     INFO: Resuming triggers.
[12:12:22.843]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:12:52.763]     INFO: Resuming triggers.
[12:13:03.781]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:13:33.491]     INFO: Resuming triggers.
[12:13:44.509]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:14:14.046]     INFO: Resuming triggers.
[12:14:25.060]     INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:14:54.620]     INFO: Resuming triggers.
[12:15:05.634]     INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:15:35.329]     INFO: Resuming triggers.
[12:15:46.343]     INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:16:15.725]     INFO: Resuming triggers.
[12:16:26.744]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:16:56.332]     INFO: Resuming triggers.
[12:17:07.351]     INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:17:37.122]     INFO: Resuming triggers.
[12:17:38.315]     INFO: data taking finished, elapsed time: 100 seconds.
[12:17:41.928]     INFO: PixTest::       pg_setup set to default.
[12:17:41.931]     INFO: PixTestXray::doPhRun() done
[12:17:42.070]     INFO: enter test to run
[12:18:12.360]     INFO:   test: [D[BXray setting parameters: ->source=DCHighRate<-
[12:18:12.360]     INFO:   running: [d[bxray
[12:18:12.384]     INFO: command ->[d[bxray<- not known, ignored
[12:18:12.384]     INFO: enter test to run
[12:18:50.367]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:18:50.368]     INFO:   running: xray
[12:18:50.369]     INFO:    ----------------------------------------------------------------------
[12:18:50.369]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:18:50.369]     INFO:    ----------------------------------------------------------------------
[12:18:51.336]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:18:57.624]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:19:27.879]     INFO: Resuming triggers.
[12:19:34.172]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:20:04.503]     INFO: Resuming triggers.
[12:20:10.791]     INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:20:41.040]     INFO: Resuming triggers.
[12:20:47.334]     INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:21:18.459]     INFO: Resuming triggers.
[12:21:24.752]     INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:21:56.124]     INFO: Resuming triggers.
[12:22:02.418]     INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[12:22:33.373]     INFO: Resuming triggers.
[12:22:39.663]     INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:23:11.416]     INFO: Resuming triggers.
[12:23:17.706]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:23:49.447]     INFO: Resuming triggers.
[12:23:55.738]     INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:24:27.294]     INFO: Resuming triggers.
[12:24:33.583]     INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[12:25:03.765]     INFO: Resuming triggers.
[12:25:10.051]     INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:25:40.344]     INFO: Resuming triggers.
[12:25:46.631]     INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:26:16.825]     INFO: Resuming triggers.
[12:26:23.113]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:26:53.447]     INFO: Resuming triggers.
[12:26:59.732]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:27:29.940]     INFO: Resuming triggers.
[12:27:36.226]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:28:06.421]     INFO: Resuming triggers.
[12:28:12.424]     INFO: data taking finished, elapsed time: 100 seconds.
[12:28:41.483]     INFO: PixTest::       pg_setup set to default.
[12:28:41.486]     INFO: PixTestXray::doPhRun() done
[12:28:41.639]     INFO: enter test to run
[12:29:29.339]     INFO:   test: HighRate no parameter change
[12:29:29.339]     INFO:   running: highrate
[12:29:29.357]     INFO:    ----------------------------------------------------------------------
[12:29:29.357]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:29:29.357]     INFO:    ----------------------------------------------------------------------
[12:29:29.513]     INFO: Expecting 768 events.
[12:29:30.647]     INFO: 768 events read in total (419ms).
[12:29:30.647]     INFO: Test took 1269ms.
[12:29:31.451]     INFO: Expecting 41600 events.
[12:29:34.556]     INFO: 41600 events read in total (2579ms).
[12:29:34.557]     INFO: Test took 3850ms.
[12:29:34.593]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:35.314]     INFO: Expecting 41600 events.
[12:29:38.554]     INFO: 41600 events read in total (2713ms).
[12:29:38.555]     INFO: Test took 3945ms.
[12:29:38.593]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:39.304]     INFO: Expecting 41600 events.
[12:29:42.589]     INFO: 41600 events read in total (2758ms).
[12:29:42.590]     INFO: Test took 3977ms.
[12:29:42.627]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:43.343]     INFO: Expecting 41600 events.
[12:29:46.613]     INFO: 41600 events read in total (2743ms).
[12:29:46.614]     INFO: Test took 3968ms.
[12:29:46.652]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:47.371]     INFO: Expecting 41600 events.
[12:29:50.633]     INFO: 41600 events read in total (2735ms).
[12:29:50.634]     INFO: Test took 3962ms.
[12:29:50.671]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:51.391]     INFO: Expecting 41600 events.
[12:29:54.672]     INFO: 41600 events read in total (2754ms).
[12:29:54.673]     INFO: Test took 3983ms.
[12:29:54.711]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:55.425]     INFO: Expecting 41600 events.
[12:29:58.719]     INFO: 41600 events read in total (2767ms).
[12:29:58.720]     INFO: Test took 3991ms.
[12:29:58.758]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:59.475]     INFO: Expecting 41600 events.
[12:30:02.753]     INFO: 41600 events read in total (2751ms).
[12:30:02.754]     INFO: Test took 3978ms.
[12:30:02.792]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:03.510]     INFO: Expecting 41600 events.
[12:30:06.797]     INFO: 41600 events read in total (2760ms).
[12:30:06.798]     INFO: Test took 3988ms.
[12:30:06.836]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:07.554]     INFO: Expecting 41600 events.
[12:30:10.840]     INFO: 41600 events read in total (2760ms).
[12:30:10.841]     INFO: Test took 3986ms.
[12:30:10.878]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:11.596]     INFO: Expecting 41600 events.
[12:30:14.881]     INFO: 41600 events read in total (2758ms).
[12:30:14.882]     INFO: Test took 3986ms.
[12:30:14.919]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:15.635]     INFO: Expecting 41600 events.
[12:30:18.928]     INFO: 41600 events read in total (2766ms).
[12:30:18.929]     INFO: Test took 3990ms.
[12:30:18.967]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:19.683]     INFO: Expecting 41600 events.
[12:30:22.972]     INFO: 41600 events read in total (2763ms).
[12:30:22.973]     INFO: Test took 3987ms.
[12:30:23.011]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:23.730]     INFO: Expecting 41600 events.
[12:30:27.014]     INFO: 41600 events read in total (2757ms).
[12:30:27.015]     INFO: Test took 3984ms.
[12:30:27.052]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:27.770]     INFO: Expecting 41600 events.
[12:30:31.033]     INFO: 41600 events read in total (2736ms).
[12:30:31.034]     INFO: Test took 3963ms.
[12:30:31.071]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:31.786]     INFO: Expecting 41600 events.
[12:30:35.069]     INFO: 41600 events read in total (2756ms).
[12:30:35.070]     INFO: Test took 3980ms.
[12:30:35.107]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:35.826]     INFO: Expecting 41600 events.
[12:30:39.116]     INFO: 41600 events read in total (2763ms).
[12:30:39.117]     INFO: Test took 3991ms.
[12:30:39.154]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:39.871]     INFO: Expecting 41600 events.
[12:30:43.155]     INFO: 41600 events read in total (2757ms).
[12:30:43.156]     INFO: Test took 3982ms.
[12:30:43.193]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:43.911]     INFO: Expecting 41600 events.
[12:30:47.209]     INFO: 41600 events read in total (2771ms).
[12:30:47.210]     INFO: Test took 3997ms.
[12:30:47.247]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:47.961]     INFO: Expecting 41600 events.
[12:30:51.106]     INFO: 41600 events read in total (2619ms).
[12:30:51.107]     INFO: Test took 3842ms.
[12:30:51.144]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:51.495]     INFO: enter test to run
[12:31:03.035]     INFO:   test: HighRate no parameter change
[12:31:03.035]     INFO:   running: highrate
[12:31:03.036]     INFO:    ----------------------------------------------------------------------
[12:31:03.036]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:31:03.036]     INFO:    ----------------------------------------------------------------------
[12:31:03.657]     INFO: Expecting 208000 events.
[12:31:15.771]     INFO: 208000 events read in total (11588ms).
[12:31:15.775]     INFO: Test took 12730ms.
[12:31:15.933]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:16.192]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    3    3    0    0    0    0    0    0    0    1
[12:31:16.192]     INFO: number of red-efficiency pixels:    72   38   92  145  152  158  173  107  107  128  167  146  113   68   35   26
[12:31:16.193]     INFO: number of X-ray hits detected:    65796 45319 72951 116053 123440 131168 126803 91442 89706 115171 112594 100420 103799 61184 23869 28577
[12:31:16.193]     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:31:16.193]     INFO: number of Vcal hits detected:  207927 207962 207906 207852 207848 207837 207676 207746 207889 207870 207825 207852 207886 207931 207964 207925
[12:31:16.193]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:31:16.193]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:31:16.193]     INFO: X-ray hit rate [MHz/cm2]:  19.3 13.3 21.4 34.0 36.2 38.4 37.2 26.8 26.3 33.8 33.0 29.4 30.4 17.9 7.0 8.4
[12:31:16.193]     INFO: PixTestHighRate::doXPixelAlive() done
[12:31:16.244]     INFO: PixTest::       pg_setup set to default.
[12:31:16.255]     INFO: enter test to run
[12:32:18.554]     INFO:   test: HighRate no parameter change
[12:32:18.554]     INFO:   running: highrate
[12:32:18.555]     INFO:    ----------------------------------------------------------------------
[12:32:18.555]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:32:18.555]     INFO:    ----------------------------------------------------------------------
[12:32:19.173]     INFO: Expecting 208000 events.
[12:32:33.158]     INFO: 208000 events read in total (13458ms).
[12:32:33.164]     INFO: Test took 14600ms.
[12:32:33.482]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:33.792]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    3    3    0    0    0    0    0    0    0    1
[12:32:33.792]     INFO: number of red-efficiency pixels:   176  108  293  560  482  657  499  398  276  398  476  408  335  203   56   56
[12:32:33.792]     INFO: number of X-ray hits detected:    133071 92011 147135 234416 249948 264345 256199 185116 182884 232246 227810 202705 208792 124244 48145 58016
[12:32:33.792]     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:32:33.792]     INFO: number of Vcal hits detected:  207821 207890 207677 207383 207484 207257 207296 207404 207709 207562 207488 207548 207641 207787 207942 207894
[12:32:33.792]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:32:33.792]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.7 99.8 99.6 99.7 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[12:32:33.792]     INFO: X-ray hit rate [MHz/cm2]:  39.0 27.0 43.1 68.7 73.3 77.5 75.1 54.3 53.6 68.1 66.8 59.4 61.2 36.4 14.1 17.0
[12:32:33.792]     INFO: PixTestHighRate::doXPixelAlive() done
[12:32:33.845]     INFO: PixTest::       pg_setup set to default.
[12:32:33.859]     INFO: enter test to run
[12:33:13.322]     INFO:   test: HighRate no parameter change
[12:33:13.322]     INFO:   running: highrate
[12:33:13.323]     INFO:    ----------------------------------------------------------------------
[12:33:13.323]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:33:13.323]     INFO:    ----------------------------------------------------------------------
[12:33:13.947]     INFO: Expecting 208000 events.
[12:33:30.289]     INFO: 208000 events read in total (15815ms).
[12:33:30.297]     INFO: Test took 16963ms.
[12:33:30.805]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:31.173]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    3    3    0    0    0    0    0    0    0    1
[12:33:31.173]     INFO: number of red-efficiency pixels:   411  216  660 1271 1125 1615 1291  954  621  934 1188 1003  859  405   93  107
[12:33:31.173]     INFO: number of X-ray hits detected:    200659 139900 223066 353774 378524 397969 387810 278922 276910 352130 343490 306752 316391 189153 73280 87866
[12:33:31.173]     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:33:31.173]     INFO: number of Vcal hits detected:  207526 207763 207120 206324 206614 205683 206138 206566 207310 206900 206486 206728 206978 207522 207905 207842
[12:33:31.173]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.6 99.3 99.4 99.0 99.3 99.4 99.7 99.5 99.3 99.5 99.6 99.8 100.0 100.0
[12:33:31.173]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.6 99.2 99.3 98.9 99.1 99.3 99.7 99.5 99.3 99.4 99.5 99.8 100.0 99.9
[12:33:31.173]     INFO: X-ray hit rate [MHz/cm2]:  58.8 41.0 65.4 103.7 110.9 116.6 113.7 81.8 81.2 103.2 100.7 89.9 92.7 55.4 21.5 25.8
[12:33:31.173]     INFO: PixTestHighRate::doXPixelAlive() done
[12:33:31.217]     INFO: PixTest::       pg_setup set to default.
[12:33:31.236]     INFO: enter test to run
[12:34:29.089]     INFO:   test: exit no parameter change
[12:34:29.359]    QUIET: Connection to board 33 closed.
[12:34:29.368]     INFO: pXar: this is the end, my friend