[16:38:29.336] INFO: *** Welcome to pxar ***
[16:38:29.336] INFO: *** Today: 2016/08/24
[16:38:30.142] INFO: *** Version: v1.9.0-818-g96727
[16:38:30.142] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//dacParameters35_C15.dat
[16:38:30.176] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:38:30.176] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[16:38:30.185] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[16:38:30.298] INFO: clk: 4
[16:38:30.298] INFO: ctr: 4
[16:38:30.298] INFO: sda: 19
[16:38:30.298] INFO: tin: 9
[16:38:30.298] INFO: level: 15
[16:38:30.298] INFO: triggerdelay: 0
[16:38:30.298] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:38:30.298] INFO: Log level: INFO
[16:38:30.317] QUIET: Connection to board DTB_WREK4U opened.
[16:38:30.320] 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:
------------------------------------------------------
[16:38:30.323] INFO: RPC call hashes of host and DTB match: 398089610
[16:38:31.852] INFO: DUT info:
[16:38:31.852] INFO: The DUT currently contains the following objects:
[16:38:31.852] INFO: 2 TBM Cores tbm08c (2 ON)
[16:38:31.852] INFO: TBM Core alpha (0): 7 registers set
[16:38:31.852] INFO: TBM Core beta (1): 7 registers set
[16:38:31.852] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:38:31.852] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.852] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:31.853] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:38:32.304] INFO: enter 'restricted' command line mode
[16:38:32.305] INFO: enter test to run
[16:38:40.653] INFO: test: PixelAlive no parameter change
[16:38:40.653] INFO: running: pixelalive
[16:38:40.662] INFO: ----------------------------------------------------------------------
[16:38:40.662] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:38:40.662] INFO: ----------------------------------------------------------------------
[16:38:40.986] INFO: Expecting 41600 events.
[16:38:45.301] INFO: 41600 events read in total (3596ms).
[16:38:45.467] INFO: Test took 4800ms.
[16:38:45.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:45.739] INFO: PixTestAlive::aliveTest() done
[16:38:45.739] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[16:38:45.768] INFO: enter test to run
[16:39:12.781] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:39:12.781] INFO: running: highrate
[16:39:12.781] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:39:12.000] INFO: ----------------------------------------------------------------------
[16:39:12.000] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:39:12.000] INFO: ----------------------------------------------------------------------
[16:39:12.000] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:39:12.000] INFO: edge/corner pixel THR is adjusted
[16:39:12.000] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:39:13.959] INFO: Collecting data for 5 seconds...
[16:39:18.976] INFO: Done with hot pixel readout
[16:39:30.809] INFO: PixTest:: pg_setup set to default.
[16:39:30.810] INFO: 30 hot pixels found in step 0
[16:39:31.804] INFO: Collecting data for 5 seconds...
[16:39:36.821] INFO: Done with hot pixel readout
[16:39:48.323] INFO: PixTest:: pg_setup set to default.
[16:39:48.323] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:39:48.324] INFO: 33 hot pixels found in step 1
[16:39:49.320] INFO: Collecting data for 5 seconds...
[16:39:54.336] INFO: Done with hot pixel readout
[16:40:06.178] INFO: PixTest:: pg_setup set to default.
[16:40:06.178] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:40:06.179] INFO: 35 hot pixels found in step 2
[16:40:07.173] INFO: Collecting data for 5 seconds...
[16:40:12.190] INFO: Done with hot pixel readout
[16:40:24.199] INFO: PixTest:: pg_setup set to default.
[16:40:24.199] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:40:24.200] INFO: 37 hot pixels found in step 3
[16:40:25.194] INFO: Collecting data for 5 seconds...
[16:40:30.210] INFO: Done with hot pixel readout
[16:40:42.285] INFO: PixTest:: pg_setup set to default.
[16:40:42.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:40:42.286] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:40:42.286] INFO: 40 hot pixels found in step 4
[16:40:43.280] INFO: Collecting data for 5 seconds...
[16:40:48.297] INFO: Done with hot pixel readout
[16:41:00.392] INFO: PixTest:: pg_setup set to default.
[16:41:00.392] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:41:00.393] INFO: 32 hot pixels found in step 5
[16:41:01.387] INFO: Collecting data for 5 seconds...
[16:41:06.403] INFO: Done with hot pixel readout
[16:41:18.493] INFO: PixTest:: pg_setup set to default.
[16:41:18.494] INFO: 26 hot pixels found in step 6
[16:41:19.489] INFO: Collecting data for 5 seconds...
[16:41:24.507] INFO: Done with hot pixel readout
[16:41:36.322] INFO: PixTest:: pg_setup set to default.
[16:41:36.323] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:41:36.323] INFO: 36 hot pixels found in step 7
[16:41:37.318] INFO: Collecting data for 5 seconds...
[16:41:42.337] INFO: Done with hot pixel readout
[16:41:53.956] INFO: PixTest:: pg_setup set to default.
[16:41:53.957] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:41:53.957] INFO: 29 hot pixels found in step 8
[16:41:54.952] INFO: Collecting data for 5 seconds...
[16:41:59.971] INFO: Done with hot pixel readout
[16:42:11.794] INFO: PixTest:: pg_setup set to default.
[16:42:11.795] INFO: 29 hot pixels found in step 9
[16:42:12.789] INFO: Collecting data for 5 seconds...
[16:42:17.808] INFO: Done with hot pixel readout
[16:42:29.780] INFO: PixTest:: pg_setup set to default.
[16:42:29.781] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:42:29.781] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:42:29.781] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:42:29.781] INFO: 30 hot pixels found in step 10
[16:42:30.785] INFO: Collecting data for 5 seconds...
[16:42:35.804] INFO: Done with hot pixel readout
[16:42:46.705] INFO: PixTest:: pg_setup set to default.
[16:42:46.705] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:42:46.706] INFO: 29 hot pixels found in step 11
[16:42:47.702] INFO: Collecting data for 5 seconds...
[16:42:52.721] INFO: Done with hot pixel readout
[16:43:04.346] INFO: PixTest:: pg_setup set to default.
[16:43:04.346] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:04.347] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:04.347] INFO: 27 hot pixels found in step 12
[16:43:05.342] INFO: Collecting data for 5 seconds...
[16:43:10.360] INFO: Done with hot pixel readout
[16:43:22.408] INFO: PixTest:: pg_setup set to default.
[16:43:22.409] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:22.409] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:22.409] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:22.409] INFO: 25 hot pixels found in step 13
[16:43:23.404] INFO: Collecting data for 5 seconds...
[16:43:28.422] INFO: Done with hot pixel readout
[16:43:40.057] INFO: PixTest:: pg_setup set to default.
[16:43:40.058] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:43:40.058] INFO: 24 hot pixels found in step 14
[16:43:40.098] INFO: 24 hot pixels could not be trimmed and have been masked.
[16:43:40.123] INFO: PixTest::trimHotPixels() done
[16:43:40.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat
[16:43:40.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C1.dat
[16:43:40.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C2.dat
[16:43:40.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C3.dat
[16:43:40.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C4.dat
[16:43:40.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C5.dat
[16:43:40.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C6.dat
[16:43:40.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C7.dat
[16:43:40.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C8.dat
[16:43:40.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C9.dat
[16:43:40.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C10.dat
[16:43:40.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C11.dat
[16:43:40.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C12.dat
[16:43:40.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C13.dat
[16:43:40.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C14.dat
[16:43:40.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[16:43:40.252] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[16:43:40.263] INFO: enter test to run
[16:44:28.203] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:44:28.203] INFO: running: highrate
[16:44:28.207] INFO: ----------------------------------------------------------------------
[16:44:28.207] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:44:28.207] INFO: ----------------------------------------------------------------------
[16:44:28.207] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:44:28.207] INFO: edge/corner pixel THR is adjusted
[16:44:28.207] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:44:29.165] INFO: Collecting data for 1 seconds...
[16:44:30.168] INFO: Done with hot pixel readout
[16:44:34.314] INFO: PixTest:: pg_setup set to default.
[16:44:34.315] INFO: 0 hot pixels found in step 0
[16:44:34.320] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:44:34.402] INFO: PixTest::trimHotPixels() done
[16:44:34.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat
[16:44:34.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C1.dat
[16:44:34.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C2.dat
[16:44:34.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C3.dat
[16:44:34.425] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C4.dat
[16:44:34.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C5.dat
[16:44:34.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C6.dat
[16:44:34.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C7.dat
[16:44:34.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C8.dat
[16:44:34.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C9.dat
[16:44:34.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C10.dat
[16:44:34.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C11.dat
[16:44:34.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C12.dat
[16:44:34.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C13.dat
[16:44:34.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C14.dat
[16:44:34.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[16:44:34.488] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-39_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[16:44:34.498] INFO: enter test to run
[16:45:05.819] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:45:05.819] INFO: running: xray
[16:45:05.820] INFO: ----------------------------------------------------------------------
[16:45:05.820] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:45:05.820] INFO: ----------------------------------------------------------------------
[16:45:06.810] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:45:18.123] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:45:47.996] INFO: Resuming triggers.
[16:45:59.307] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:46:29.163] INFO: Resuming triggers.
[16:46:40.478] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:47:10.397] INFO: Resuming triggers.
[16:47:21.714] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:47:50.001] INFO: Resuming triggers.
[16:48:02.312] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:48:31.696] INFO: Resuming triggers.
[16:48:43.010] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:49:12.380] INFO: Resuming triggers.
[16:49:23.691] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:49:53.162] INFO: Resuming triggers.
[16:50:04.474] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:50:33.944] INFO: Resuming triggers.
[16:50:43.790] INFO: data taking finished, elapsed time: 100 seconds.
[16:51:09.293] INFO: PixTest:: pg_setup set to default.
[16:51:09.297] INFO: PixTestXray::doPhRun() done
[16:51:09.457] INFO: enter test to run
[16:51:44.328] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:51:44.328] INFO: running: xray
[16:51:44.329] INFO: ----------------------------------------------------------------------
[16:51:44.329] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:51:44.329] INFO: ----------------------------------------------------------------------
[16:51:45.293] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:51:51.879] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:52:22.107] INFO: Resuming triggers.
[16:52:28.694] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:52:58.937] INFO: Resuming triggers.
[16:53:05.521] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:53:36.184] INFO: Resuming triggers.
[16:53:42.767] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:54:13.347] INFO: Resuming triggers.
[16:54:19.932] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:54:50.077] INFO: Resuming triggers.
[16:54:56.662] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[16:55:27.842] INFO: Resuming triggers.
[16:55:34.430] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:56:05.357] INFO: Resuming triggers.
[16:56:11.941] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:56:42.619] INFO: Resuming triggers.
[16:56:49.203] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:57:19.945] INFO: Resuming triggers.
[16:57:26.526] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[16:57:57.473] INFO: Resuming triggers.
[16:58:04.053] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:58:35.036] INFO: Resuming triggers.
[16:58:41.618] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:59:12.385] INFO: Resuming triggers.
[16:59:18.967] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:59:49.270] INFO: Resuming triggers.
[16:59:55.849] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[17:00:26.145] INFO: Resuming triggers.
[17:00:32.722] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[17:01:02.927] INFO: Resuming triggers.
[17:01:04.530] INFO: data taking finished, elapsed time: 100 seconds.
[17:01:12.234] INFO: PixTest:: pg_setup set to default.
[17:01:12.238] INFO: PixTestXray::doPhRun() done
[17:01:12.388] INFO: enter test to run
[17:01:41.796] INFO: test: HighRate no parameter change
[17:01:41.796] INFO: running: highrate
[17:01:41.808] INFO: ----------------------------------------------------------------------
[17:01:41.808] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:01:41.808] INFO: ----------------------------------------------------------------------
[17:01:41.962] INFO: Expecting 768 events.
[17:01:43.096] INFO: 768 events read in total (418ms).
[17:01:43.096] INFO: Test took 1268ms.
[17:01:43.899] INFO: Expecting 41600 events.
[17:01:47.042] INFO: 41600 events read in total (2616ms).
[17:01:47.043] INFO: Test took 3922ms.
[17:01:47.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:47.803] INFO: Expecting 41600 events.
[17:01:51.035] INFO: 41600 events read in total (2705ms).
[17:01:51.036] INFO: Test took 3939ms.
[17:01:51.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:51.790] INFO: Expecting 41600 events.
[17:01:55.036] INFO: 41600 events read in total (2719ms).
[17:01:55.037] INFO: Test took 3946ms.
[17:01:55.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:55.794] INFO: Expecting 41600 events.
[17:01:59.054] INFO: 41600 events read in total (2733ms).
[17:01:59.055] INFO: Test took 3964ms.
[17:01:59.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:59.810] INFO: Expecting 41600 events.
[17:02:03.074] INFO: 41600 events read in total (2737ms).
[17:02:03.075] INFO: Test took 3964ms.
[17:02:03.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:03.832] INFO: Expecting 41600 events.
[17:02:07.095] INFO: 41600 events read in total (2737ms).
[17:02:07.096] INFO: Test took 3961ms.
[17:02:07.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:07.853] INFO: Expecting 41600 events.
[17:02:11.124] INFO: 41600 events read in total (2745ms).
[17:02:11.125] INFO: Test took 3973ms.
[17:02:11.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:11.880] INFO: Expecting 41600 events.
[17:02:15.156] INFO: 41600 events read in total (2749ms).
[17:02:15.158] INFO: Test took 3977ms.
[17:02:15.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:15.910] INFO: Expecting 41600 events.
[17:02:19.188] INFO: 41600 events read in total (2751ms).
[17:02:19.189] INFO: Test took 3975ms.
[17:02:19.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:19.944] INFO: Expecting 41600 events.
[17:02:23.208] INFO: 41600 events read in total (2737ms).
[17:02:23.209] INFO: Test took 3965ms.
[17:02:23.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:23.962] INFO: Expecting 41600 events.
[17:02:27.232] INFO: 41600 events read in total (2743ms).
[17:02:27.233] INFO: Test took 3968ms.
[17:02:27.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:27.991] INFO: Expecting 41600 events.
[17:02:31.265] INFO: 41600 events read in total (2748ms).
[17:02:31.266] INFO: Test took 3977ms.
[17:02:31.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:32.025] INFO: Expecting 41600 events.
[17:02:35.304] INFO: 41600 events read in total (2754ms).
[17:02:35.305] INFO: Test took 3984ms.
[17:02:35.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:36.059] INFO: Expecting 41600 events.
[17:02:39.324] INFO: 41600 events read in total (2738ms).
[17:02:39.325] INFO: Test took 3962ms.
[17:02:39.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:40.079] INFO: Expecting 41600 events.
[17:02:43.360] INFO: 41600 events read in total (2755ms).
[17:02:43.361] INFO: Test took 3978ms.
[17:02:43.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:44.118] INFO: Expecting 41600 events.
[17:02:47.391] INFO: 41600 events read in total (2746ms).
[17:02:47.392] INFO: Test took 3974ms.
[17:02:47.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:48.148] INFO: Expecting 41600 events.
[17:02:51.409] INFO: 41600 events read in total (2734ms).
[17:02:51.410] INFO: Test took 3961ms.
[17:02:51.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:52.165] INFO: Expecting 41600 events.
[17:02:55.433] INFO: 41600 events read in total (2742ms).
[17:02:55.434] INFO: Test took 3969ms.
[17:02:55.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:56.193] INFO: Expecting 41600 events.
[17:02:59.439] INFO: 41600 events read in total (2719ms).
[17:02:59.440] INFO: Test took 3949ms.
[17:02:59.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:00.197] INFO: Expecting 41600 events.
[17:03:03.309] INFO: 41600 events read in total (2585ms).
[17:03:03.310] INFO: Test took 3814ms.
[17:03:03.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:03.698] INFO: enter test to run
[17:03:07.635] INFO: test: HighRate no parameter change
[17:03:07.635] INFO: running: highrate
[17:03:07.636] INFO: ----------------------------------------------------------------------
[17:03:07.636] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:03:07.636] INFO: ----------------------------------------------------------------------
[17:03:08.254] INFO: Expecting 208000 events.
[17:03:20.262] INFO: 208000 events read in total (11481ms).
[17:03:20.265] INFO: Test took 12622ms.
[17:03:20.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:20.679] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:03:20.679] INFO: number of red-efficiency pixels: 79 51 99 145 199 193 175 128 103 152 102 107 115 69 30 32
[17:03:20.679] INFO: number of X-ray hits detected: 69409 43421 72577 113060 123641 131295 127398 94616 91966 107437 105666 88254 90316 56339 21385 26746
[17:03:20.679] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:03:20.679] INFO: number of Vcal hits detected: 207919 207949 207898 207841 207796 207802 207817 207872 207895 207847 207895 207890 207882 207930 207970 207869
[17:03:20.679] 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 100.0 100.0 99.9 100.0 100.0 100.0
[17:03:20.679] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9
[17:03:20.679] INFO: X-ray hit rate [MHz/cm2]: 20.3 12.7 21.3 33.1 36.2 38.5 37.3 27.7 27.0 31.5 31.0 25.9 26.5 16.5 6.3 7.8
[17:03:20.679] INFO: PixTestHighRate::doXPixelAlive() done
[17:03:20.724] INFO: PixTest:: pg_setup set to default.
[17:03:20.739] INFO: enter test to run
[17:03:35.171] INFO: test: HighRate no parameter change
[17:03:35.171] INFO: running: highrate
[17:03:35.172] INFO: ----------------------------------------------------------------------
[17:03:35.172] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:03:35.172] INFO: ----------------------------------------------------------------------
[17:03:35.789] INFO: Expecting 208000 events.
[17:03:49.578] INFO: 208000 events read in total (13262ms).
[17:03:49.584] INFO: Test took 14402ms.
[17:03:49.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:50.200] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:03:50.200] INFO: number of red-efficiency pixels: 250 115 364 422 579 748 703 340 250 413 365 269 319 231 36 71
[17:03:50.200] INFO: number of X-ray hits detected: 137013 85920 143362 224279 244410 259204 250797 186450 180916 211940 209399 174725 178663 111238 42998 53414
[17:03:50.200] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:03:50.200] INFO: number of Vcal hits detected: 207725 207881 207592 207529 207346 207134 207200 207639 207730 207562 207622 207710 207657 207753 207964 207828
[17:03:50.200] 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.9 99.9 100.0 100.0
[17:03:50.200] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.6 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 99.9
[17:03:50.200] INFO: X-ray hit rate [MHz/cm2]: 40.2 25.2 42.0 65.7 71.6 76.0 73.5 54.6 53.0 62.1 61.4 51.2 52.4 32.6 12.6 15.7
[17:03:50.200] INFO: PixTestHighRate::doXPixelAlive() done
[17:03:50.246] INFO: PixTest:: pg_setup set to default.
[17:03:50.261] INFO: enter test to run
[17:04:13.283] INFO: test: HighRate no parameter change
[17:04:13.283] INFO: running: highrate
[17:04:13.284] INFO: ----------------------------------------------------------------------
[17:04:13.284] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:04:13.284] INFO: ----------------------------------------------------------------------
[17:04:13.901] INFO: Expecting 208000 events.
[17:04:29.510] INFO: 208000 events read in total (15083ms).
[17:04:29.517] INFO: Test took 16224ms.
[17:04:29.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:30.313] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:04:30.313] INFO: number of red-efficiency pixels: 561 205 720 877 1464 1598 1482 694 597 905 814 564 682 486 94 110
[17:04:30.313] INFO: number of X-ray hits detected: 204569 128015 215039 332465 362826 386562 375379 279242 271480 314707 312133 259497 267778 166627 63598 79989
[17:04:30.313] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:04:30.313] INFO: number of Vcal hits detected: 207309 207777 207003 206916 206036 205660 205923 207134 207331 206901 207026 207363 207215 207419 207902 207788
[17:04:30.313] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.5 99.2 99.0 99.1 99.6 99.7 99.5 99.6 99.7 99.7 99.7 100.0 99.9
[17:04:30.313] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.5 99.1 98.9 99.0 99.6 99.7 99.5 99.5 99.7 99.6 99.7 100.0 99.9
[17:04:30.313] INFO: X-ray hit rate [MHz/cm2]: 60.0 37.5 63.0 97.4 106.3 113.3 110.0 81.8 79.6 92.2 91.5 76.1 78.5 48.8 18.6 23.4
[17:04:30.313] INFO: PixTestHighRate::doXPixelAlive() done
[17:04:30.364] INFO: PixTest:: pg_setup set to default.
[17:04:30.379] INFO: enter test to run
[17:04:33.642] INFO: test: exit no parameter change
[17:04:34.062] QUIET: Connection to board 32 closed.
[17:04:34.070] INFO: pXar: this is the end, my friend