[13:21:45.226] INFO: *** Welcome to pxar ***
[13:21:45.226] INFO: *** Today: 2016/05/16
[13:21:45.247] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:21:45.247] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//dacParameters35_C15.dat
[13:21:45.310] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:21:45.310] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:45.318] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:45.403] INFO: clk: 4
[13:21:45.403] INFO: ctr: 4
[13:21:45.403] INFO: sda: 19
[13:21:45.403] INFO: tin: 9
[13:21:45.403] INFO: level: 15
[13:21:45.403] INFO: triggerdelay: 0
[13:21:45.403] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:21:45.403] INFO: Log level: INFO
[13:21:45.421] QUIET: Connection to board DTB_WREKRL opened.
[13:21:45.425] 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:
------------------------------------------------------
[13:21:45.428] INFO: RPC call hashes of host and DTB match: 398089610
[13:21:46.957] INFO: DUT info:
[13:21:46.957] INFO: The DUT currently contains the following objects:
[13:21:46.957] INFO: 2 TBM Cores tbm08c (2 ON)
[13:21:46.957] INFO: TBM Core alpha (0): 7 registers set
[13:21:46.957] INFO: TBM Core beta (1): 7 registers set
[13:21:46.958] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:21:46.958] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.958] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.959] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.959] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:46.959] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:21:47.362] INFO: enter 'restricted' command line mode
[13:21:47.362] INFO: enter test to run
[13:21:51.744] INFO: test: PixelAlive no parameter change
[13:21:51.744] INFO: running: pixelalive
[13:21:51.754] INFO: ----------------------------------------------------------------------
[13:21:51.754] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:21:51.754] INFO: ----------------------------------------------------------------------
[13:21:52.075] INFO: Expecting 41600 events.
[13:21:56.405] INFO: 41600 events read in total (3611ms).
[13:21:56.574] INFO: Test took 4818ms.
[13:21:56.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:56.865] INFO: PixTestAlive::aliveTest() done
[13:21:56.865] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[13:21:56.896] INFO: enter test to run
[13:22:58.088] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:22:58.088] INFO: running: highrate
[13:22:58.088] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:22:58.299] INFO: ----------------------------------------------------------------------
[13:22:58.299] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:22:58.299] INFO: ----------------------------------------------------------------------
[13:22:58.299] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:22:58.299] INFO: edge/corner pixel THR is adjusted
[13:22:58.299] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:22:59.258] INFO: Collecting data for 5 seconds...
[13:23:04.276] INFO: Done with hot pixel readout
[13:23:16.069] INFO: PixTest:: pg_setup set to default.
[13:23:16.070] INFO: 8 hot pixels found in step 0
[13:23:17.063] INFO: Collecting data for 5 seconds...
[13:23:22.085] INFO: Done with hot pixel readout
[13:23:34.624] INFO: PixTest:: pg_setup set to default.
[13:23:34.625] INFO: 10 hot pixels found in step 1
[13:23:35.624] INFO: Collecting data for 5 seconds...
[13:23:40.645] INFO: Done with hot pixel readout
[13:23:53.008] INFO: PixTest:: pg_setup set to default.
[13:23:53.009] INFO: 9 hot pixels found in step 2
[13:23:54.003] INFO: Collecting data for 5 seconds...
[13:23:59.026] INFO: Done with hot pixel readout
[13:24:11.259] INFO: PixTest:: pg_setup set to default.
[13:24:11.259] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:24:11.259] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:24:11.260] INFO: 11 hot pixels found in step 3
[13:24:12.255] INFO: Collecting data for 5 seconds...
[13:24:17.275] INFO: Done with hot pixel readout
[13:24:29.651] INFO: PixTest:: pg_setup set to default.
[13:24:29.651] INFO: 11 hot pixels found in step 4
[13:24:30.648] INFO: Collecting data for 5 seconds...
[13:24:35.668] INFO: Done with hot pixel readout
[13:24:48.104] INFO: PixTest:: pg_setup set to default.
[13:24:48.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:24:48.105] INFO: 13 hot pixels found in step 5
[13:24:49.100] INFO: Collecting data for 5 seconds...
[13:24:54.119] INFO: Done with hot pixel readout
[13:25:06.507] INFO: PixTest:: pg_setup set to default.
[13:25:06.508] INFO: 9 hot pixels found in step 6
[13:25:07.503] INFO: Collecting data for 5 seconds...
[13:25:12.523] INFO: Done with hot pixel readout
[13:25:24.779] INFO: PixTest:: pg_setup set to default.
[13:25:24.779] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:25:24.780] INFO: 6 hot pixels found in step 7
[13:25:25.774] INFO: Collecting data for 5 seconds...
[13:25:30.790] INFO: Done with hot pixel readout
[13:25:42.949] INFO: PixTest:: pg_setup set to default.
[13:25:42.949] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:25:42.950] INFO: 7 hot pixels found in step 8
[13:25:43.945] INFO: Collecting data for 5 seconds...
[13:25:48.961] INFO: Done with hot pixel readout
[13:26:01.160] INFO: PixTest:: pg_setup set to default.
[13:26:01.160] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:26:01.161] INFO: 3 hot pixels found in step 9
[13:26:02.156] INFO: Collecting data for 5 seconds...
[13:26:07.173] INFO: Done with hot pixel readout
[13:26:19.381] INFO: PixTest:: pg_setup set to default.
[13:26:19.382] INFO: 3 hot pixels found in step 10
[13:26:20.376] INFO: Collecting data for 5 seconds...
[13:26:25.392] INFO: Done with hot pixel readout
[13:26:37.601] INFO: PixTest:: pg_setup set to default.
[13:26:37.602] INFO: 3 hot pixels found in step 11
[13:26:38.596] INFO: Collecting data for 5 seconds...
[13:26:43.612] INFO: Done with hot pixel readout
[13:26:55.796] INFO: PixTest:: pg_setup set to default.
[13:26:55.796] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:26:55.797] INFO: 4 hot pixels found in step 12
[13:26:56.793] INFO: Collecting data for 5 seconds...
[13:27:01.810] INFO: Done with hot pixel readout
[13:27:14.014] INFO: PixTest:: pg_setup set to default.
[13:27:14.015] INFO: 4 hot pixels found in step 13
[13:27:15.010] INFO: Collecting data for 5 seconds...
[13:27:20.026] INFO: Done with hot pixel readout
[13:27:32.223] INFO: PixTest:: pg_setup set to default.
[13:27:32.223] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:27:32.223] INFO: 4 hot pixels found in step 14
[13:27:32.262] INFO: 4 hot pixels could not be trimmed and have been masked.
[13:27:32.266] INFO: PixTest::trimHotPixels() done
[13:27:32.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat
[13:27:32.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C1.dat
[13:27:32.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C2.dat
[13:27:32.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C3.dat
[13:27:32.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C4.dat
[13:27:32.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C5.dat
[13:27:32.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C6.dat
[13:27:32.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C7.dat
[13:27:32.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C8.dat
[13:27:32.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C9.dat
[13:27:32.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C10.dat
[13:27:32.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C11.dat
[13:27:32.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C12.dat
[13:27:32.335] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C13.dat
[13:27:32.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C14.dat
[13:27:32.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[13:27:32.351] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[13:27:32.361] INFO: enter test to run
[13:28:45.413] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:28:45.413] INFO: running: highrate
[13:28:45.418] INFO: ----------------------------------------------------------------------
[13:28:45.418] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:28:45.418] INFO: ----------------------------------------------------------------------
[13:28:45.418] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:28:45.418] INFO: edge/corner pixel THR is adjusted
[13:28:45.418] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:28:46.375] INFO: Collecting data for 1 seconds...
[13:28:47.379] INFO: Done with hot pixel readout
[13:28:51.559] INFO: PixTest:: pg_setup set to default.
[13:28:51.560] INFO: 0 hot pixels found in step 0
[13:28:51.565] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:28:51.646] INFO: PixTest::trimHotPixels() done
[13:28:51.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat
[13:28:51.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C1.dat
[13:28:51.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C2.dat
[13:28:51.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C3.dat
[13:28:51.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C4.dat
[13:28:51.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C5.dat
[13:28:51.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C6.dat
[13:28:51.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C7.dat
[13:28:51.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C8.dat
[13:28:51.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C9.dat
[13:28:51.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C10.dat
[13:28:51.710] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C11.dat
[13:28:51.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C12.dat
[13:28:51.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C13.dat
[13:28:51.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C14.dat
[13:28:51.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[13:28:51.736] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-D-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[13:28:51.753] INFO: enter test to run
[13:29:12.701] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:29:12.701] INFO: running: xray
[13:29:12.703] INFO: ----------------------------------------------------------------------
[13:29:12.703] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:29:12.703] INFO: ----------------------------------------------------------------------
[13:29:13.674] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:29:24.559] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:29:54.257] INFO: Resuming triggers.
[13:30:05.143] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:30:34.865] INFO: Resuming triggers.
[13:30:45.750] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:31:15.447] INFO: Resuming triggers.
[13:31:26.333] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:31:56.032] INFO: Resuming triggers.
[13:32:06.916] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:32:36.575] INFO: Resuming triggers.
[13:32:47.461] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:33:17.177] INFO: Resuming triggers.
[13:33:28.060] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:33:57.479] INFO: Resuming triggers.
[13:34:08.362] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:34:37.889] INFO: Resuming triggers.
[13:34:48.771] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:35:18.992] INFO: Resuming triggers.
[13:35:21.386] INFO: data taking finished, elapsed time: 100 seconds.
[13:35:28.350] INFO: PixTest:: pg_setup set to default.
[13:35:28.353] INFO: PixTestXray::doPhRun() done
[13:35:28.495] INFO: enter test to run
[13:36:56.322] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:36:56.322] INFO: running: xray
[13:36:56.323] INFO: ----------------------------------------------------------------------
[13:36:56.323] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:36:56.323] INFO: ----------------------------------------------------------------------
[13:36:57.291] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:37:03.530] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:37:33.607] INFO: Resuming triggers.
[13:37:39.847] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:38:09.865] INFO: Resuming triggers.
[13:38:16.107] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:38:46.112] INFO: Resuming triggers.
[13:38:52.354] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:39:22.397] INFO: Resuming triggers.
[13:39:28.638] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:39:58.735] INFO: Resuming triggers.
[13:40:04.976] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:40:35.007] INFO: Resuming triggers.
[13:40:41.245] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:41:11.299] INFO: Resuming triggers.
[13:41:17.537] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:41:47.411] INFO: Resuming triggers.
[13:41:53.649] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:42:23.740] INFO: Resuming triggers.
[13:42:29.975] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[13:43:00.042] INFO: Resuming triggers.
[13:43:06.277] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:43:36.324] INFO: Resuming triggers.
[13:43:42.559] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:44:12.546] INFO: Resuming triggers.
[13:44:18.779] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:44:49.499] INFO: Resuming triggers.
[13:44:55.735] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:45:26.264] INFO: Resuming triggers.
[13:45:32.502] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:46:03.631] INFO: Resuming triggers.
[13:46:09.870] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:46:41.131] INFO: Resuming triggers.
[13:46:41.672] INFO: data taking finished, elapsed time: 100 seconds.
[13:46:44.777] INFO: PixTest:: pg_setup set to default.
[13:46:44.780] INFO: PixTestXray::doPhRun() done
[13:46:44.931] INFO: enter test to run
[13:47:31.493] INFO: test: HighRate no parameter change
[13:47:31.493] INFO: running: highrate
[13:47:31.510] INFO: ----------------------------------------------------------------------
[13:47:31.510] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:47:31.510] INFO: ----------------------------------------------------------------------
[13:47:31.665] INFO: Expecting 768 events.
[13:47:32.799] INFO: 768 events read in total (419ms).
[13:47:32.799] INFO: Test took 1268ms.
[13:47:33.602] INFO: Expecting 41600 events.
[13:47:36.717] INFO: 41600 events read in total (2588ms).
[13:47:36.719] INFO: Test took 3892ms.
[13:47:36.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:37.475] INFO: Expecting 41600 events.
[13:47:40.719] INFO: 41600 events read in total (2717ms).
[13:47:40.720] INFO: Test took 3944ms.
[13:47:40.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:41.474] INFO: Expecting 41600 events.
[13:47:44.749] INFO: 41600 events read in total (2748ms).
[13:47:44.750] INFO: Test took 3971ms.
[13:47:44.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:45.502] INFO: Expecting 41600 events.
[13:47:48.784] INFO: 41600 events read in total (2756ms).
[13:47:48.785] INFO: Test took 3977ms.
[13:47:48.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:49.539] INFO: Expecting 41600 events.
[13:47:52.823] INFO: 41600 events read in total (2757ms).
[13:47:52.824] INFO: Test took 3979ms.
[13:47:52.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:53.573] INFO: Expecting 41600 events.
[13:47:56.870] INFO: 41600 events read in total (2771ms).
[13:47:56.871] INFO: Test took 3990ms.
[13:47:56.910] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:57.622] INFO: Expecting 41600 events.
[13:48:00.915] INFO: 41600 events read in total (2766ms).
[13:48:00.916] INFO: Test took 3986ms.
[13:48:00.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:01.670] INFO: Expecting 41600 events.
[13:48:04.962] INFO: 41600 events read in total (2765ms).
[13:48:04.963] INFO: Test took 3989ms.
[13:48:05.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:05.720] INFO: Expecting 41600 events.
[13:48:09.027] INFO: 41600 events read in total (2780ms).
[13:48:09.028] INFO: Test took 4006ms.
[13:48:09.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:09.779] INFO: Expecting 41600 events.
[13:48:13.071] INFO: 41600 events read in total (2765ms).
[13:48:13.073] INFO: Test took 3988ms.
[13:48:13.111] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:13.827] INFO: Expecting 41600 events.
[13:48:17.102] INFO: 41600 events read in total (2749ms).
[13:48:17.103] INFO: Test took 3972ms.
[13:48:17.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:17.855] INFO: Expecting 41600 events.
[13:48:21.159] INFO: 41600 events read in total (2777ms).
[13:48:21.160] INFO: Test took 3998ms.
[13:48:21.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:21.912] INFO: Expecting 41600 events.
[13:48:25.205] INFO: 41600 events read in total (2766ms).
[13:48:25.206] INFO: Test took 3989ms.
[13:48:25.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:25.960] INFO: Expecting 41600 events.
[13:48:29.260] INFO: 41600 events read in total (2773ms).
[13:48:29.261] INFO: Test took 3996ms.
[13:48:29.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:30.013] INFO: Expecting 41600 events.
[13:48:33.326] INFO: 41600 events read in total (2786ms).
[13:48:33.327] INFO: Test took 4007ms.
[13:48:33.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:34.080] INFO: Expecting 41600 events.
[13:48:37.371] INFO: 41600 events read in total (2765ms).
[13:48:37.371] INFO: Test took 3985ms.
[13:48:37.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:38.126] INFO: Expecting 41600 events.
[13:48:41.428] INFO: 41600 events read in total (2776ms).
[13:48:41.429] INFO: Test took 3999ms.
[13:48:41.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:42.185] INFO: Expecting 41600 events.
[13:48:45.485] INFO: 41600 events read in total (2773ms).
[13:48:45.486] INFO: Test took 3998ms.
[13:48:45.525] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:46.242] INFO: Expecting 41600 events.
[13:48:49.515] INFO: 41600 events read in total (2747ms).
[13:48:49.516] INFO: Test took 3972ms.
[13:48:49.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:50.270] INFO: Expecting 41600 events.
[13:48:53.423] INFO: 41600 events read in total (2626ms).
[13:48:53.424] INFO: Test took 3849ms.
[13:48:53.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:53.817] INFO: enter test to run
[13:49:56.220] INFO: test: HighRate no parameter change
[13:49:56.220] INFO: running: highrate
[13:49:56.221] INFO: ----------------------------------------------------------------------
[13:49:56.221] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:49:56.221] INFO: ----------------------------------------------------------------------
[13:49:56.845] INFO: Expecting 208000 events.
[13:50:08.965] INFO: 208000 events read in total (11593ms).
[13:50:08.969] INFO: Test took 12739ms.
[13:50:09.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:09.398] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:50:09.398] INFO: number of red-efficiency pixels: 84 67 102 145 176 229 161 109 97 153 146 133 126 86 27 40
[13:50:09.398] INFO: number of X-ray hits detected: 71241 52550 83201 127078 136914 141005 141060 105096 96331 107300 109110 94800 98535 57013 24135 31942
[13:50:09.398] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:50:09.398] INFO: number of Vcal hits detected: 207912 207930 207896 207848 207818 207767 207836 207890 207898 207842 207851 207864 207873 207913 207973 207960
[13:50:09.398] 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
[13:50:09.398] INFO: Vcal hit overall 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
[13:50:09.398] INFO: X-ray hit rate [MHz/cm2]: 20.9 15.4 24.4 37.2 40.1 41.3 41.3 30.8 28.2 31.5 32.0 27.8 28.9 16.7 7.1 9.4
[13:50:09.398] INFO: PixTestHighRate::doXPixelAlive() done
[13:50:09.446] INFO: PixTest:: pg_setup set to default.
[13:50:09.460] INFO: enter test to run
[13:50:43.916] INFO: test: HighRate no parameter change
[13:50:43.916] INFO: running: highrate
[13:50:43.917] INFO: ----------------------------------------------------------------------
[13:50:43.917] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:50:43.917] INFO: ----------------------------------------------------------------------
[13:50:44.535] INFO: Expecting 208000 events.
[13:50:58.661] INFO: 208000 events read in total (13599ms).
[13:50:58.667] INFO: Test took 14742ms.
[13:50:58.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:59.298] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:50:59.298] INFO: number of red-efficiency pixels: 233 184 329 491 612 781 582 414 299 478 448 325 372 203 45 67
[13:50:59.298] INFO: number of X-ray hits detected: 140963 103848 164219 250200 270036 278789 276758 207855 190857 212304 216938 187369 195110 113176 48335 64115
[13:50:59.298] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:50:59.298] INFO: number of Vcal hits detected: 207752 207809 207642 207471 207335 207102 207347 207546 207693 207478 207514 207661 207597 207787 207951 207930
[13:50:59.298] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:50:59.298] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.7 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:50:59.298] INFO: X-ray hit rate [MHz/cm2]: 41.3 30.4 48.1 73.3 79.1 81.7 81.1 60.9 55.9 62.2 63.6 54.9 57.2 33.2 14.2 18.8
[13:50:59.298] INFO: PixTestHighRate::doXPixelAlive() done
[13:50:59.347] INFO: PixTest:: pg_setup set to default.
[13:50:59.360] INFO: enter test to run
[13:51:21.756] INFO: test: HighRate no parameter change
[13:51:21.756] INFO: running: highrate
[13:51:21.757] INFO: ----------------------------------------------------------------------
[13:51:21.757] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:51:21.757] INFO: ----------------------------------------------------------------------
[13:51:22.375] INFO: Expecting 208000 events.
[13:51:38.588] INFO: 208000 events read in total (15686ms).
[13:51:38.596] INFO: Test took 16831ms.
[13:51:39.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:39.448] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:51:39.448] INFO: number of red-efficiency pixels: 513 357 656 1005 1409 1749 1299 920 614 989 1097 617 805 492 93 118
[13:51:39.448] INFO: number of X-ray hits detected: 209719 154938 243866 373053 402135 414511 410087 308957 285411 314547 321506 277554 290515 167737 72252 95403
[13:51:39.448] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:51:39.448] INFO: number of Vcal hits detected: 207405 207600 207104 206742 206108 205409 206326 206738 207309 206802 206657 207290 207067 207405 207906 207881
[13:51:39.448] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.5 99.2 98.9 99.3 99.5 99.7 99.5 99.4 99.7 99.6 99.7 100.0 99.9
[13:51:39.448] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.4 99.1 98.8 99.2 99.4 99.7 99.4 99.4 99.7 99.6 99.7 100.0 99.9
[13:51:39.448] INFO: X-ray hit rate [MHz/cm2]: 61.5 45.4 71.5 109.3 117.9 121.5 120.2 90.6 83.7 92.2 94.2 81.4 85.2 49.2 21.2 28.0
[13:51:39.448] INFO: PixTestHighRate::doXPixelAlive() done
[13:51:39.494] INFO: PixTest:: pg_setup set to default.
[13:51:39.510] INFO: enter test to run
[13:51:44.611] INFO: test: exit no parameter change
[13:51:44.898] QUIET: Connection to board 33 closed.
[13:51:44.914] INFO: pXar: this is the end, my friend