[12:18:56.742] INFO: *** Welcome to pxar ***
[12:18:56.742] INFO: *** Today: 2016/04/13
[12:18:56.783] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:18:56.783] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//dacParameters35_C15.dat
[12:18:56.784] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:18:56.784] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//defaultMaskFile.dat
[12:18:56.784] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C15.dat
[12:18:56.850] INFO: clk: 4
[12:18:56.850] INFO: ctr: 4
[12:18:56.850] INFO: sda: 19
[12:18:56.850] INFO: tin: 9
[12:18:56.850] INFO: level: 15
[12:18:56.850] INFO: triggerdelay: 0
[12:18:56.850] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:18:56.850] INFO: Log level: INFO
[12:18:56.868] QUIET: Connection to board DTB_WREKRL opened.
[12:18:56.872] 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:18:56.875] INFO: RPC call hashes of host and DTB match: 398089610
[12:18:58.407] INFO: DUT info:
[12:18:58.407] INFO: The DUT currently contains the following objects:
[12:18:58.407] INFO: 2 TBM Cores tbm08c (2 ON)
[12:18:58.407] INFO: TBM Core alpha (0): 7 registers set
[12:18:58.408] INFO: TBM Core beta (1): 7 registers set
[12:18:58.408] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:18:58.408] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.408] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:58.812] INFO: enter 'restricted' command line mode
[12:18:58.812] INFO: enter test to run
[12:19:05.099] INFO: test: PixelAlive no parameter change
[12:19:05.099] INFO: running: pixelalive
[12:19:05.108] INFO: ----------------------------------------------------------------------
[12:19:05.108] 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:19:05.108] INFO: ----------------------------------------------------------------------
[12:19:05.423] INFO: Expecting 41600 events.
[12:19:09.738] INFO: 41600 events read in total (3596ms).
[12:19:09.905] INFO: Test took 4795ms.
[12:19:09.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:10.180] INFO: PixTestAlive::aliveTest() done
[12:19:10.180] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:19:10.214] INFO: enter test to run
[12:19:36.971] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:19:36.971] INFO: running: highrate
[12:19:36.971] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:19:37.122] INFO: ----------------------------------------------------------------------
[12:19:37.122] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:19:37.122] INFO: ----------------------------------------------------------------------
[12:19:37.122] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:19:37.122] INFO: edge/corner pixel THR is adjusted
[12:19:37.122] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:19:38.081] INFO: Collecting data for 5 seconds...
[12:19:43.098] INFO: Done with hot pixel readout
[12:19:55.438] INFO: PixTest:: pg_setup set to default.
[12:19:55.438] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:19:55.439] INFO: 47 hot pixels found in step 0
[12:19:56.432] INFO: Collecting data for 5 seconds...
[12:20:01.449] INFO: Done with hot pixel readout
[12:20:13.720] INFO: PixTest:: pg_setup set to default.
[12:20:13.721] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:13.721] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:13.721] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:13.721] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:13.722] INFO: 54 hot pixels found in step 1
[12:20:14.719] INFO: Collecting data for 5 seconds...
[12:20:19.735] INFO: Done with hot pixel readout
[12:20:32.053] INFO: PixTest:: pg_setup set to default.
[12:20:32.053] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:32.053] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:32.054] INFO: 46 hot pixels found in step 2
[12:20:33.050] INFO: Collecting data for 5 seconds...
[12:20:38.067] INFO: Done with hot pixel readout
[12:20:50.364] INFO: PixTest:: pg_setup set to default.
[12:20:50.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:50.365] INFO: 36 hot pixels found in step 3
[12:20:51.361] INFO: Collecting data for 5 seconds...
[12:20:56.378] INFO: Done with hot pixel readout
[12:21:08.705] INFO: PixTest:: pg_setup set to default.
[12:21:08.705] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:08.705] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:08.705] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:08.705] INFO: 42 hot pixels found in step 4
[12:21:09.703] INFO: Collecting data for 5 seconds...
[12:21:14.720] INFO: Done with hot pixel readout
[12:21:27.030] INFO: PixTest:: pg_setup set to default.
[12:21:27.031] INFO: 47 hot pixels found in step 5
[12:21:28.027] INFO: Collecting data for 5 seconds...
[12:21:33.043] INFO: Done with hot pixel readout
[12:21:45.372] INFO: PixTest:: pg_setup set to default.
[12:21:45.372] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:45.372] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:45.372] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:45.373] INFO: 36 hot pixels found in step 6
[12:21:46.370] INFO: Collecting data for 5 seconds...
[12:21:51.387] INFO: Done with hot pixel readout
[12:22:03.707] INFO: PixTest:: pg_setup set to default.
[12:22:03.707] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:03.708] INFO: 29 hot pixels found in step 7
[12:22:04.704] INFO: Collecting data for 5 seconds...
[12:22:09.720] INFO: Done with hot pixel readout
[12:22:22.045] INFO: PixTest:: pg_setup set to default.
[12:22:22.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:22.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:22.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:22.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:22.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:22.046] INFO: 40 hot pixels found in step 8
[12:22:23.052] INFO: Collecting data for 5 seconds...
[12:22:28.069] INFO: Done with hot pixel readout
[12:22:40.379] INFO: PixTest:: pg_setup set to default.
[12:22:40.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:40.380] INFO: 31 hot pixels found in step 9
[12:22:41.377] INFO: Collecting data for 5 seconds...
[12:22:46.394] INFO: Done with hot pixel readout
[12:22:58.755] INFO: PixTest:: pg_setup set to default.
[12:22:58.756] INFO: 35 hot pixels found in step 10
[12:22:59.754] INFO: Collecting data for 5 seconds...
[12:23:04.770] INFO: Done with hot pixel readout
[12:23:17.090] INFO: PixTest:: pg_setup set to default.
[12:23:17.091] INFO: 28 hot pixels found in step 11
[12:23:18.087] INFO: Collecting data for 5 seconds...
[12:23:23.105] INFO: Done with hot pixel readout
[12:23:35.449] INFO: PixTest:: pg_setup set to default.
[12:23:35.449] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:35.450] INFO: 28 hot pixels found in step 12
[12:23:36.446] INFO: Collecting data for 5 seconds...
[12:23:41.463] INFO: Done with hot pixel readout
[12:23:53.797] INFO: PixTest:: pg_setup set to default.
[12:23:53.797] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:53.798] INFO: 22 hot pixels found in step 13
[12:23:54.794] INFO: Collecting data for 5 seconds...
[12:23:59.811] INFO: Done with hot pixel readout
[12:24:12.147] INFO: PixTest:: pg_setup set to default.
[12:24:12.147] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:24:12.147] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:24:12.148] INFO: 32 hot pixels found in step 14
[12:24:12.188] INFO: 32 hot pixels could not be trimmed and have been masked.
[12:24:12.192] INFO: PixTest::trimHotPixels() done
[12:24:12.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C0.dat
[12:24:12.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C1.dat
[12:24:12.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C2.dat
[12:24:12.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C3.dat
[12:24:12.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C4.dat
[12:24:12.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C5.dat
[12:24:12.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C6.dat
[12:24:12.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C7.dat
[12:24:12.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C8.dat
[12:24:12.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C9.dat
[12:24:12.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C10.dat
[12:24:12.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C11.dat
[12:24:12.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C12.dat
[12:24:12.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C13.dat
[12:24:12.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C14.dat
[12:24:12.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C15.dat
[12:24:12.278] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//defaultMaskFile.dat
[12:24:12.289] INFO: enter test to run
[12:24:39.680] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:24:39.680] INFO: running: highrate
[12:24:39.685] INFO: ----------------------------------------------------------------------
[12:24:39.685] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:24:39.685] INFO: ----------------------------------------------------------------------
[12:24:39.685] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:24:39.685] INFO: edge/corner pixel THR is adjusted
[12:24:39.685] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:24:40.643] INFO: Collecting data for 1 seconds...
[12:24:41.647] INFO: Done with hot pixel readout
[12:24:45.902] INFO: PixTest:: pg_setup set to default.
[12:24:45.903] INFO: 0 hot pixels found in step 0
[12:24:45.908] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:24:45.989] INFO: PixTest::trimHotPixels() done
[12:24:45.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C0.dat
[12:24:46.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C1.dat
[12:24:46.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C2.dat
[12:24:46.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C3.dat
[12:24:46.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C4.dat
[12:24:46.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C5.dat
[12:24:46.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C6.dat
[12:24:46.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C7.dat
[12:24:46.039] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C8.dat
[12:24:46.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C9.dat
[12:24:46.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C10.dat
[12:24:46.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C11.dat
[12:24:46.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C12.dat
[12:24:46.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C13.dat
[12:24:46.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C14.dat
[12:24:46.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//trimParameters35_C15.dat
[12:24:46.081] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-34_FPIXTest-17C-Nebraska-160331-1351_2016-03-31_13h51m_1459450269/000_FPIXTest_p17//defaultMaskFile.dat
[12:24:46.091] INFO: enter test to run
[12:25:49.584] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:25:49.584] INFO: running: xray
[12:25:49.585] INFO: ----------------------------------------------------------------------
[12:25:49.585] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:25:49.585] INFO: ----------------------------------------------------------------------
[12:25:50.548] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:26:01.468] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:26:29.409] INFO: Resuming triggers.
[12:26:40.332] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:27:10.557] INFO: Resuming triggers.
[12:27:21.481] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:27:51.708] INFO: Resuming triggers.
[12:28:02.630] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:28:32.705] INFO: Resuming triggers.
[12:28:43.624] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:29:13.821] INFO: Resuming triggers.
[12:29:24.747] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:29:54.940] INFO: Resuming triggers.
[12:30:05.866] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:30:36.064] INFO: Resuming triggers.
[12:30:46.983] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:31:17.193] INFO: Resuming triggers.
[12:31:28.116] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:31:58.258] INFO: Resuming triggers.
[12:32:00.287] INFO: data taking finished, elapsed time: 100 seconds.
[12:32:06.204] INFO: PixTest:: pg_setup set to default.
[12:32:06.207] INFO: PixTestXray::doPhRun() done
[12:32:06.362] INFO: enter test to run
[12:32:56.725] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:32:56.725] INFO: running: xray
[12:32:56.726] INFO: ----------------------------------------------------------------------
[12:32:56.726] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:32:56.726] INFO: ----------------------------------------------------------------------
[12:32:57.698] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:33:03.858] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:33:34.452] INFO: Resuming triggers.
[12:33:40.612] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:34:11.231] INFO: Resuming triggers.
[12:34:17.394] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:34:48.172] INFO: Resuming triggers.
[12:34:54.338] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:35:24.927] INFO: Resuming triggers.
[12:35:31.090] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[12:36:01.717] INFO: Resuming triggers.
[12:36:07.885] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:36:37.339] INFO: Resuming triggers.
[12:36:43.505] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:37:14.134] INFO: Resuming triggers.
[12:37:20.300] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:37:50.849] INFO: Resuming triggers.
[12:37:57.012] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[12:38:27.657] INFO: Resuming triggers.
[12:38:33.823] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:39:04.440] INFO: Resuming triggers.
[12:39:10.604] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:39:41.187] INFO: Resuming triggers.
[12:39:47.348] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:40:17.949] INFO: Resuming triggers.
[12:40:24.111] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:40:54.682] INFO: Resuming triggers.
[12:41:00.842] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:41:31.952] INFO: Resuming triggers.
[12:41:38.111] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:42:09.049] INFO: Resuming triggers.
[12:42:15.209] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:42:45.924] INFO: Resuming triggers.
[12:42:47.651] INFO: data taking finished, elapsed time: 100 seconds.
[12:42:56.538] INFO: PixTest:: pg_setup set to default.
[12:42:56.541] INFO: PixTestXray::doPhRun() done
[12:42:56.691] INFO: enter test to run
[12:44:03.680] INFO: test: HighRate no parameter change
[12:44:03.680] INFO: running: highrate
[12:44:03.691] INFO: ----------------------------------------------------------------------
[12:44:03.691] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:44:03.691] INFO: ----------------------------------------------------------------------
[12:44:03.846] INFO: Expecting 768 events.
[12:44:04.980] INFO: 768 events read in total (419ms).
[12:44:04.981] INFO: Test took 1269ms.
[12:44:05.784] INFO: Expecting 41600 events.
[12:44:08.908] INFO: 41600 events read in total (2597ms).
[12:44:08.909] INFO: Test took 3922ms.
[12:44:08.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:09.670] INFO: Expecting 41600 events.
[12:44:12.894] INFO: 41600 events read in total (2697ms).
[12:44:12.895] INFO: Test took 3929ms.
[12:44:12.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:13.652] INFO: Expecting 41600 events.
[12:44:16.912] INFO: 41600 events read in total (2733ms).
[12:44:16.913] INFO: Test took 3961ms.
[12:44:16.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:17.665] INFO: Expecting 41600 events.
[12:44:20.945] INFO: 41600 events read in total (2753ms).
[12:44:20.946] INFO: Test took 3976ms.
[12:44:20.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:21.698] INFO: Expecting 41600 events.
[12:44:24.979] INFO: 41600 events read in total (2754ms).
[12:44:24.980] INFO: Test took 3977ms.
[12:44:25.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:25.734] INFO: Expecting 41600 events.
[12:44:29.014] INFO: 41600 events read in total (2753ms).
[12:44:29.015] INFO: Test took 3978ms.
[12:44:29.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:29.773] INFO: Expecting 41600 events.
[12:44:33.068] INFO: 41600 events read in total (2769ms).
[12:44:33.069] INFO: Test took 3997ms.
[12:44:33.106] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:33.823] INFO: Expecting 41600 events.
[12:44:37.101] INFO: 41600 events read in total (2751ms).
[12:44:37.102] INFO: Test took 3977ms.
[12:44:37.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:37.857] INFO: Expecting 41600 events.
[12:44:41.132] INFO: 41600 events read in total (2749ms).
[12:44:41.133] INFO: Test took 3973ms.
[12:44:41.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:41.889] INFO: Expecting 41600 events.
[12:44:45.175] INFO: 41600 events read in total (2759ms).
[12:44:45.176] INFO: Test took 3987ms.
[12:44:45.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:45.930] INFO: Expecting 41600 events.
[12:44:49.218] INFO: 41600 events read in total (2761ms).
[12:44:49.219] INFO: Test took 3985ms.
[12:44:49.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:49.973] INFO: Expecting 41600 events.
[12:44:53.241] INFO: 41600 events read in total (2741ms).
[12:44:53.242] INFO: Test took 3966ms.
[12:44:53.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:53.998] INFO: Expecting 41600 events.
[12:44:57.285] INFO: 41600 events read in total (2760ms).
[12:44:57.286] INFO: Test took 3986ms.
[12:44:57.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:58.043] INFO: Expecting 41600 events.
[12:45:01.331] INFO: 41600 events read in total (2761ms).
[12:45:01.332] INFO: Test took 3988ms.
[12:45:01.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:02.088] INFO: Expecting 41600 events.
[12:45:05.359] INFO: 41600 events read in total (2744ms).
[12:45:05.360] INFO: Test took 3971ms.
[12:45:05.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:06.115] INFO: Expecting 41600 events.
[12:45:09.392] INFO: 41600 events read in total (2750ms).
[12:45:09.393] INFO: Test took 3976ms.
[12:45:09.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:10.147] INFO: Expecting 41600 events.
[12:45:13.424] INFO: 41600 events read in total (2750ms).
[12:45:13.425] INFO: Test took 3975ms.
[12:45:13.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:14.181] INFO: Expecting 41600 events.
[12:45:17.455] INFO: 41600 events read in total (2747ms).
[12:45:17.456] INFO: Test took 3973ms.
[12:45:17.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:18.212] INFO: Expecting 41600 events.
[12:45:21.464] INFO: 41600 events read in total (2725ms).
[12:45:21.465] INFO: Test took 3953ms.
[12:45:21.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:22.222] INFO: Expecting 41600 events.
[12:45:25.323] INFO: 41600 events read in total (2574ms).
[12:45:25.324] INFO: Test took 3801ms.
[12:45:25.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:25.726] INFO: enter test to run
[12:45:54.959] INFO: test: HighRate no parameter change
[12:45:54.959] INFO: running: highrate
[12:45:54.960] INFO: ----------------------------------------------------------------------
[12:45:54.960] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:45:54.960] INFO: ----------------------------------------------------------------------
[12:45:55.579] INFO: Expecting 208000 events.
[12:46:07.675] INFO: 208000 events read in total (11569ms).
[12:46:07.678] INFO: Test took 12708ms.
[12:46:07.840] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:08.097] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:46:08.097] INFO: number of red-efficiency pixels: 85 67 104 153 194 176 198 107 100 122 113 110 83 71 28 31
[12:46:08.097] INFO: number of X-ray hits detected: 75941 52076 76635 120743 131196 131531 130224 91928 89976 109643 112410 94223 97210 59496 26301 27950
[12:46:08.097] 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:46:08.097] INFO: number of Vcal hits detected: 207914 207931 207891 207844 207795 207819 207795 207892 207900 207877 207882 207888 207915 207928 207971 207968
[12:46:08.098] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[12:46:08.098] INFO: Vcal hit overall 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 100.0 100.0 100.0 100.0
[12:46:08.098] INFO: X-ray hit rate [MHz/cm2]: 22.3 15.3 22.5 35.4 38.5 38.6 38.2 26.9 26.4 32.1 32.9 27.6 28.5 17.4 7.7 8.2
[12:46:08.098] INFO: PixTestHighRate::doXPixelAlive() done
[12:46:08.143] INFO: PixTest:: pg_setup set to default.
[12:46:08.157] INFO: enter test to run
[12:46:49.575] INFO: test: HighRate no parameter change
[12:46:49.575] INFO: running: highrate
[12:46:49.576] INFO: ----------------------------------------------------------------------
[12:46:49.576] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:49.576] INFO: ----------------------------------------------------------------------
[12:46:50.193] INFO: Expecting 208000 events.
[12:47:04.306] INFO: 208000 events read in total (13586ms).
[12:47:04.312] INFO: Test took 14728ms.
[12:47:04.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:04.964] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:47:04.964] INFO: number of red-efficiency pixels: 239 148 379 463 586 735 765 352 340 404 408 373 364 237 77 71
[12:47:04.964] INFO: number of X-ray hits detected: 157310 107848 159730 251168 271671 271039 268788 191076 185278 227474 232398 195738 201511 123456 55201 58046
[12:47:04.964] 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:47:04.964] INFO: number of Vcal hits detected: 207744 207846 207564 207494 207348 207135 207133 207613 207636 207566 207554 207595 207617 207749 207923 207929
[12:47:04.964] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.6 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:47:04.964] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.6 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:47:04.964] INFO: X-ray hit rate [MHz/cm2]: 46.1 31.6 46.8 73.6 79.6 79.4 78.8 56.0 54.3 66.7 68.1 57.4 59.1 36.2 16.2 17.0
[12:47:04.964] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:05.014] INFO: PixTest:: pg_setup set to default.
[12:47:05.033] INFO: enter test to run
[12:47:19.238] INFO: test: HighRate no parameter change
[12:47:19.238] INFO: running: highrate
[12:47:19.239] INFO: ----------------------------------------------------------------------
[12:47:19.239] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:19.240] INFO: ----------------------------------------------------------------------
[12:47:19.853] INFO: Expecting 208000 events.
[12:47:36.199] INFO: 208000 events read in total (15819ms).
[12:47:36.207] INFO: Test took 16957ms.
[12:47:36.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:37.095] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:47:37.095] INFO: number of red-efficiency pixels: 481 327 851 1028 1450 1726 1650 727 726 867 965 903 789 577 113 123
[12:47:37.095] INFO: number of X-ray hits detected: 235675 161260 239078 376452 408681 407117 403249 286689 280046 342322 347818 292968 303080 185936 83008 87137
[12:47:37.095] 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:47:37.095] INFO: number of Vcal hits detected: 207402 207640 206782 206710 205988 205434 205600 207072 207166 206970 206816 206913 207054 207276 207884 207875
[12:47:37.095] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.4 99.1 98.9 99.0 99.6 99.6 99.5 99.5 99.5 99.6 99.7 99.9 99.9
[12:47:37.095] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.4 99.0 98.8 98.8 99.6 99.6 99.5 99.4 99.5 99.5 99.7 99.9 99.9
[12:47:37.095] INFO: X-ray hit rate [MHz/cm2]: 69.1 47.3 70.1 110.3 119.8 119.3 118.2 84.0 82.1 100.3 101.9 85.9 88.8 54.5 24.3 25.5
[12:47:37.095] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:37.148] INFO: PixTest:: pg_setup set to default.
[12:47:37.162] INFO: enter test to run
[12:47:41.630] INFO: test: exit no parameter change
[12:47:41.978] QUIET: Connection to board 33 closed.
[12:47:41.987] INFO: pXar: this is the end, my friend