[11:42:20.869] INFO: *** Welcome to pxar ***
[11:42:20.869] INFO: *** Today: 2016/04/13
[11:42:20.919] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:42:20.919] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//dacParameters35_C15.dat
[11:42:20.976] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:42:20.976] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[11:42:20.981] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[11:42:21.160] INFO: clk: 4
[11:42:21.160] INFO: ctr: 4
[11:42:21.160] INFO: sda: 19
[11:42:21.160] INFO: tin: 9
[11:42:21.160] INFO: level: 15
[11:42:21.160] INFO: triggerdelay: 0
[11:42:21.160] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:42:21.160] INFO: Log level: INFO
[11:42:21.179] QUIET: Connection to board DTB_WREKRL opened.
[11:42:21.182] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[11:42:21.185] INFO: RPC call hashes of host and DTB match: 398089610
[11:42:22.720] INFO: DUT info:
[11:42:22.720] INFO: The DUT currently contains the following objects:
[11:42:22.720] INFO: 2 TBM Cores tbm08c (2 ON)
[11:42:22.720] INFO: TBM Core alpha (0): 7 registers set
[11:42:22.720] INFO: TBM Core beta (1): 7 registers set
[11:42:22.720] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:42:22.720] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:22.720] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:42:23.128] INFO: enter 'restricted' command line mode
[11:42:23.128] INFO: enter test to run
[11:42:30.571] INFO: test: PixelAlive no parameter change
[11:42:30.571] INFO: running: pixelalive
[11:42:30.580] INFO: ----------------------------------------------------------------------
[11:42:30.580] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:42:30.580] INFO: ----------------------------------------------------------------------
[11:42:30.901] INFO: Expecting 41600 events.
[11:42:35.237] INFO: 41600 events read in total (3618ms).
[11:42:35.402] INFO: Test took 4818ms.
[11:42:35.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:35.677] INFO: PixTestAlive::aliveTest() done
[11:42:35.677] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 1 0 0 0 2 21 0 0 0 0
[11:42:35.707] INFO: enter test to run
[11:42:54.923] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:42:54.923] INFO: running: highrate
[11:42:54.923] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:42:55.126] INFO: ----------------------------------------------------------------------
[11:42:55.126] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:42:55.126] INFO: ----------------------------------------------------------------------
[11:42:55.126] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:42:55.126] INFO: edge/corner pixel THR is adjusted
[11:42:55.126] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:42:56.086] INFO: Collecting data for 5 seconds...
[11:43:01.103] INFO: Done with hot pixel readout
[11:43:14.753] INFO: PixTest:: pg_setup set to default.
[11:43:14.782] INFO: 896 hot pixels found in step 0
[11:43:15.776] INFO: Collecting data for 5 seconds...
[11:43:20.793] INFO: Done with hot pixel readout
[11:43:32.985] INFO: PixTest:: pg_setup set to default.
[11:43:32.986] INFO: 462 hot pixels found in step 1
[11:43:33.982] INFO: Collecting data for 5 seconds...
[11:43:38.998] INFO: Done with hot pixel readout
[11:43:50.952] INFO: PixTest:: pg_setup set to default.
[11:43:50.953] INFO: 44 hot pixels found in step 2
[11:43:51.948] INFO: Collecting data for 5 seconds...
[11:43:56.964] INFO: Done with hot pixel readout
[11:44:08.927] INFO: PixTest:: pg_setup set to default.
[11:44:08.928] INFO: 21 hot pixels found in step 3
[11:44:09.922] INFO: Collecting data for 5 seconds...
[11:44:14.939] INFO: Done with hot pixel readout
[11:44:26.807] INFO: PixTest:: pg_setup set to default.
[11:44:26.808] INFO: 18 hot pixels found in step 4
[11:44:27.802] INFO: Collecting data for 5 seconds...
[11:44:32.817] INFO: Done with hot pixel readout
[11:44:44.344] INFO: PixTest:: pg_setup set to default.
[11:44:44.344] INFO: 5 hot pixels found in step 5
[11:44:45.338] INFO: Collecting data for 5 seconds...
[11:44:50.355] INFO: Done with hot pixel readout
[11:45:02.275] INFO: PixTest:: pg_setup set to default.
[11:45:02.276] INFO: 7 hot pixels found in step 6
[11:45:03.269] INFO: Collecting data for 5 seconds...
[11:45:08.285] INFO: Done with hot pixel readout
[11:45:20.139] INFO: PixTest:: pg_setup set to default.
[11:45:20.140] INFO: 9 hot pixels found in step 7
[11:45:21.134] INFO: Collecting data for 5 seconds...
[11:45:26.153] INFO: Done with hot pixel readout
[11:45:38.029] INFO: PixTest:: pg_setup set to default.
[11:45:38.030] INFO: 10 hot pixels found in step 8
[11:45:39.025] INFO: Collecting data for 5 seconds...
[11:45:44.041] INFO: Done with hot pixel readout
[11:45:53.647] INFO: PixTest:: pg_setup set to default.
[11:45:53.648] INFO: 5 hot pixels found in step 9
[11:45:54.643] INFO: Collecting data for 5 seconds...
[11:45:59.654] INFO: Done with hot pixel readout
[11:46:08.848] INFO: PixTest:: pg_setup set to default.
[11:46:08.849] INFO: 6 hot pixels found in step 10
[11:46:09.843] INFO: Collecting data for 5 seconds...
[11:46:14.860] INFO: Done with hot pixel readout
[11:46:25.479] INFO: PixTest:: pg_setup set to default.
[11:46:25.480] INFO: 1 hot pixels found in step 11
[11:46:26.481] INFO: Collecting data for 5 seconds...
[11:46:31.497] INFO: Done with hot pixel readout
[11:46:41.762] INFO: PixTest:: pg_setup set to default.
[11:46:41.763] INFO: 6 hot pixels found in step 12
[11:46:42.757] INFO: Collecting data for 5 seconds...
[11:46:47.773] INFO: Done with hot pixel readout
[11:46:57.620] INFO: PixTest:: pg_setup set to default.
[11:46:57.621] INFO: 6 hot pixels found in step 13
[11:46:58.623] INFO: Collecting data for 5 seconds...
[11:47:03.640] INFO: Done with hot pixel readout
[11:47:13.455] INFO: PixTest:: pg_setup set to default.
[11:47:13.456] INFO: 5 hot pixels found in step 14
[11:47:13.495] INFO: 5 hot pixels could not be trimmed and have been masked.
[11:47:13.498] INFO: PixTest::trimHotPixels() done
[11:47:13.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat
[11:47:13.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C1.dat
[11:47:13.514] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C2.dat
[11:47:13.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C3.dat
[11:47:13.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C4.dat
[11:47:13.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C5.dat
[11:47:13.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C6.dat
[11:47:13.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C7.dat
[11:47:13.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C8.dat
[11:47:13.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C9.dat
[11:47:13.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C10.dat
[11:47:13.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C11.dat
[11:47:13.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C12.dat
[11:47:13.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C13.dat
[11:47:13.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C14.dat
[11:47:13.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[11:47:13.598] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[11:47:13.608] INFO: enter test to run
[11:48:12.544] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:48:12.544] INFO: running: highrate
[11:48:12.549] INFO: ----------------------------------------------------------------------
[11:48:12.549] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:48:12.549] INFO: ----------------------------------------------------------------------
[11:48:12.549] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:48:12.549] INFO: edge/corner pixel THR is adjusted
[11:48:12.549] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:48:13.506] INFO: Collecting data for 1 seconds...
[11:48:14.509] INFO: Done with hot pixel readout
[11:48:18.376] INFO: PixTest:: pg_setup set to default.
[11:48:18.377] INFO: 0 hot pixels found in step 0
[11:48:18.382] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:48:18.455] INFO: PixTest::trimHotPixels() done
[11:48:18.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat
[11:48:18.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C1.dat
[11:48:18.477] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C2.dat
[11:48:18.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C3.dat
[11:48:18.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C4.dat
[11:48:18.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C5.dat
[11:48:18.512] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C6.dat
[11:48:18.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C7.dat
[11:48:18.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C8.dat
[11:48:18.528] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C9.dat
[11:48:18.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C10.dat
[11:48:18.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C11.dat
[11:48:18.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C12.dat
[11:48:18.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C13.dat
[11:48:18.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C14.dat
[11:48:18.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[11:48:18.567] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-17_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[11:48:18.582] INFO: enter test to run
[11:49:07.712] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:49:07.712] INFO: running: xray
[11:49:07.713] INFO: ----------------------------------------------------------------------
[11:49:07.713] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:49:07.713] INFO: ----------------------------------------------------------------------
[11:49:08.676] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:49:19.944] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:49:49.210] INFO: Resuming triggers.
[11:50:00.480] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:50:29.818] INFO: Resuming triggers.
[11:50:41.085] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:51:10.060] INFO: Resuming triggers.
[11:51:21.327] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[11:51:50.766] INFO: Resuming triggers.
[11:52:02.031] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:52:31.196] INFO: Resuming triggers.
[11:52:42.460] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:53:11.439] INFO: Resuming triggers.
[11:53:22.707] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[11:53:51.847] INFO: Resuming triggers.
[11:54:03.112] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[11:54:32.423] INFO: Resuming triggers.
[11:54:42.634] INFO: data taking finished, elapsed time: 100 seconds.
[11:55:09.211] INFO: PixTest:: pg_setup set to default.
[11:55:09.214] INFO: PixTestXray::doPhRun() done
[11:55:09.351] INFO: enter test to run
[11:55:44.789] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:55:44.789] INFO: running: xray
[11:55:44.790] INFO: ----------------------------------------------------------------------
[11:55:44.790] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:55:44.790] INFO: ----------------------------------------------------------------------
[11:55:45.766] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:55:52.341] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:56:18.664] INFO: Resuming triggers.
[11:56:25.236] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:56:55.302] INFO: Resuming triggers.
[11:57:01.876] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:57:32.071] INFO: Resuming triggers.
[11:57:38.642] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:58:08.901] INFO: Resuming triggers.
[11:58:15.471] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:58:45.512] INFO: Resuming triggers.
[11:58:52.084] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:59:22.137] INFO: Resuming triggers.
[11:59:28.708] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:59:58.901] INFO: Resuming triggers.
[12:00:05.474] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:00:35.456] INFO: Resuming triggers.
[12:00:42.030] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:01:12.149] INFO: Resuming triggers.
[12:01:18.721] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:01:48.684] INFO: Resuming triggers.
[12:01:55.257] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:02:25.328] INFO: Resuming triggers.
[12:02:31.902] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[12:03:02.124] INFO: Resuming triggers.
[12:03:08.697] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:03:38.964] INFO: Resuming triggers.
[12:03:45.536] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:04:15.510] INFO: Resuming triggers.
[12:04:22.082] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:04:52.082] INFO: Resuming triggers.
[12:04:53.834] INFO: data taking finished, elapsed time: 100 seconds.
[12:05:02.253] INFO: PixTest:: pg_setup set to default.
[12:05:02.256] INFO: PixTestXray::doPhRun() done
[12:05:02.408] INFO: enter test to run
[12:05:17.001] INFO: test: HighRate no parameter change
[12:05:17.001] INFO: running: highrate
[12:05:18.002] INFO: ----------------------------------------------------------------------
[12:05:18.002] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:05:18.002] INFO: ----------------------------------------------------------------------
[12:05:18.142] INFO: Expecting 768 events.
[12:05:19.276] INFO: 768 events read in total (419ms).
[12:05:19.277] INFO: Test took 1269ms.
[12:05:20.080] INFO: Expecting 41600 events.
[12:05:23.244] INFO: 41600 events read in total (2637ms).
[12:05:23.245] INFO: Test took 3963ms.
[12:05:23.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:24.002] INFO: Expecting 41600 events.
[12:05:27.243] INFO: 41600 events read in total (2715ms).
[12:05:27.244] INFO: Test took 3946ms.
[12:05:27.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:27.000] INFO: Expecting 41600 events.
[12:05:31.257] INFO: 41600 events read in total (2730ms).
[12:05:31.258] INFO: Test took 3959ms.
[12:05:31.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:32.016] INFO: Expecting 41600 events.
[12:05:35.284] INFO: 41600 events read in total (2741ms).
[12:05:35.285] INFO: Test took 3973ms.
[12:05:35.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:36.040] INFO: Expecting 41600 events.
[12:05:39.312] INFO: 41600 events read in total (2745ms).
[12:05:39.313] INFO: Test took 3972ms.
[12:05:39.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:40.072] INFO: Expecting 41600 events.
[12:05:43.349] INFO: 41600 events read in total (2750ms).
[12:05:43.350] INFO: Test took 3982ms.
[12:05:43.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:44.105] INFO: Expecting 41600 events.
[12:05:47.393] INFO: 41600 events read in total (2761ms).
[12:05:47.394] INFO: Test took 3988ms.
[12:05:47.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:48.149] INFO: Expecting 41600 events.
[12:05:51.435] INFO: 41600 events read in total (2759ms).
[12:05:51.436] INFO: Test took 3988ms.
[12:05:51.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:52.190] INFO: Expecting 41600 events.
[12:05:55.456] INFO: 41600 events read in total (2740ms).
[12:05:55.457] INFO: Test took 3966ms.
[12:05:55.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:56.212] INFO: Expecting 41600 events.
[12:05:59.500] INFO: 41600 events read in total (2762ms).
[12:05:59.501] INFO: Test took 3989ms.
[12:05:59.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:00.255] INFO: Expecting 41600 events.
[12:06:03.534] INFO: 41600 events read in total (2752ms).
[12:06:03.535] INFO: Test took 3980ms.
[12:06:03.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:04.291] INFO: Expecting 41600 events.
[12:06:07.122] INFO: 41600 events read in total (2304ms).
[12:06:07.122] INFO: Test took 3533ms.
[12:06:07.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:07.882] INFO: Expecting 41600 events.
[12:06:10.983] INFO: 41600 events read in total (2574ms).
[12:06:10.984] INFO: Test took 3806ms.
[12:06:11.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:11.737] INFO: Expecting 41600 events.
[12:06:14.632] INFO: 41600 events read in total (2368ms).
[12:06:14.633] INFO: Test took 3593ms.
[12:06:14.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:15.387] INFO: Expecting 41600 events.
[12:06:18.237] INFO: 41600 events read in total (2323ms).
[12:06:18.238] INFO: Test took 3550ms.
[12:06:18.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:18.997] INFO: Expecting 41600 events.
[12:06:22.279] INFO: 41600 events read in total (2755ms).
[12:06:22.280] INFO: Test took 3987ms.
[12:06:22.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:23.037] INFO: Expecting 41600 events.
[12:06:26.320] INFO: 41600 events read in total (2756ms).
[12:06:26.321] INFO: Test took 3986ms.
[12:06:26.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:27.076] INFO: Expecting 41600 events.
[12:06:30.329] INFO: 41600 events read in total (2726ms).
[12:06:30.330] INFO: Test took 3954ms.
[12:06:30.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:31.087] INFO: Expecting 41600 events.
[12:06:34.346] INFO: 41600 events read in total (2732ms).
[12:06:34.347] INFO: Test took 3962ms.
[12:06:34.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:35.101] INFO: Expecting 41600 events.
[12:06:38.160] INFO: 41600 events read in total (2533ms).
[12:06:38.161] INFO: Test took 3758ms.
[12:06:38.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:38.558] INFO: enter test to run
[12:07:38.440] INFO: test: HighRate no parameter change
[12:07:38.440] INFO: running: highrate
[12:07:38.441] INFO: ----------------------------------------------------------------------
[12:07:38.441] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:07:38.441] INFO: ----------------------------------------------------------------------
[12:07:39.057] INFO: Expecting 208000 events.
[12:07:50.998] INFO: 208000 events read in total (11414ms).
[12:07:50.001] INFO: Test took 12552ms.
[12:07:51.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:51.413] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 1 0 0 0 2 21 0 0 0 0
[12:07:51.413] INFO: number of red-efficiency pixels: 91 61 108 152 158 135 154 100 160 180 176 2019 131 91 49 58
[12:07:51.413] INFO: number of X-ray hits detected: 67220 44859 72853 114977 116463 117951 116661 88008 87640 102669 102164 136105 90632 52927 22585 25923
[12:07:51.414] 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:07:51.414] INFO: number of Vcal hits detected: 207906 207938 207791 207840 207840 207860 207788 207899 207834 207808 207718 204257 207865 207903 207948 207938
[12:07:51.414] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 98.7 99.9 100.0 100.0 100.0
[12:07:51.414] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 98.2 99.9 100.0 100.0 100.0
[12:07:51.414] INFO: X-ray hit rate [MHz/cm2]: 19.7 13.1 21.4 33.7 34.1 34.6 34.2 25.8 25.7 30.1 29.9 39.9 26.6 15.5 6.6 7.6
[12:07:51.414] INFO: PixTestHighRate::doXPixelAlive() done
[12:07:51.470] INFO: PixTest:: pg_setup set to default.
[12:07:51.487] INFO: enter test to run
[12:08:08.792] INFO: test: HighRate no parameter change
[12:08:08.792] INFO: running: highrate
[12:08:08.793] INFO: ----------------------------------------------------------------------
[12:08:08.793] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:08:08.793] INFO: ----------------------------------------------------------------------
[12:08:09.408] INFO: Expecting 208000 events.
[12:08:23.106] INFO: 208000 events read in total (13171ms).
[12:08:23.112] INFO: Test took 14310ms.
[12:08:23.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:23.736] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 1 0 0 0 2 20 0 0 0 0
[12:08:23.737] INFO: number of red-efficiency pixels: 246 127 312 526 571 433 568 291 395 483 436 1822 384 221 108 97
[12:08:23.737] INFO: number of X-ray hits detected: 135994 91338 148392 233232 238370 240948 237723 178514 178331 208506 207210 240667 183573 107641 45995 53198
[12:08:23.737] 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:08:23.737] INFO: number of Vcal hits detected: 207737 207866 207555 207429 207367 207534 207324 207692 207562 207458 207415 204218 207574 207750 207876 207887
[12:08:23.737] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.8 99.8 99.8 98.7 99.8 99.9 99.9 99.9
[12:08:23.737] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.9 99.8 99.7 99.7 98.2 99.8 99.9 99.9 99.9
[12:08:23.737] INFO: X-ray hit rate [MHz/cm2]: 39.9 26.8 43.5 68.4 69.9 70.6 69.7 52.3 52.3 61.1 60.7 70.5 53.8 31.6 13.5 15.6
[12:08:23.737] INFO: PixTestHighRate::doXPixelAlive() done
[12:08:23.787] INFO: PixTest:: pg_setup set to default.
[12:08:23.804] INFO: enter test to run
[12:09:50.775] INFO: test: HighRate no parameter change
[12:09:50.775] INFO: running: highrate
[12:09:50.776] INFO: ----------------------------------------------------------------------
[12:09:50.776] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:09:50.776] INFO: ----------------------------------------------------------------------
[12:09:51.393] INFO: Expecting 208000 events.
[12:10:07.005] INFO: 208000 events read in total (15085ms).
[12:10:07.015] INFO: Test took 16230ms.
[12:10:07.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:07.834] INFO: number of dead pixels (per ROC): 0 0 2 0 0 0 1 0 0 0 2 19 0 0 0 0
[12:10:07.834] INFO: number of red-efficiency pixels: 478 295 651 1141 1246 958 1211 569 743 992 993 1947 763 451 127 123
[12:10:07.834] INFO: number of X-ray hits detected: 201744 135410 219104 344770 352106 356257 350060 264347 264886 308836 306428 334152 272878 159491 67715 79085
[12:10:07.834] 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:10:07.834] INFO: number of Vcal hits detected: 207453 207681 207015 206589 206397 206820 206377 207319 207140 206784 206722 203819 207125 207468 207856 207861
[12:10:07.834] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.3 99.5 99.3 99.7 99.6 99.5 99.5 98.5 99.6 99.8 99.9 99.9
[12:10:07.834] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.2 99.4 99.2 99.7 99.6 99.4 99.4 98.0 99.6 99.7 99.9 99.9
[12:10:07.834] INFO: X-ray hit rate [MHz/cm2]: 59.1 39.7 64.2 101.1 103.2 104.4 102.6 77.5 77.6 90.5 89.8 97.9 80.0 46.7 19.8 23.2
[12:10:07.834] INFO: PixTestHighRate::doXPixelAlive() done
[12:10:07.879] INFO: PixTest:: pg_setup set to default.
[12:10:07.894] INFO: enter test to run
[12:10:25.742] INFO: test: exit no parameter change
[12:10:26.454] QUIET: Connection to board 33 closed.
[12:10:26.455] INFO: pXar: this is the end, my friend