[18:06:13.680] INFO: *** Welcome to pxar ***
[18:06:13.680] INFO: *** Today: 2016/06/22
[18:06:13.718] INFO: *** Version: v1.9.0-814-g7497
[18:06:13.718] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//dacParameters35_C15.dat
[18:06:13.748] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:06:13.748] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//defaultMaskFile.dat
[18:06:13.748] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C15.dat
[18:06:13.836] INFO: clk: 4
[18:06:13.837] INFO: ctr: 4
[18:06:13.837] INFO: sda: 19
[18:06:13.837] INFO: tin: 9
[18:06:13.837] INFO: level: 15
[18:06:13.837] INFO: triggerdelay: 0
[18:06:13.837] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:06:13.837] INFO: Log level: INFO
[18:06:13.852] QUIET: Connection to board DTB_WREK4U opened.
[18:06:13.856] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[18:06:13.858] INFO: RPC call hashes of host and DTB match: 398089610
[18:06:15.392] INFO: DUT info:
[18:06:15.392] INFO: The DUT currently contains the following objects:
[18:06:15.393] INFO: 2 TBM Cores tbm08c (2 ON)
[18:06:15.393] INFO: TBM Core alpha (0): 7 registers set
[18:06:15.393] INFO: TBM Core beta (1): 7 registers set
[18:06:15.393] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:06:15.393] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.393] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.394] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.394] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.394] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.394] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.394] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:06:15.797] INFO: enter 'restricted' command line mode
[18:06:15.797] INFO: enter test to run
[18:06:17.118] INFO: test: PixelAlive no parameter change
[18:06:17.118] INFO: running: pixelalive
[18:06:17.128] INFO: ----------------------------------------------------------------------
[18:06:17.128] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:06:17.128] INFO: ----------------------------------------------------------------------
[18:06:17.450] INFO: Expecting 41600 events.
[18:06:21.747] INFO: 41600 events read in total (3578ms).
[18:06:21.918] INFO: Test took 4788ms.
[18:06:21.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:06:22.198] INFO: PixTestAlive::aliveTest() done
[18:06:22.198] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 1 0 0
[18:06:22.243] INFO: enter test to run
[18:06:38.438] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:06:38.438] INFO: running: highrate
[18:06:38.438] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:06:38.990] INFO: ----------------------------------------------------------------------
[18:06:38.990] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:06:38.990] INFO: ----------------------------------------------------------------------
[18:06:38.990] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:06:38.990] INFO: edge/corner pixel THR is adjusted
[18:06:38.990] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:06:39.948] INFO: Collecting data for 5 seconds...
[18:06:44.968] INFO: Done with hot pixel readout
[18:06:56.378] INFO: PixTest:: pg_setup set to default.
[18:06:56.379] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:06:56.379] INFO: 24 hot pixels found in step 0
[18:06:57.368] INFO: Collecting data for 5 seconds...
[18:07:02.387] INFO: Done with hot pixel readout
[18:07:13.673] INFO: PixTest:: pg_setup set to default.
[18:07:13.674] INFO: 22 hot pixels found in step 1
[18:07:14.669] INFO: Collecting data for 5 seconds...
[18:07:19.688] INFO: Done with hot pixel readout
[18:07:31.699] INFO: PixTest:: pg_setup set to default.
[18:07:31.700] INFO: 21 hot pixels found in step 2
[18:07:32.693] INFO: Collecting data for 5 seconds...
[18:07:37.712] INFO: Done with hot pixel readout
[18:07:49.942] INFO: PixTest:: pg_setup set to default.
[18:07:49.943] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:07:49.943] INFO: 20 hot pixels found in step 3
[18:07:50.936] INFO: Collecting data for 5 seconds...
[18:07:55.955] INFO: Done with hot pixel readout
[18:08:07.818] INFO: PixTest:: pg_setup set to default.
[18:08:07.819] INFO: 21 hot pixels found in step 4
[18:08:08.812] INFO: Collecting data for 5 seconds...
[18:08:13.832] INFO: Done with hot pixel readout
[18:08:25.825] INFO: PixTest:: pg_setup set to default.
[18:08:25.826] INFO: 19 hot pixels found in step 5
[18:08:26.821] INFO: Collecting data for 5 seconds...
[18:08:31.838] INFO: Done with hot pixel readout
[18:08:43.709] INFO: PixTest:: pg_setup set to default.
[18:08:43.709] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:08:43.709] INFO: 13 hot pixels found in step 6
[18:08:44.703] INFO: Collecting data for 5 seconds...
[18:08:49.720] INFO: Done with hot pixel readout
[18:09:01.512] INFO: PixTest:: pg_setup set to default.
[18:09:01.512] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:09:01.513] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:09:01.513] INFO: 21 hot pixels found in step 7
[18:09:02.506] INFO: Collecting data for 5 seconds...
[18:09:07.523] INFO: Done with hot pixel readout
[18:09:19.428] INFO: PixTest:: pg_setup set to default.
[18:09:19.429] INFO: 12 hot pixels found in step 8
[18:09:20.423] INFO: Collecting data for 5 seconds...
[18:09:25.440] INFO: Done with hot pixel readout
[18:09:37.336] INFO: PixTest:: pg_setup set to default.
[18:09:37.336] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:09:37.336] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:09:37.337] INFO: 17 hot pixels found in step 9
[18:09:38.330] INFO: Collecting data for 5 seconds...
[18:09:43.347] INFO: Done with hot pixel readout
[18:09:55.236] INFO: PixTest:: pg_setup set to default.
[18:09:55.236] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:09:55.237] INFO: 8 hot pixels found in step 10
[18:09:56.231] INFO: Collecting data for 5 seconds...
[18:10:01.248] INFO: Done with hot pixel readout
[18:10:13.131] INFO: PixTest:: pg_setup set to default.
[18:10:13.131] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:10:13.131] INFO: 10 hot pixels found in step 11
[18:10:14.124] INFO: Collecting data for 5 seconds...
[18:10:19.141] INFO: Done with hot pixel readout
[18:10:31.019] INFO: PixTest:: pg_setup set to default.
[18:10:31.019] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:10:31.020] INFO: 10 hot pixels found in step 12
[18:10:32.014] INFO: Collecting data for 5 seconds...
[18:10:37.031] INFO: Done with hot pixel readout
[18:10:48.878] INFO: PixTest:: pg_setup set to default.
[18:10:48.878] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:10:48.879] INFO: 3 hot pixels found in step 13
[18:10:49.872] INFO: Collecting data for 5 seconds...
[18:10:54.888] INFO: Done with hot pixel readout
[18:11:06.782] INFO: PixTest:: pg_setup set to default.
[18:11:06.782] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:11:06.782] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:11:06.783] INFO: 5 hot pixels found in step 14
[18:11:06.820] INFO: 5 hot pixels could not be trimmed and have been masked.
[18:11:06.823] INFO: PixTest::trimHotPixels() done
[18:11:06.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C0.dat
[18:11:06.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C1.dat
[18:11:06.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C2.dat
[18:11:06.841] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C3.dat
[18:11:06.846] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C4.dat
[18:11:06.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C5.dat
[18:11:06.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C6.dat
[18:11:06.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C7.dat
[18:11:06.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C8.dat
[18:11:06.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C9.dat
[18:11:06.877] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C10.dat
[18:11:06.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C11.dat
[18:11:06.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C12.dat
[18:11:06.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C13.dat
[18:11:06.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C14.dat
[18:11:06.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C15.dat
[18:11:06.909] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//defaultMaskFile.dat
[18:11:06.919] INFO: enter test to run
[18:13:42.915] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:13:42.915] INFO: running: highrate
[18:13:42.920] INFO: ----------------------------------------------------------------------
[18:13:42.920] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:13:42.920] INFO: ----------------------------------------------------------------------
[18:13:42.920] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:13:42.920] INFO: edge/corner pixel THR is adjusted
[18:13:42.920] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:13:43.878] INFO: Collecting data for 1 seconds...
[18:13:44.882] INFO: Done with hot pixel readout
[18:13:48.952] INFO: PixTest:: pg_setup set to default.
[18:13:48.953] INFO: 0 hot pixels found in step 0
[18:13:48.958] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:13:49.047] INFO: PixTest::trimHotPixels() done
[18:13:49.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C0.dat
[18:13:49.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C1.dat
[18:13:49.064] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C2.dat
[18:13:49.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C3.dat
[18:13:49.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C4.dat
[18:13:49.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C5.dat
[18:13:49.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C6.dat
[18:13:49.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C7.dat
[18:13:49.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C8.dat
[18:13:49.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C9.dat
[18:13:49.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C10.dat
[18:13:49.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C11.dat
[18:13:49.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C12.dat
[18:13:49.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C13.dat
[18:13:49.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C14.dat
[18:13:49.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//trimParameters35_C15.dat
[18:13:49.136] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-33_FPIXTest-17C-Nebraska-160520-1426_2016-05-20_14h27m_1463772474/000_FPIXTest_p17//defaultMaskFile.dat
[18:13:49.148] INFO: enter test to run
[18:14:16.818] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:14:16.818] INFO: running: xray
[18:14:16.820] INFO: ----------------------------------------------------------------------
[18:14:16.820] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:14:16.820] INFO: ----------------------------------------------------------------------
[18:14:17.783] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:14:29.059] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[18:14:58.481] INFO: Resuming triggers.
[18:15:09.761] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[18:15:39.302] INFO: Resuming triggers.
[18:15:50.583] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[18:16:19.966] INFO: Resuming triggers.
[18:16:31.241] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[18:17:00.884] INFO: Resuming triggers.
[18:17:12.163] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[18:17:41.440] INFO: Resuming triggers.
[18:17:52.715] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[18:18:22.207] INFO: Resuming triggers.
[18:18:33.485] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[18:19:03.596] INFO: Resuming triggers.
[18:19:14.874] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[18:19:44.531] INFO: Resuming triggers.
[18:19:54.672] INFO: data taking finished, elapsed time: 100 seconds.
[18:20:21.280] INFO: PixTest:: pg_setup set to default.
[18:20:21.283] INFO: PixTestXray::doPhRun() done
[18:20:21.419] INFO: enter test to run
[18:20:47.832] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:20:47.832] INFO: running: xray
[18:20:47.833] INFO: ----------------------------------------------------------------------
[18:20:47.833] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:20:47.833] INFO: ----------------------------------------------------------------------
[18:20:48.798] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:20:55.365] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[18:21:25.441] INFO: Resuming triggers.
[18:21:32.009] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[18:22:02.048] INFO: Resuming triggers.
[18:22:08.611] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[18:22:38.669] INFO: Resuming triggers.
[18:22:45.236] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[18:23:15.328] INFO: Resuming triggers.
[18:23:21.897] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[18:23:51.932] INFO: Resuming triggers.
[18:23:58.496] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[18:24:28.526] INFO: Resuming triggers.
[18:24:35.091] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[18:25:05.199] INFO: Resuming triggers.
[18:25:11.765] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[18:25:41.964] INFO: Resuming triggers.
[18:25:48.531] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[18:26:18.639] INFO: Resuming triggers.
[18:26:25.206] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[18:26:55.273] INFO: Resuming triggers.
[18:27:01.842] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[18:27:31.896] INFO: Resuming triggers.
[18:27:38.462] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[18:28:08.581] INFO: Resuming triggers.
[18:28:15.149] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[18:28:46.602] INFO: Resuming triggers.
[18:28:53.168] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[18:29:23.726] INFO: Resuming triggers.
[18:29:30.294] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[18:30:01.335] INFO: Resuming triggers.
[18:30:03.171] INFO: data taking finished, elapsed time: 100 seconds.
[18:30:12.370] INFO: PixTest:: pg_setup set to default.
[18:30:12.373] INFO: PixTestXray::doPhRun() done
[18:30:12.546] INFO: enter test to run
[18:31:28.964] INFO: test: HighRate no parameter change
[18:31:28.964] INFO: running: highrate
[18:31:28.965] INFO: ----------------------------------------------------------------------
[18:31:28.965] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:31:28.965] INFO: ----------------------------------------------------------------------
[18:31:29.107] INFO: Expecting 768 events.
[18:31:30.241] INFO: 768 events read in total (419ms).
[18:31:30.241] INFO: Test took 1268ms.
[18:31:31.044] INFO: Expecting 41600 events.
[18:31:34.244] INFO: 41600 events read in total (2674ms).
[18:31:34.245] INFO: Test took 3998ms.
[18:31:34.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:35.002] INFO: Expecting 41600 events.
[18:31:38.243] INFO: 41600 events read in total (2714ms).
[18:31:38.244] INFO: Test took 3946ms.
[18:31:38.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:38.000] INFO: Expecting 41600 events.
[18:31:42.241] INFO: 41600 events read in total (2714ms).
[18:31:42.242] INFO: Test took 3944ms.
[18:31:42.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:42.999] INFO: Expecting 41600 events.
[18:31:46.236] INFO: 41600 events read in total (2710ms).
[18:31:46.237] INFO: Test took 3940ms.
[18:31:46.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:46.993] INFO: Expecting 41600 events.
[18:31:50.233] INFO: 41600 events read in total (2713ms).
[18:31:50.234] INFO: Test took 3943ms.
[18:31:50.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:50.990] INFO: Expecting 41600 events.
[18:31:54.240] INFO: 41600 events read in total (2723ms).
[18:31:54.241] INFO: Test took 3953ms.
[18:31:54.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:54.999] INFO: Expecting 41600 events.
[18:31:58.238] INFO: 41600 events read in total (2712ms).
[18:31:58.239] INFO: Test took 3944ms.
[18:31:58.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:58.996] INFO: Expecting 41600 events.
[18:32:02.248] INFO: 41600 events read in total (2726ms).
[18:32:02.249] INFO: Test took 3957ms.
[18:32:02.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:03.009] INFO: Expecting 41600 events.
[18:32:06.251] INFO: 41600 events read in total (2715ms).
[18:32:06.252] INFO: Test took 3947ms.
[18:32:06.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:07.006] INFO: Expecting 41600 events.
[18:32:10.264] INFO: 41600 events read in total (2731ms).
[18:32:10.265] INFO: Test took 3959ms.
[18:32:10.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:11.023] INFO: Expecting 41600 events.
[18:32:14.258] INFO: 41600 events read in total (2708ms).
[18:32:14.259] INFO: Test took 3940ms.
[18:32:14.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:15.018] INFO: Expecting 41600 events.
[18:32:18.241] INFO: 41600 events read in total (2696ms).
[18:32:18.242] INFO: Test took 3928ms.
[18:32:18.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:18.999] INFO: Expecting 41600 events.
[18:32:22.250] INFO: 41600 events read in total (2724ms).
[18:32:22.251] INFO: Test took 3954ms.
[18:32:22.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:23.008] INFO: Expecting 41600 events.
[18:32:26.268] INFO: 41600 events read in total (2733ms).
[18:32:26.269] INFO: Test took 3963ms.
[18:32:26.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:27.025] INFO: Expecting 41600 events.
[18:32:30.267] INFO: 41600 events read in total (2715ms).
[18:32:30.268] INFO: Test took 3945ms.
[18:32:30.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:31.026] INFO: Expecting 41600 events.
[18:32:34.286] INFO: 41600 events read in total (2733ms).
[18:32:34.288] INFO: Test took 3966ms.
[18:32:34.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:35.046] INFO: Expecting 41600 events.
[18:32:38.294] INFO: 41600 events read in total (2722ms).
[18:32:38.295] INFO: Test took 3947ms.
[18:32:38.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:39.053] INFO: Expecting 41600 events.
[18:32:42.313] INFO: 41600 events read in total (2733ms).
[18:32:42.314] INFO: Test took 3965ms.
[18:32:42.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:43.072] INFO: Expecting 41600 events.
[18:32:46.300] INFO: 41600 events read in total (2701ms).
[18:32:46.301] INFO: Test took 3932ms.
[18:32:46.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:47.060] INFO: Expecting 41600 events.
[18:32:50.197] INFO: 41600 events read in total (2611ms).
[18:32:50.198] INFO: Test took 3843ms.
[18:32:50.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:50.593] INFO: enter test to run
[18:33:51.323] INFO: test: HighRate no parameter change
[18:33:51.323] INFO: running: highrate
[18:33:51.324] INFO: ----------------------------------------------------------------------
[18:33:51.324] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:33:51.324] INFO: ----------------------------------------------------------------------
[18:33:51.941] INFO: Expecting 208000 events.
[18:34:03.812] INFO: 208000 events read in total (11344ms).
[18:34:03.815] INFO: Test took 12482ms.
[18:34:03.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:04.225] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 1 0 0
[18:34:04.225] INFO: number of red-efficiency pixels: 88 59 88 143 135 171 182 108 90 144 140 104 119 87 33 34
[18:34:04.225] INFO: number of X-ray hits detected: 65002 47301 72307 117800 118370 123479 122828 84279 78773 102439 101038 88858 92148 56526 24108 28023
[18:34:04.225] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:34:04.225] INFO: number of Vcal hits detected: 207910 207937 207853 207806 207864 207824 207810 207890 207910 207845 207855 207894 207878 207857 207967 207965
[18:34:04.225] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[18:34:04.225] 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 99.9 99.9 100.0 100.0
[18:34:04.225] INFO: X-ray hit rate [MHz/cm2]: 19.1 13.9 21.2 34.5 34.7 36.2 36.0 24.7 23.1 30.0 29.6 26.0 27.0 16.6 7.1 8.2
[18:34:04.225] INFO: PixTestHighRate::doXPixelAlive() done
[18:34:04.278] INFO: PixTest:: pg_setup set to default.
[18:34:04.295] INFO: enter test to run
[18:34:25.530] INFO: test: HighRate no parameter change
[18:34:25.530] INFO: running: highrate
[18:34:25.531] INFO: ----------------------------------------------------------------------
[18:34:25.531] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:34:25.531] INFO: ----------------------------------------------------------------------
[18:34:26.146] INFO: Expecting 208000 events.
[18:34:39.877] INFO: 208000 events read in total (13204ms).
[18:34:39.883] INFO: Test took 14342ms.
[18:34:40.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:40.487] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 1 0 0
[18:34:40.487] INFO: number of red-efficiency pixels: 197 135 269 553 426 564 627 345 197 416 439 257 341 198 49 55
[18:34:40.487] INFO: number of X-ray hits detected: 132614 96958 147216 240406 240081 251828 250676 173579 160207 209438 204407 180526 188284 114428 49620 57644
[18:34:40.487] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:34:40.487] INFO: number of Vcal hits detected: 207784 207859 207641 207348 207553 207381 207303 207625 207798 207554 207529 207730 207633 207733 207951 207944
[18:34:40.487] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[18:34:40.487] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[18:34:40.487] INFO: X-ray hit rate [MHz/cm2]: 38.9 28.4 43.2 70.5 70.4 73.8 73.5 50.9 47.0 61.4 59.9 52.9 55.2 33.5 14.5 16.9
[18:34:40.487] INFO: PixTestHighRate::doXPixelAlive() done
[18:34:40.538] INFO: PixTest:: pg_setup set to default.
[18:34:40.559] INFO: enter test to run
[18:35:01.018] INFO: test: HighRate no parameter change
[18:35:01.018] INFO: running: highrate
[18:35:01.019] INFO: ----------------------------------------------------------------------
[18:35:01.019] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:35:01.019] INFO: ----------------------------------------------------------------------
[18:35:01.643] INFO: Expecting 208000 events.
[18:35:17.350] INFO: 208000 events read in total (15180ms).
[18:35:17.357] INFO: Test took 16327ms.
[18:35:17.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:18.152] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 1 0 0
[18:35:18.152] INFO: number of red-efficiency pixels: 476 287 511 1333 940 1369 1439 830 398 1003 923 563 763 358 83 93
[18:35:18.152] INFO: number of X-ray hits detected: 198951 146222 221672 361291 360544 379175 377080 258951 242261 315704 307866 272277 283013 172840 75768 86684
[18:35:18.152] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:35:18.152] INFO: number of Vcal hits detected: 207417 207686 207294 206212 206844 206194 206100 206948 207569 206773 206876 207364 207099 207525 207915 207906
[18:35:18.152] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.2 99.5 99.2 99.2 99.5 99.8 99.5 99.5 99.7 99.6 99.8 100.0 100.0
[18:35:18.152] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.7 99.1 99.4 99.1 99.1 99.5 99.8 99.4 99.5 99.7 99.6 99.8 100.0 100.0
[18:35:18.152] INFO: X-ray hit rate [MHz/cm2]: 58.3 42.9 65.0 105.9 105.7 111.1 110.5 75.9 71.0 92.5 90.2 79.8 83.0 50.7 22.2 25.4
[18:35:18.152] INFO: PixTestHighRate::doXPixelAlive() done
[18:35:18.201] INFO: PixTest:: pg_setup set to default.
[18:35:18.213] INFO: enter test to run
[18:35:26.018] INFO: test: exit no parameter change
[18:35:26.306] QUIET: Connection to board 32 closed.
[18:35:26.307] INFO: pXar: this is the end, my friend