[15:28:21.850] INFO: *** Welcome to pxar ***
[15:28:21.850] INFO: *** Today: 2016/04/28
[15:28:21.897] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:28:21.897] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//dacParameters35_C15.dat
[15:28:21.921] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:28:21.921] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//defaultMaskFile.dat
[15:28:21.921] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C15.dat
[15:28:22.035] INFO: clk: 4
[15:28:22.035] INFO: ctr: 4
[15:28:22.035] INFO: sda: 19
[15:28:22.035] INFO: tin: 9
[15:28:22.035] INFO: level: 15
[15:28:22.035] INFO: triggerdelay: 0
[15:28:22.039] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:28:22.039] INFO: Log level: INFO
[15:28:22.057] QUIET: Connection to board DTB_WREKRL opened.
[15:28:22.061] 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:
------------------------------------------------------
[15:28:22.063] INFO: RPC call hashes of host and DTB match: 398089610
[15:28:23.610] INFO: DUT info:
[15:28:23.610] INFO: The DUT currently contains the following objects:
[15:28:23.610] INFO: 2 TBM Cores tbm08c (2 ON)
[15:28:23.610] INFO: TBM Core alpha (0): 7 registers set
[15:28:23.610] INFO: TBM Core beta (1): 7 registers set
[15:28:23.610] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:28:23.610] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.610] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:23.611] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:28:24.032] INFO: enter 'restricted' command line mode
[15:28:24.032] INFO: enter test to run
[15:28:32.725] INFO: test: PixelAlive no parameter change
[15:28:32.725] INFO: running: pixelalive
[15:28:32.735] INFO: ----------------------------------------------------------------------
[15:28:32.735] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:28:32.735] INFO: ----------------------------------------------------------------------
[15:28:33.057] INFO: Expecting 41600 events.
[15:28:37.387] INFO: 41600 events read in total (3612ms).
[15:28:37.554] INFO: Test took 4815ms.
[15:28:37.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:37.829] INFO: PixTestAlive::aliveTest() done
[15:28:37.829] INFO: number of dead pixels (per ROC): 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:28:37.862] INFO: enter test to run
[15:29:06.261] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:29:06.261] INFO: running: highrate
[15:29:06.262] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:29:06.469] INFO: ----------------------------------------------------------------------
[15:29:06.469] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:29:06.469] INFO: ----------------------------------------------------------------------
[15:29:06.469] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:29:06.469] INFO: edge/corner pixel THR is adjusted
[15:29:06.469] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:29:07.429] INFO: Collecting data for 5 seconds...
[15:29:12.445] INFO: Done with hot pixel readout
[15:29:24.647] INFO: PixTest:: pg_setup set to default.
[15:29:24.647] INFO: 22 hot pixels found in step 0
[15:29:25.665] INFO: Collecting data for 5 seconds...
[15:29:30.681] INFO: Done with hot pixel readout
[15:29:42.844] INFO: PixTest:: pg_setup set to default.
[15:29:42.845] INFO: 22 hot pixels found in step 1
[15:29:43.836] INFO: Collecting data for 5 seconds...
[15:29:48.852] INFO: Done with hot pixel readout
[15:30:01.029] INFO: PixTest:: pg_setup set to default.
[15:30:01.030] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:30:01.030] INFO: 24 hot pixels found in step 2
[15:30:02.022] INFO: Collecting data for 5 seconds...
[15:30:07.038] INFO: Done with hot pixel readout
[15:30:19.181] INFO: PixTest:: pg_setup set to default.
[15:30:19.182] INFO: 17 hot pixels found in step 3
[15:30:20.172] INFO: Collecting data for 5 seconds...
[15:30:25.188] INFO: Done with hot pixel readout
[15:30:37.378] INFO: PixTest:: pg_setup set to default.
[15:30:37.378] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:30:37.378] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:30:37.379] INFO: 26 hot pixels found in step 4
[15:30:38.370] INFO: Collecting data for 5 seconds...
[15:30:43.386] INFO: Done with hot pixel readout
[15:30:55.360] INFO: PixTest:: pg_setup set to default.
[15:30:55.360] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:30:55.361] INFO: 20 hot pixels found in step 5
[15:30:56.351] INFO: Collecting data for 5 seconds...
[15:31:01.368] INFO: Done with hot pixel readout
[15:31:12.696] INFO: PixTest:: pg_setup set to default.
[15:31:12.696] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:12.696] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:12.697] INFO: 15 hot pixels found in step 6
[15:31:13.696] INFO: Collecting data for 5 seconds...
[15:31:18.713] INFO: Done with hot pixel readout
[15:31:30.172] INFO: PixTest:: pg_setup set to default.
[15:31:30.172] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:30.172] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:30.173] INFO: 21 hot pixels found in step 7
[15:31:31.165] INFO: Collecting data for 5 seconds...
[15:31:36.181] INFO: Done with hot pixel readout
[15:31:47.224] INFO: PixTest:: pg_setup set to default.
[15:31:47.224] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:47.224] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:31:47.225] INFO: 16 hot pixels found in step 8
[15:31:48.215] INFO: Collecting data for 5 seconds...
[15:31:53.232] INFO: Done with hot pixel readout
[15:32:05.064] INFO: PixTest:: pg_setup set to default.
[15:32:05.064] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:05.064] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:05.064] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:05.065] INFO: 11 hot pixels found in step 9
[15:32:06.057] INFO: Collecting data for 5 seconds...
[15:32:11.073] INFO: Done with hot pixel readout
[15:32:22.501] INFO: PixTest:: pg_setup set to default.
[15:32:22.501] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:22.501] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:22.502] INFO: 11 hot pixels found in step 10
[15:32:23.499] INFO: Collecting data for 5 seconds...
[15:32:28.516] INFO: Done with hot pixel readout
[15:32:39.215] INFO: PixTest:: pg_setup set to default.
[15:32:39.215] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:39.215] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:39.216] INFO: 8 hot pixels found in step 11
[15:32:40.206] INFO: Collecting data for 5 seconds...
[15:32:45.223] INFO: Done with hot pixel readout
[15:32:57.389] INFO: PixTest:: pg_setup set to default.
[15:32:57.389] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:57.389] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:32:57.390] INFO: 15 hot pixels found in step 12
[15:32:58.381] INFO: Collecting data for 5 seconds...
[15:33:03.397] INFO: Done with hot pixel readout
[15:33:15.522] INFO: PixTest:: pg_setup set to default.
[15:33:15.522] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:33:15.522] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:33:15.522] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:33:15.523] INFO: 12 hot pixels found in step 13
[15:33:16.514] INFO: Collecting data for 5 seconds...
[15:33:21.530] INFO: Done with hot pixel readout
[15:33:33.667] INFO: PixTest:: pg_setup set to default.
[15:33:33.667] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:33:33.667] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:33:33.668] INFO: 10 hot pixels found in step 14
[15:33:33.702] INFO: 10 hot pixels could not be trimmed and have been masked.
[15:33:33.706] INFO: PixTest::trimHotPixels() done
[15:33:33.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C0.dat
[15:33:33.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C1.dat
[15:33:33.724] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C2.dat
[15:33:33.729] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C3.dat
[15:33:33.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C4.dat
[15:33:33.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C5.dat
[15:33:33.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C6.dat
[15:33:33.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C7.dat
[15:33:33.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C8.dat
[15:33:33.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C9.dat
[15:33:33.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C10.dat
[15:33:33.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C11.dat
[15:33:33.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C12.dat
[15:33:33.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C13.dat
[15:33:33.788] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C14.dat
[15:33:33.793] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C15.dat
[15:33:33.798] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//defaultMaskFile.dat
[15:33:33.808] INFO: enter test to run
[15:33:59.251] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:33:59.251] INFO: running: highrate
[15:33:59.255] INFO: ----------------------------------------------------------------------
[15:33:59.255] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:33:59.256] INFO: ----------------------------------------------------------------------
[15:33:59.256] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:33:59.256] INFO: edge/corner pixel THR is adjusted
[15:33:59.256] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:34:00.213] INFO: Collecting data for 1 seconds...
[15:34:01.216] INFO: Done with hot pixel readout
[15:34:05.160] INFO: PixTest:: pg_setup set to default.
[15:34:05.161] INFO: 0 hot pixels found in step 0
[15:34:05.166] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:34:05.258] INFO: PixTest::trimHotPixels() done
[15:34:05.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C0.dat
[15:34:05.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C1.dat
[15:34:05.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C2.dat
[15:34:05.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C3.dat
[15:34:05.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C4.dat
[15:34:05.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C5.dat
[15:34:05.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C6.dat
[15:34:05.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C7.dat
[15:34:05.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C8.dat
[15:34:05.314] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C9.dat
[15:34:05.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C10.dat
[15:34:05.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C11.dat
[15:34:05.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C12.dat
[15:34:05.335] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C13.dat
[15:34:05.340] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C14.dat
[15:34:05.345] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//trimParameters35_C15.dat
[15:34:05.351] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-09_FPIXTest-17C-FNAL-160426-1157_2016-04-26_11h57m_1461689842/000_FPIXTest_p17//defaultMaskFile.dat
[15:34:05.360] INFO: enter test to run
[15:35:46.530] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:35:46.530] INFO: running: xray
[15:35:46.532] INFO: ----------------------------------------------------------------------
[15:35:46.532] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:35:46.532] INFO: ----------------------------------------------------------------------
[15:35:47.510] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:35:58.695] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:36:28.368] INFO: Resuming triggers.
[15:36:39.553] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:37:08.898] INFO: Resuming triggers.
[15:37:20.080] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:37:49.695] INFO: Resuming triggers.
[15:38:00.878] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:38:30.355] INFO: Resuming triggers.
[15:38:41.534] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:39:11.016] INFO: Resuming triggers.
[15:39:22.202] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:39:51.710] INFO: Resuming triggers.
[15:40:02.892] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:40:32.291] INFO: Resuming triggers.
[15:40:43.469] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:41:12.854] INFO: Resuming triggers.
[15:41:23.717] INFO: data taking finished, elapsed time: 100 seconds.
[15:41:52.538] INFO: PixTest:: pg_setup set to default.
[15:41:52.541] INFO: PixTestXray::doPhRun() done
[15:41:52.724] INFO: enter test to run
[15:43:03.887] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:43:03.887] INFO: running: xray
[15:43:03.888] INFO: ----------------------------------------------------------------------
[15:43:03.888] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:43:03.888] INFO: ----------------------------------------------------------------------
[15:43:04.858] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:43:11.744] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:43:41.805] INFO: Resuming triggers.
[15:43:48.692] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:44:18.765] INFO: Resuming triggers.
[15:44:25.652] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:44:54.881] INFO: Resuming triggers.
[15:45:01.769] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:45:31.772] INFO: Resuming triggers.
[15:45:38.658] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:46:08.713] INFO: Resuming triggers.
[15:46:15.604] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:46:45.670] INFO: Resuming triggers.
[15:46:52.560] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:47:22.638] INFO: Resuming triggers.
[15:47:29.529] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[15:47:59.590] INFO: Resuming triggers.
[15:48:06.483] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:48:36.534] INFO: Resuming triggers.
[15:48:43.428] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:49:13.385] INFO: Resuming triggers.
[15:49:20.275] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[15:49:50.372] INFO: Resuming triggers.
[15:49:57.262] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:50:27.243] INFO: Resuming triggers.
[15:50:34.130] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:51:04.176] INFO: Resuming triggers.
[15:51:11.066] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[15:51:41.111] INFO: Resuming triggers.
[15:51:44.973] INFO: data taking finished, elapsed time: 100 seconds.
[15:52:02.088] INFO: PixTest:: pg_setup set to default.
[15:52:02.091] INFO: PixTestXray::doPhRun() done
[15:52:02.244] INFO: enter test to run
[15:52:23.371] INFO: test: HighRate no parameter change
[15:52:23.371] INFO: running: highrate
[15:52:23.372] INFO: ----------------------------------------------------------------------
[15:52:23.372] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:52:23.372] INFO: ----------------------------------------------------------------------
[15:52:23.529] INFO: Expecting 768 events.
[15:52:24.663] INFO: 768 events read in total (419ms).
[15:52:24.663] INFO: Test took 1269ms.
[15:52:25.467] INFO: Expecting 41600 events.
[15:52:28.588] INFO: 41600 events read in total (2595ms).
[15:52:28.589] INFO: Test took 3899ms.
[15:52:28.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:29.353] INFO: Expecting 41600 events.
[15:52:32.550] INFO: 41600 events read in total (2671ms).
[15:52:32.551] INFO: Test took 3909ms.
[15:52:32.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:33.309] INFO: Expecting 41600 events.
[15:52:36.543] INFO: 41600 events read in total (2707ms).
[15:52:36.544] INFO: Test took 3940ms.
[15:52:36.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:37.301] INFO: Expecting 41600 events.
[15:52:40.564] INFO: 41600 events read in total (2736ms).
[15:52:40.565] INFO: Test took 3966ms.
[15:52:40.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:41.321] INFO: Expecting 41600 events.
[15:52:44.571] INFO: 41600 events read in total (2723ms).
[15:52:44.572] INFO: Test took 3953ms.
[15:52:44.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:45.328] INFO: Expecting 41600 events.
[15:52:48.570] INFO: 41600 events read in total (2715ms).
[15:52:48.571] INFO: Test took 3946ms.
[15:52:48.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:49.329] INFO: Expecting 41600 events.
[15:52:52.590] INFO: 41600 events read in total (2734ms).
[15:52:52.591] INFO: Test took 3967ms.
[15:52:52.628] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:53.349] INFO: Expecting 41600 events.
[15:52:56.608] INFO: 41600 events read in total (2732ms).
[15:52:56.609] INFO: Test took 3963ms.
[15:52:56.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:57.365] INFO: Expecting 41600 events.
[15:53:00.618] INFO: 41600 events read in total (2726ms).
[15:53:00.619] INFO: Test took 3957ms.
[15:53:00.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:01.377] INFO: Expecting 41600 events.
[15:53:04.646] INFO: 41600 events read in total (2742ms).
[15:53:04.647] INFO: Test took 3976ms.
[15:53:04.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:05.401] INFO: Expecting 41600 events.
[15:53:08.656] INFO: 41600 events read in total (2728ms).
[15:53:08.657] INFO: Test took 3957ms.
[15:53:08.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:09.413] INFO: Expecting 41600 events.
[15:53:12.677] INFO: 41600 events read in total (2737ms).
[15:53:12.678] INFO: Test took 3968ms.
[15:53:12.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:13.434] INFO: Expecting 41600 events.
[15:53:16.697] INFO: 41600 events read in total (2736ms).
[15:53:16.698] INFO: Test took 3966ms.
[15:53:16.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:17.457] INFO: Expecting 41600 events.
[15:53:20.728] INFO: 41600 events read in total (2745ms).
[15:53:20.729] INFO: Test took 3978ms.
[15:53:20.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:21.486] INFO: Expecting 41600 events.
[15:53:24.737] INFO: 41600 events read in total (2724ms).
[15:53:24.738] INFO: Test took 3954ms.
[15:53:24.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:25.496] INFO: Expecting 41600 events.
[15:53:28.754] INFO: 41600 events read in total (2731ms).
[15:53:28.755] INFO: Test took 3965ms.
[15:53:28.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:29.511] INFO: Expecting 41600 events.
[15:53:32.775] INFO: 41600 events read in total (2738ms).
[15:53:32.776] INFO: Test took 3967ms.
[15:53:32.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:33.533] INFO: Expecting 41600 events.
[15:53:36.794] INFO: 41600 events read in total (2735ms).
[15:53:36.795] INFO: Test took 3965ms.
[15:53:36.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:37.550] INFO: Expecting 41600 events.
[15:53:40.791] INFO: 41600 events read in total (2714ms).
[15:53:40.792] INFO: Test took 3943ms.
[15:53:40.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:41.547] INFO: Expecting 41600 events.
[15:53:44.678] INFO: 41600 events read in total (2604ms).
[15:53:44.679] INFO: Test took 3831ms.
[15:53:44.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:45.075] INFO: enter test to run
[15:54:15.002] INFO: test: HighRate no parameter change
[15:54:15.002] INFO: running: highrate
[15:54:15.003] INFO: ----------------------------------------------------------------------
[15:54:15.003] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:54:15.003] INFO: ----------------------------------------------------------------------
[15:54:16.618] INFO: Expecting 208000 events.
[15:54:26.710] INFO: 208000 events read in total (9565ms).
[15:54:26.713] INFO: Test took 10702ms.
[15:54:26.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:27.119] INFO: number of dead pixels (per ROC): 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:54:27.119] INFO: number of red-efficiency pixels: 85 51 75 190 163 168 118 93 84 106 101 84 97 50 31 26
[15:54:27.119] INFO: number of X-ray hits detected: 71451 46773 69907 113413 112758 122577 119643 82642 76496 98104 93872 89161 91874 55453 25597 25986
[15:54:27.119] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:54:27.119] INFO: number of Vcal hits detected: 207913 207801 207914 207805 207835 207831 207878 207906 207914 207894 207897 207915 207903 207950 207969 207974
[15:54:27.119] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:54:27.119] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[15:54:27.119] INFO: X-ray hit rate [MHz/cm2]: 20.9 13.7 20.5 33.2 33.1 35.9 35.1 24.2 22.4 28.8 27.5 26.1 26.9 16.3 7.5 7.6
[15:54:27.119] INFO: PixTestHighRate::doXPixelAlive() done
[15:54:27.165] INFO: PixTest:: pg_setup set to default.
[15:54:27.172] INFO: enter test to run
[15:54:43.842] INFO: test: HighRate no parameter change
[15:54:43.842] INFO: running: highrate
[15:54:43.843] INFO: ----------------------------------------------------------------------
[15:54:43.843] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:54:43.843] INFO: ----------------------------------------------------------------------
[15:54:44.459] INFO: Expecting 208000 events.
[15:54:58.208] INFO: 208000 events read in total (13222ms).
[15:54:58.214] INFO: Test took 14361ms.
[15:54:58.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:58.826] INFO: number of dead pixels (per ROC): 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:54:58.826] INFO: number of red-efficiency pixels: 193 132 239 553 532 640 445 260 275 399 265 291 327 202 71 59
[15:54:58.826] INFO: number of X-ray hits detected: 147893 97099 145214 233696 232225 253273 250083 173187 159205 204799 194833 185705 191255 115572 53498 53781
[15:54:58.826] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:54:58.826] INFO: number of Vcal hits detected: 207795 207718 207736 207392 207409 207282 207518 207723 207709 207579 207723 207686 207659 207790 207928 207940
[15:54:58.826] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[15:54:58.826] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.8 99.8 99.9 100.0 100.0
[15:54:58.826] INFO: X-ray hit rate [MHz/cm2]: 43.3 28.5 42.6 68.5 68.1 74.2 73.3 50.8 46.7 60.0 57.1 54.4 56.1 33.9 15.7 15.8
[15:54:58.826] INFO: PixTestHighRate::doXPixelAlive() done
[15:54:58.873] INFO: PixTest:: pg_setup set to default.
[15:54:58.884] INFO: enter test to run
[15:55:22.970] INFO: test: HighRate no parameter change
[15:55:22.970] INFO: running: highrate
[15:55:22.971] INFO: ----------------------------------------------------------------------
[15:55:22.971] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:55:22.971] INFO: ----------------------------------------------------------------------
[15:55:23.583] INFO: Expecting 208000 events.
[15:55:39.189] INFO: 208000 events read in total (15079ms).
[15:55:39.196] INFO: Test took 16217ms.
[15:55:39.655] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:40.007] INFO: number of dead pixels (per ROC): 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:55:40.007] INFO: number of red-efficiency pixels: 450 314 527 1256 1209 1403 1095 553 525 907 567 633 736 364 125 86
[15:55:40.007] INFO: number of X-ray hits detected: 219318 144943 216273 348280 342987 375431 368704 256319 236605 304102 289236 275691 284122 172170 79482 80299
[15:55:40.007] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:55:40.007] INFO: number of Vcal hits detected: 207470 207507 207367 206389 206473 206057 206645 207355 207422 206907 207380 207284 207145 207594 207870 207913
[15:55:40.007] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.3 99.3 99.1 99.4 99.7 99.7 99.5 99.7 99.7 99.6 99.8 99.9 100.0
[15:55:40.007] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.7 99.2 99.3 99.1 99.3 99.7 99.7 99.5 99.7 99.7 99.6 99.8 99.9 100.0
[15:55:40.007] INFO: X-ray hit rate [MHz/cm2]: 64.3 42.5 63.4 102.1 100.5 110.0 108.1 75.1 69.4 89.1 84.8 80.8 83.3 50.5 23.3 23.5
[15:55:40.007] INFO: PixTestHighRate::doXPixelAlive() done
[15:55:40.052] INFO: PixTest:: pg_setup set to default.
[15:55:40.067] INFO: enter test to run
[15:55:46.577] INFO: test: exit no parameter change
[15:55:46.893] QUIET: Connection to board 33 closed.
[15:55:46.903] INFO: pXar: this is the end, my friend