[19:47:15.217]     INFO: *** Welcome to pxar ***
[19:47:15.217]     INFO: *** Today: 2016/10/06
[19:47:15.258]     INFO: *** Version: v1.9.0-818-g96727
[19:47:15.258]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//dacParameters35_C15.dat
[19:47:15.285]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//tbmParameters_C0b.dat
[19:47:15.285]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//defaultMaskFile.dat
[19:47:15.289]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C15.dat
[19:47:15.379]     INFO:         clk: 4
[19:47:15.379]     INFO:         ctr: 4
[19:47:15.379]     INFO:         sda: 19
[19:47:15.379]     INFO:         tin: 9
[19:47:15.379]     INFO:         level: 15
[19:47:15.379]     INFO:         triggerdelay: 0
[19:47:15.379]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[19:47:15.379]     INFO: Log level: INFO
[19:47:15.397]    QUIET: Connection to board DTB_WREKRL opened.
[19:47:15.400]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[19:47:15.403]     INFO: RPC call hashes of host and DTB match: 398089610
[19:47:16.932]     INFO: DUT info: 
[19:47:16.932]     INFO: The DUT currently contains the following objects:
[19:47:16.932]     INFO:  2 TBM Cores tbm08c (2 ON)
[19:47:16.932]     INFO: 	TBM Core alpha (0): 7 registers set
[19:47:16.932]     INFO: 	TBM Core beta  (1): 7 registers set
[19:47:16.932]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[19:47:16.932]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.933]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:16.934]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:17.337]     INFO: enter 'restricted' command line mode
[19:47:17.337]     INFO: enter test to run
[19:47:26.442]     INFO:   test: PixelAlive no parameter change
[19:47:26.443]     INFO:   running: pixelalive
[19:47:26.452]     INFO:    ----------------------------------------------------------------------
[19:47:26.452]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[19:47:26.452]     INFO:    ----------------------------------------------------------------------
[19:47:26.776]     INFO: Expecting 41600 events.
[19:47:31.121]     INFO: 41600 events read in total (3626ms).
[19:47:31.291]     INFO: Test took 4836ms.
[19:47:31.301]     INFO: Fetched DAQ statistics. Counters are being reset now.
[19:47:31.564]     INFO: PixTestAlive::aliveTest() done
[19:47:31.564]     INFO: number of dead pixels (per ROC):     1    0   33    1    0    0    0    0    0    0    2    0    1    0    0    1
[19:47:31.594]     INFO: enter test to run
[19:48:02.562]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[19:48:02.562]     INFO:   running: highrate
[19:48:02.563]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[19:48:02.777]     INFO:    ----------------------------------------------------------------------
[19:48:02.777]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[19:48:02.777]     INFO:    ----------------------------------------------------------------------
[19:48:02.777]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[19:48:02.777]     INFO: edge/corner pixel THR is adjusted
[19:48:02.777]     INFO: PixTestHighRate::trimHotPixels: step 0...
[19:48:03.735]     INFO: Collecting data for 5 seconds...
[19:48:08.754]     INFO: Done with hot pixel readout
[19:48:20.636]     INFO: PixTest::       pg_setup set to default.
[19:48:20.637]     INFO: 6 hot pixels found in step 0
[19:48:21.626]     INFO: Collecting data for 5 seconds...
[19:48:26.645]     INFO: Done with hot pixel readout
[19:48:37.902]     INFO: PixTest::       pg_setup set to default.
[19:48:37.903]     INFO: 6 hot pixels found in step 1
[19:48:38.898]     INFO: Collecting data for 5 seconds...
[19:48:43.915]     INFO: Done with hot pixel readout
[19:48:55.085]     INFO: PixTest::       pg_setup set to default.
[19:48:55.086]     INFO: 2 hot pixels found in step 2
[19:48:56.079]     INFO: Collecting data for 5 seconds...
[19:49:01.096]     INFO: Done with hot pixel readout
[19:49:12.850]     INFO: PixTest::       pg_setup set to default.
[19:49:12.851]     INFO: 4 hot pixels found in step 3
[19:49:13.845]     INFO: Collecting data for 5 seconds...
[19:49:18.975]     INFO: Done with hot pixel readout
[19:49:30.569]     INFO: PixTest::       pg_setup set to default.
[19:49:30.570]     INFO: 6 hot pixels found in step 4
[19:49:31.566]     INFO: Collecting data for 5 seconds...
[19:49:36.583]     INFO: Done with hot pixel readout
[19:49:47.940]     INFO: PixTest::       pg_setup set to default.
[19:49:47.941]     INFO: 1 hot pixels found in step 5
[19:49:48.935]     INFO: Collecting data for 5 seconds...
[19:49:53.953]     INFO: Done with hot pixel readout
[19:50:05.518]     INFO: PixTest::       pg_setup set to default.
[19:50:05.519]     INFO: 3 hot pixels found in step 6
[19:50:06.512]     INFO: Collecting data for 5 seconds...
[19:50:11.530]     INFO: Done with hot pixel readout
[19:50:22.859]     INFO: PixTest::       pg_setup set to default.
[19:50:22.860]     INFO: 2 hot pixels found in step 7
[19:50:23.854]     INFO: Collecting data for 5 seconds...
[19:50:28.872]     INFO: Done with hot pixel readout
[19:50:40.490]     INFO: PixTest::       pg_setup set to default.
[19:50:40.491]     INFO: 5 hot pixels found in step 8
[19:50:41.485]     INFO: Collecting data for 5 seconds...
[19:50:46.503]     INFO: Done with hot pixel readout
[19:50:58.052]     INFO: PixTest::       pg_setup set to default.
[19:50:58.053]     INFO: 1 hot pixels found in step 9
[19:50:59.047]     INFO: Collecting data for 5 seconds...
[19:51:04.066]     INFO: Done with hot pixel readout
[19:51:16.107]     INFO: PixTest::       pg_setup set to default.
[19:51:16.108]     INFO: 3 hot pixels found in step 10
[19:51:17.103]     INFO: Collecting data for 5 seconds...
[19:51:22.123]     INFO: Done with hot pixel readout
[19:51:34.231]     INFO: PixTest::       pg_setup set to default.
[19:51:34.232]     INFO: 6 hot pixels found in step 11
[19:51:35.225]     INFO: Collecting data for 5 seconds...
[19:51:40.244]     INFO: Done with hot pixel readout
[19:51:52.205]     INFO: PixTest::       pg_setup set to default.
[19:51:52.206]     INFO: 3 hot pixels found in step 12
[19:51:53.200]     INFO: Collecting data for 5 seconds...
[19:51:58.220]     INFO: Done with hot pixel readout
[19:52:10.109]     INFO: PixTest::       pg_setup set to default.
[19:52:10.110]     INFO: 5 hot pixels found in step 13
[19:52:11.103]     INFO: Collecting data for 5 seconds...
[19:52:16.127]     INFO: Done with hot pixel readout
[19:52:28.287]     INFO: PixTest::       pg_setup set to default.
[19:52:28.288]     INFO: 5 hot pixels found in step 14
[19:52:28.327]     INFO: 5 hot pixels could not be trimmed and have been masked.
[19:52:28.330]     INFO: PixTest::trimHotPixels() done
[19:52:28.330]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C0.dat
[19:52:28.338]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C1.dat
[19:52:28.344]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C2.dat
[19:52:28.350]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C3.dat
[19:52:28.355]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C4.dat
[19:52:28.361]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C5.dat
[19:52:28.366]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C6.dat
[19:52:28.372]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C7.dat
[19:52:28.377]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C8.dat
[19:52:28.383]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C9.dat
[19:52:28.388]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C10.dat
[19:52:28.394]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C11.dat
[19:52:28.399]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C12.dat
[19:52:28.405]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C13.dat
[19:52:28.410]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C14.dat
[19:52:28.416]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C15.dat
[19:52:28.421]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//defaultMaskFile.dat
[19:52:28.440]     INFO: enter test to run
[19:52:56.352]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[19:52:56.352]     INFO:   running: highrate
[19:52:56.357]     INFO:    ----------------------------------------------------------------------
[19:52:56.357]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[19:52:56.357]     INFO:    ----------------------------------------------------------------------
[19:52:56.357]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[19:52:56.357]     INFO: edge/corner pixel THR is adjusted
[19:52:56.357]     INFO: PixTestHighRate::trimHotPixels: step 0...
[19:52:57.314]     INFO: Collecting data for 1 seconds...
[19:52:58.319]     INFO: Done with hot pixel readout
[19:53:02.634]     INFO: PixTest::       pg_setup set to default.
[19:53:02.635]     INFO: 0 hot pixels found in step 0
[19:53:02.640]     INFO: 0 hot pixels could not be trimmed and have been masked.
[19:53:02.727]     INFO: PixTest::trimHotPixels() done
[19:53:02.727]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C0.dat
[19:53:02.735]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C1.dat
[19:53:02.742]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C2.dat
[19:53:02.747]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C3.dat
[19:53:02.753]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C4.dat
[19:53:02.758]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C5.dat
[19:53:02.764]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C6.dat
[19:53:02.769]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C7.dat
[19:53:02.774]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C8.dat
[19:53:02.780]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C9.dat
[19:53:02.785]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C10.dat
[19:53:02.790]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C11.dat
[19:53:02.796]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C12.dat
[19:53:02.801]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C13.dat
[19:53:02.806]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C14.dat
[19:53:02.812]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//trimParameters35_C15.dat
[19:53:02.817]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-10_FPIXTest-17C-FNAL-161005-0928-150V_2016-10-05_09h28m_1475677711/000_FPIXTest_p17//defaultMaskFile.dat
[19:53:02.827]     INFO: enter test to run
[19:53:38.808]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[19:53:38.808]     INFO:   running: xray
[19:53:38.809]     INFO:    ----------------------------------------------------------------------
[19:53:38.809]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[19:53:38.809]     INFO:    ----------------------------------------------------------------------
[19:53:39.772]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[19:53:50.844]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[19:54:20.433]     INFO: Resuming triggers.
[19:54:31.512]     INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[19:55:01.037]     INFO: Resuming triggers.
[19:55:12.114]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[19:55:41.664]     INFO: Resuming triggers.
[19:55:52.741]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[19:56:22.249]     INFO: Resuming triggers.
[19:56:33.328]     INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[19:57:02.864]     INFO: Resuming triggers.
[19:57:13.937]     INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[19:57:43.519]     INFO: Resuming triggers.
[19:57:54.592]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[19:58:24.011]     INFO: Resuming triggers.
[19:58:35.089]     INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[19:59:04.558]     INFO: Resuming triggers.
[19:59:15.634]     INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[19:59:45.152]     INFO: Resuming triggers.
[19:59:45.793]     INFO: data taking finished, elapsed time: 100 seconds.
[19:59:47.875]     INFO: PixTest::       pg_setup set to default.
[19:59:47.878]     INFO: PixTestXray::doPhRun() done
[19:59:48.020]     INFO: enter test to run
[20:00:13.197]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[20:00:13.197]     INFO:   running: xray
[20:00:13.198]     INFO:    ----------------------------------------------------------------------
[20:00:13.199]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[20:00:13.199]     INFO:    ----------------------------------------------------------------------
[20:00:14.167]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[20:00:20.607]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[20:00:50.794]     INFO: Resuming triggers.
[20:00:57.235]     INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[20:01:28.654]     INFO: Resuming triggers.
[20:01:35.092]     INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[20:02:06.276]     INFO: Resuming triggers.
[20:02:12.716]     INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[20:02:43.162]     INFO: Resuming triggers.
[20:02:49.604]     INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[20:03:20.413]     INFO: Resuming triggers.
[20:03:26.854]     INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[20:03:57.741]     INFO: Resuming triggers.
[20:04:04.182]     INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[20:04:36.245]     INFO: Resuming triggers.
[20:04:42.688]     INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[20:05:14.270]     INFO: Resuming triggers.
[20:05:20.715]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[20:05:51.971]     INFO: Resuming triggers.
[20:05:58.413]     INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[20:06:29.380]     INFO: Resuming triggers.
[20:06:35.824]     INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[20:07:05.976]     INFO: Resuming triggers.
[20:07:12.422]     INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[20:07:42.621]     INFO: Resuming triggers.
[20:07:49.066]     INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[20:08:19.267]     INFO: Resuming triggers.
[20:08:25.712]     INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[20:08:55.913]     INFO: Resuming triggers.
[20:09:02.356]     INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[20:09:32.521]     INFO: Resuming triggers.
[20:09:36.234]     INFO: data taking finished, elapsed time: 100 seconds.
[20:09:53.762]     INFO: PixTest::       pg_setup set to default.
[20:09:53.765]     INFO: PixTestXray::doPhRun() done
[20:09:53.914]     INFO: enter test to run
[20:10:26.809]     INFO:   test: HighRate no parameter change
[20:10:26.809]     INFO:   running: highrate
[20:10:26.822]     INFO:    ----------------------------------------------------------------------
[20:10:26.822]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[20:10:26.822]     INFO:    ----------------------------------------------------------------------
[20:10:26.978]     INFO: Expecting 768 events.
[20:10:28.112]     INFO: 768 events read in total (419ms).
[20:10:28.112]     INFO: Test took 1270ms.
[20:10:28.915]     INFO: Expecting 41600 events.
[20:10:32.041]     INFO: 41600 events read in total (2599ms).
[20:10:32.042]     INFO: Test took 3905ms.
[20:10:32.079]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:32.803]     INFO: Expecting 41600 events.
[20:10:36.016]     INFO: 41600 events read in total (2686ms).
[20:10:36.017]     INFO: Test took 3920ms.
[20:10:36.053]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:36.774]     INFO: Expecting 41600 events.
[20:10:40.020]     INFO: 41600 events read in total (2719ms).
[20:10:40.021]     INFO: Test took 3950ms.
[20:10:40.057]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:40.776]     INFO: Expecting 41600 events.
[20:10:44.030]     INFO: 41600 events read in total (2728ms).
[20:10:44.031]     INFO: Test took 3956ms.
[20:10:44.069]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:44.788]     INFO: Expecting 41600 events.
[20:10:48.061]     INFO: 41600 events read in total (2746ms).
[20:10:48.061]     INFO: Test took 3972ms.
[20:10:48.099]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:48.816]     INFO: Expecting 41600 events.
[20:10:52.080]     INFO: 41600 events read in total (2737ms).
[20:10:52.081]     INFO: Test took 3965ms.
[20:10:52.118]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:52.835]     INFO: Expecting 41600 events.
[20:10:56.103]     INFO: 41600 events read in total (2741ms).
[20:10:56.104]     INFO: Test took 3968ms.
[20:10:56.140]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:10:56.862]     INFO: Expecting 41600 events.
[20:11:00.146]     INFO: 41600 events read in total (2757ms).
[20:11:00.147]     INFO: Test took 3987ms.
[20:11:00.183]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:00.901]     INFO: Expecting 41600 events.
[20:11:04.167]     INFO: 41600 events read in total (2739ms).
[20:11:04.168]     INFO: Test took 3966ms.
[20:11:04.205]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:04.925]     INFO: Expecting 41600 events.
[20:11:08.185]     INFO: 41600 events read in total (2733ms).
[20:11:08.186]     INFO: Test took 3962ms.
[20:11:08.222]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:08.941]     INFO: Expecting 41600 events.
[20:11:12.197]     INFO: 41600 events read in total (2729ms).
[20:11:12.198]     INFO: Test took 3957ms.
[20:11:12.235]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:12.957]     INFO: Expecting 41600 events.
[20:11:16.226]     INFO: 41600 events read in total (2742ms).
[20:11:16.227]     INFO: Test took 3974ms.
[20:11:16.270]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:16.981]     INFO: Expecting 41600 events.
[20:11:20.245]     INFO: 41600 events read in total (2737ms).
[20:11:20.246]     INFO: Test took 3957ms.
[20:11:20.283]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:20.999]     INFO: Expecting 41600 events.
[20:11:24.254]     INFO: 41600 events read in total (2728ms).
[20:11:24.255]     INFO: Test took 3953ms.
[20:11:24.292]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:25.012]     INFO: Expecting 41600 events.
[20:11:28.284]     INFO: 41600 events read in total (2745ms).
[20:11:28.285]     INFO: Test took 3974ms.
[20:11:28.321]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:29.037]     INFO: Expecting 41600 events.
[20:11:32.296]     INFO: 41600 events read in total (2732ms).
[20:11:32.297]     INFO: Test took 3956ms.
[20:11:32.334]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:33.054]     INFO: Expecting 41600 events.
[20:11:36.303]     INFO: 41600 events read in total (2722ms).
[20:11:36.304]     INFO: Test took 3950ms.
[20:11:36.341]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:37.060]     INFO: Expecting 41600 events.
[20:11:40.323]     INFO: 41600 events read in total (2736ms).
[20:11:40.324]     INFO: Test took 3965ms.
[20:11:40.360]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:41.081]     INFO: Expecting 41600 events.
[20:11:44.331]     INFO: 41600 events read in total (2723ms).
[20:11:44.332]     INFO: Test took 3953ms.
[20:11:44.368]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:45.088]     INFO: Expecting 41600 events.
[20:11:48.226]     INFO: 41600 events read in total (2611ms).
[20:11:48.227]     INFO: Test took 3840ms.
[20:11:48.264]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:48.614]     INFO: enter test to run
[20:12:17.816]     INFO:   test: HighRate no parameter change
[20:12:17.817]     INFO:   running: highrate
[20:12:17.818]     INFO:    ----------------------------------------------------------------------
[20:12:17.818]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:12:17.818]     INFO:    ----------------------------------------------------------------------
[20:12:18.437]     INFO: Expecting 208000 events.
[20:12:30.413]     INFO: 208000 events read in total (11449ms).
[20:12:30.416]     INFO: Test took 12588ms.
[20:12:30.572]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:30.831]     INFO: number of dead pixels (per ROC):     0    0   33    1    0    0    0    0    0    0    2    0    1    0    0    1
[20:12:30.831]     INFO: number of red-efficiency pixels:    85   54  137  186  155  180  149  121   90  118  148  133  129   70   18   33
[20:12:30.831]     INFO: number of X-ray hits detected:    72352 45624 72985 111496 113262 123569 124437 92797 90469 110712 109299 92828 92273 57397 22585 27185
[20:12:30.831]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:12:30.831]     INFO: number of Vcal hits detected:  207914 207945 206221 207761 207843 207811 207848 207876 207908 207880 207751 207863 207819 207929 207982 207918
[20:12:30.831]     INFO: Vcal hit fiducial efficiency (%):  100.0 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
[20:12:30.831]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 99.1 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
[20:12:30.831]     INFO: X-ray hit rate [MHz/cm2]:  21.2 13.4 21.4 32.7 33.2 36.2 36.5 27.2 26.5 32.5 32.0 27.2 27.0 16.8 6.6 8.0
[20:12:30.831]     INFO: PixTestHighRate::doXPixelAlive() done
[20:12:30.880]     INFO: PixTest::       pg_setup set to default.
[20:12:30.894]     INFO: enter test to run
[20:12:48.096]     INFO:   test: HighRate no parameter change
[20:12:48.096]     INFO:   running: highrate
[20:12:48.097]     INFO:    ----------------------------------------------------------------------
[20:12:48.097]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:12:48.097]     INFO:    ----------------------------------------------------------------------
[20:12:48.714]     INFO: Expecting 208000 events.
[20:13:02.609]     INFO: 208000 events read in total (13368ms).
[20:13:02.615]     INFO: Test took 14507ms.
[20:13:02.922]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:03.230]     INFO: number of dead pixels (per ROC):     0    0   33    1    0    0    0    0    0    0    2    0    1    0    0    1
[20:13:03.230]     INFO: number of red-efficiency pixels:   229  112  376  539  413  673  549  379  290  437  454  432  386  246   68   82
[20:13:03.230]     INFO: number of X-ray hits detected:    149961 94196 149833 229331 234736 256386 256015 191681 186816 228025 224414 191116 191794 117424 46636 56585
[20:13:03.230]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:13:03.230]     INFO: number of Vcal hits detected:  207753 207884 205938 207363 207547 207255 207394 207584 207695 207535 207392 207528 207536 207727 207929 207867
[20:13:03.230]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[20:13:03.231]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.0 99.7 99.8 99.6 99.7 99.8 99.9 99.8 99.7 99.8 99.8 99.9 100.0 99.9
[20:13:03.231]     INFO: X-ray hit rate [MHz/cm2]:  44.0 27.6 43.9 67.2 68.8 75.1 75.0 56.2 54.8 66.8 65.8 56.0 56.2 34.4 13.7 16.6
[20:13:03.231]     INFO: PixTestHighRate::doXPixelAlive() done
[20:13:03.279]     INFO: PixTest::       pg_setup set to default.
[20:13:03.294]     INFO: enter test to run
[20:13:18.272]     INFO:   test: HighRate no parameter change
[20:13:18.272]     INFO:   running: highrate
[20:13:18.273]     INFO:    ----------------------------------------------------------------------
[20:13:18.273]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:13:18.273]     INFO:    ----------------------------------------------------------------------
[20:13:18.901]     INFO: Expecting 208000 events.
[20:13:34.688]     INFO: 208000 events read in total (15260ms).
[20:13:34.695]     INFO: Test took 16413ms.
[20:13:35.138]     INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:35.492]     INFO: number of dead pixels (per ROC):     0    0   33    1    0    0    0    0    0    0    2    0    1    0    0    1
[20:13:35.492]     INFO: number of red-efficiency pixels:   460  216  812 1270  930 1486 1127  810  617  900 1012  919  846  552   92  133
[20:13:35.492]     INFO: number of X-ray hits detected:    218902 137560 220459 336930 341770 373948 371313 280217 272995 332497 327782 279928 281809 172642 68491 84087
[20:13:35.492]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:13:35.492]     INFO: number of Vcal hits detected:  207450 207770 205242 206305 206860 205940 206540 206957 207269 206916 206647 206883 206953 207325 207901 207815
[20:13:35.492]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.5 99.3 99.5 99.1 99.4 99.5 99.7 99.5 99.5 99.5 99.6 99.7 100.0 99.9
[20:13:35.492]     INFO: Vcal hit overall efficiency (%):  99.7 99.9 98.7 99.2 99.5 99.0 99.3 99.5 99.6 99.5 99.3 99.5 99.5 99.7 100.0 99.9
[20:13:35.492]     INFO: X-ray hit rate [MHz/cm2]:  64.2 40.3 64.6 98.8 100.2 109.6 108.8 82.1 80.0 97.5 96.1 82.0 82.6 50.6 20.1 24.6
[20:13:35.492]     INFO: PixTestHighRate::doXPixelAlive() done
[20:13:35.539]     INFO: PixTest::       pg_setup set to default.
[20:13:35.551]     INFO: enter test to run
[20:13:38.184]     INFO:   test: exit no parameter change
[20:13:38.628]    QUIET: Connection to board 33 closed.
[20:13:38.643]     INFO: pXar: this is the end, my friend