[17:33:51.259] INFO: *** Welcome to pxar ***
[17:33:51.259] INFO: *** Today: 2016/06/06
[17:33:51.320] INFO: *** Version: v1.9.0-814-g7497
[17:33:51.320] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//dacParameters35_C15.dat
[17:33:51.364] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:33:51.365] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[17:33:51.365] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[17:33:51.467] INFO: clk: 4
[17:33:51.467] INFO: ctr: 4
[17:33:51.467] INFO: sda: 19
[17:33:51.467] INFO: tin: 9
[17:33:51.467] INFO: level: 15
[17:33:51.467] INFO: triggerdelay: 0
[17:33:51.467] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:33:51.467] INFO: Log level: INFO
[17:33:51.484] QUIET: Connection to board DTB_WREK4U opened.
[17:33:51.487] 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:
------------------------------------------------------
[17:33:51.490] INFO: RPC call hashes of host and DTB match: 398089610
[17:33:53.023] INFO: DUT info:
[17:33:53.023] INFO: The DUT currently contains the following objects:
[17:33:53.023] INFO: 2 TBM Cores tbm08c (2 ON)
[17:33:53.023] INFO: TBM Core alpha (0): 7 registers set
[17:33:53.023] INFO: TBM Core beta (1): 7 registers set
[17:33:53.023] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:33:53.023] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.023] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.023] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.024] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:33:53.451] INFO: enter 'restricted' command line mode
[17:33:53.451] INFO: enter test to run
[17:33:59.645] INFO: test: PixelAlive no parameter change
[17:33:59.645] INFO: running: pixelalive
[17:33:59.653] INFO: ----------------------------------------------------------------------
[17:33:59.653] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:33:59.653] INFO: ----------------------------------------------------------------------
[17:33:59.967] INFO: Expecting 41600 events.
[17:34:04.305] INFO: 41600 events read in total (3619ms).
[17:34:04.473] INFO: Test took 4818ms.
[17:34:04.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:04.747] INFO: PixTestAlive::aliveTest() done
[17:34:04.747] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[17:34:04.780] INFO: enter test to run
[17:34:37.188] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:34:37.188] INFO: running: highrate
[17:34:37.189] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:34:37.410] INFO: ----------------------------------------------------------------------
[17:34:37.410] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:34:37.410] INFO: ----------------------------------------------------------------------
[17:34:37.410] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:34:37.410] INFO: edge/corner pixel THR is adjusted
[17:34:37.410] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:34:38.369] INFO: Collecting data for 5 seconds...
[17:34:43.387] INFO: Done with hot pixel readout
[17:34:55.106] INFO: PixTest:: pg_setup set to default.
[17:34:55.106] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:34:55.106] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:34:55.107] INFO: 30 hot pixels found in step 0
[17:34:56.102] INFO: Collecting data for 5 seconds...
[17:35:01.119] INFO: Done with hot pixel readout
[17:35:12.986] INFO: PixTest:: pg_setup set to default.
[17:35:12.987] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:35:12.987] INFO: 35 hot pixels found in step 1
[17:35:13.983] INFO: Collecting data for 5 seconds...
[17:35:18.999] INFO: Done with hot pixel readout
[17:35:30.883] INFO: PixTest:: pg_setup set to default.
[17:35:30.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:35:30.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:35:30.884] INFO: 39 hot pixels found in step 2
[17:35:31.879] INFO: Collecting data for 5 seconds...
[17:35:36.895] INFO: Done with hot pixel readout
[17:35:48.849] INFO: PixTest:: pg_setup set to default.
[17:35:48.850] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:35:48.852] INFO: 23 hot pixels found in step 3
[17:35:49.853] INFO: Collecting data for 5 seconds...
[17:35:54.870] INFO: Done with hot pixel readout
[17:36:06.905] INFO: PixTest:: pg_setup set to default.
[17:36:06.906] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:36:06.906] INFO: 23 hot pixels found in step 4
[17:36:07.902] INFO: Collecting data for 5 seconds...
[17:36:12.918] INFO: Done with hot pixel readout
[17:36:24.931] INFO: PixTest:: pg_setup set to default.
[17:36:24.931] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:36:24.932] INFO: 22 hot pixels found in step 5
[17:36:25.927] INFO: Collecting data for 5 seconds...
[17:36:30.944] INFO: Done with hot pixel readout
[17:36:42.989] INFO: PixTest:: pg_setup set to default.
[17:36:42.990] INFO: 33 hot pixels found in step 6
[17:36:43.985] INFO: Collecting data for 5 seconds...
[17:36:49.001] INFO: Done with hot pixel readout
[17:37:01.046] INFO: PixTest:: pg_setup set to default.
[17:37:01.046] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:01.047] INFO: 19 hot pixels found in step 7
[17:37:02.042] INFO: Collecting data for 5 seconds...
[17:37:07.059] INFO: Done with hot pixel readout
[17:37:19.134] INFO: PixTest:: pg_setup set to default.
[17:37:19.134] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:19.135] INFO: 27 hot pixels found in step 8
[17:37:20.131] INFO: Collecting data for 5 seconds...
[17:37:25.147] INFO: Done with hot pixel readout
[17:37:37.190] INFO: PixTest:: pg_setup set to default.
[17:37:37.190] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:37.190] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:37.191] INFO: 13 hot pixels found in step 9
[17:37:38.186] INFO: Collecting data for 5 seconds...
[17:37:43.202] INFO: Done with hot pixel readout
[17:37:55.218] INFO: PixTest:: pg_setup set to default.
[17:37:55.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:55.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:37:55.219] INFO: 24 hot pixels found in step 10
[17:37:56.214] INFO: Collecting data for 5 seconds...
[17:38:01.229] INFO: Done with hot pixel readout
[17:38:13.218] INFO: PixTest:: pg_setup set to default.
[17:38:13.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:13.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:13.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:13.219] INFO: 25 hot pixels found in step 11
[17:38:14.214] INFO: Collecting data for 5 seconds...
[17:38:19.230] INFO: Done with hot pixel readout
[17:38:31.231] INFO: PixTest:: pg_setup set to default.
[17:38:31.231] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:31.231] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:31.231] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:31.232] INFO: 18 hot pixels found in step 12
[17:38:32.227] INFO: Collecting data for 5 seconds...
[17:38:37.243] INFO: Done with hot pixel readout
[17:38:49.255] INFO: PixTest:: pg_setup set to default.
[17:38:49.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:49.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:49.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:38:49.256] INFO: 21 hot pixels found in step 13
[17:38:50.252] INFO: Collecting data for 5 seconds...
[17:38:55.267] INFO: Done with hot pixel readout
[17:39:07.282] INFO: PixTest:: pg_setup set to default.
[17:39:07.282] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:39:07.282] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:39:07.282] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:39:07.282] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:39:07.283] INFO: 10 hot pixels found in step 14
[17:39:07.323] INFO: 10 hot pixels could not be trimmed and have been masked.
[17:39:07.326] INFO: PixTest::trimHotPixels() done
[17:39:07.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat
[17:39:07.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C1.dat
[17:39:07.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C2.dat
[17:39:07.345] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C3.dat
[17:39:07.351] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C4.dat
[17:39:07.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C5.dat
[17:39:07.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C6.dat
[17:39:07.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C7.dat
[17:39:07.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C8.dat
[17:39:07.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C9.dat
[17:39:07.383] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C10.dat
[17:39:07.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C11.dat
[17:39:07.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C12.dat
[17:39:07.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C13.dat
[17:39:07.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C14.dat
[17:39:07.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[17:39:07.416] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[17:39:07.427] INFO: enter test to run
[17:40:16.210] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:40:16.210] INFO: running: highrate
[17:40:16.215] INFO: ----------------------------------------------------------------------
[17:40:16.215] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:40:16.215] INFO: ----------------------------------------------------------------------
[17:40:16.215] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:40:16.215] INFO: edge/corner pixel THR is adjusted
[17:40:16.215] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:40:17.172] INFO: Collecting data for 1 seconds...
[17:40:18.177] INFO: Done with hot pixel readout
[17:40:22.476] INFO: PixTest:: pg_setup set to default.
[17:40:22.477] INFO: 0 hot pixels found in step 0
[17:40:22.483] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:40:22.559] INFO: PixTest::trimHotPixels() done
[17:40:22.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C0.dat
[17:40:22.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C1.dat
[17:40:22.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C2.dat
[17:40:22.577] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C3.dat
[17:40:22.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C4.dat
[17:40:22.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C5.dat
[17:40:22.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C6.dat
[17:40:22.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C7.dat
[17:40:22.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C8.dat
[17:40:22.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C9.dat
[17:40:22.615] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C10.dat
[17:40:22.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C11.dat
[17:40:22.626] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C12.dat
[17:40:22.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C13.dat
[17:40:22.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C14.dat
[17:40:22.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//trimParameters35_C15.dat
[17:40:22.648] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-43_FPIXTest-17C-FNAL-160602-1208_2016-06-02_12h08m_1464887318/000_FPIXTest_p17//defaultMaskFile.dat
[17:40:22.659] INFO: enter test to run
[17:40:48.385] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:40:48.385] INFO: running: xray
[17:40:48.386] INFO: ----------------------------------------------------------------------
[17:40:48.386] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:40:48.386] INFO: ----------------------------------------------------------------------
[17:40:49.348] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:41:00.286] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[17:41:30.445] INFO: Resuming triggers.
[17:41:41.385] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[17:42:12.082] INFO: Resuming triggers.
[17:42:23.020] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[17:42:53.335] INFO: Resuming triggers.
[17:43:04.279] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[17:43:34.425] INFO: Resuming triggers.
[17:43:45.367] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[17:44:15.069] INFO: Resuming triggers.
[17:44:26.013] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[17:44:55.673] INFO: Resuming triggers.
[17:45:06.610] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[17:45:36.390] INFO: Resuming triggers.
[17:45:47.327] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[17:46:16.923] INFO: Resuming triggers.
[17:46:27.865] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[17:46:57.427] INFO: Resuming triggers.
[17:46:59.310] INFO: data taking finished, elapsed time: 100 seconds.
[17:47:04.750] INFO: PixTest:: pg_setup set to default.
[17:47:04.753] INFO: PixTestXray::doPhRun() done
[17:47:04.892] INFO: enter test to run
[17:48:17.254] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:48:17.254] INFO: running: xray
[17:48:17.255] INFO: ----------------------------------------------------------------------
[17:48:17.255] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:48:17.255] INFO: ----------------------------------------------------------------------
[17:48:18.231] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:48:24.441] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:48:54.690] INFO: Resuming triggers.
[17:49:00.900] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[17:49:30.978] INFO: Resuming triggers.
[17:49:37.186] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[17:50:07.348] INFO: Resuming triggers.
[17:50:13.558] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[17:50:43.637] INFO: Resuming triggers.
[17:50:49.847] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[17:51:20.045] INFO: Resuming triggers.
[17:51:26.253] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[17:51:57.045] INFO: Resuming triggers.
[17:52:03.256] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[17:52:33.941] INFO: Resuming triggers.
[17:52:40.147] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[17:53:11.540] INFO: Resuming triggers.
[17:53:17.748] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[17:53:49.110] INFO: Resuming triggers.
[17:53:55.321] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[17:54:26.994] INFO: Resuming triggers.
[17:54:33.202] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[17:55:03.361] INFO: Resuming triggers.
[17:55:09.575] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[17:55:39.558] INFO: Resuming triggers.
[17:55:45.767] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[17:56:15.854] INFO: Resuming triggers.
[17:56:22.062] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[17:56:52.170] INFO: Resuming triggers.
[17:56:58.382] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:57:28.459] INFO: Resuming triggers.
[17:57:34.667] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[17:58:04.717] INFO: Resuming triggers.
[17:58:05.707] INFO: data taking finished, elapsed time: 100 seconds.
[17:58:10.850] INFO: PixTest:: pg_setup set to default.
[17:58:10.854] INFO: PixTestXray::doPhRun() done
[17:58:11.006] INFO: enter test to run
[17:58:45.298] INFO: test: HighRate no parameter change
[17:58:45.298] INFO: running: highrate
[17:58:45.299] INFO: ----------------------------------------------------------------------
[17:58:45.299] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:58:45.299] INFO: ----------------------------------------------------------------------
[17:58:45.442] INFO: Expecting 768 events.
[17:58:46.575] INFO: 768 events read in total (418ms).
[17:58:46.576] INFO: Test took 1269ms.
[17:58:47.379] INFO: Expecting 41600 events.
[17:58:50.505] INFO: 41600 events read in total (2599ms).
[17:58:50.506] INFO: Test took 3924ms.
[17:58:50.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:51.267] INFO: Expecting 41600 events.
[17:58:54.513] INFO: 41600 events read in total (2719ms).
[17:58:54.514] INFO: Test took 3953ms.
[17:58:54.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:55.268] INFO: Expecting 41600 events.
[17:58:58.536] INFO: 41600 events read in total (2741ms).
[17:58:58.537] INFO: Test took 3966ms.
[17:58:58.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:59.294] INFO: Expecting 41600 events.
[17:59:02.566] INFO: 41600 events read in total (2745ms).
[17:59:02.567] INFO: Test took 3972ms.
[17:59:02.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:03.321] INFO: Expecting 41600 events.
[17:59:06.590] INFO: 41600 events read in total (2742ms).
[17:59:06.591] INFO: Test took 3967ms.
[17:59:06.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:07.348] INFO: Expecting 41600 events.
[17:59:10.606] INFO: 41600 events read in total (2731ms).
[17:59:10.607] INFO: Test took 3958ms.
[17:59:10.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:11.359] INFO: Expecting 41600 events.
[17:59:14.638] INFO: 41600 events read in total (2752ms).
[17:59:14.639] INFO: Test took 3976ms.
[17:59:14.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:15.394] INFO: Expecting 41600 events.
[17:59:18.661] INFO: 41600 events read in total (2740ms).
[17:59:18.662] INFO: Test took 3966ms.
[17:59:18.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:19.418] INFO: Expecting 41600 events.
[17:59:22.692] INFO: 41600 events read in total (2747ms).
[17:59:22.693] INFO: Test took 3973ms.
[17:59:22.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:23.449] INFO: Expecting 41600 events.
[17:59:26.733] INFO: 41600 events read in total (2757ms).
[17:59:26.734] INFO: Test took 3983ms.
[17:59:26.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:27.485] INFO: Expecting 41600 events.
[17:59:30.756] INFO: 41600 events read in total (2744ms).
[17:59:30.757] INFO: Test took 3964ms.
[17:59:30.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:31.513] INFO: Expecting 41600 events.
[17:59:34.797] INFO: 41600 events read in total (2757ms).
[17:59:34.798] INFO: Test took 3983ms.
[17:59:34.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:35.552] INFO: Expecting 41600 events.
[17:59:38.832] INFO: 41600 events read in total (2753ms).
[17:59:38.833] INFO: Test took 3978ms.
[17:59:38.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:39.589] INFO: Expecting 41600 events.
[17:59:42.872] INFO: 41600 events read in total (2756ms).
[17:59:42.873] INFO: Test took 3984ms.
[17:59:42.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:43.624] INFO: Expecting 41600 events.
[17:59:46.916] INFO: 41600 events read in total (2765ms).
[17:59:46.917] INFO: Test took 3987ms.
[17:59:46.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:47.669] INFO: Expecting 41600 events.
[17:59:50.950] INFO: 41600 events read in total (2755ms).
[17:59:50.951] INFO: Test took 3977ms.
[17:59:50.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:51.706] INFO: Expecting 41600 events.
[17:59:54.992] INFO: 41600 events read in total (2759ms).
[17:59:54.993] INFO: Test took 3984ms.
[17:59:55.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:55.745] INFO: Expecting 41600 events.
[17:59:59.027] INFO: 41600 events read in total (2755ms).
[17:59:59.028] INFO: Test took 3977ms.
[17:59:59.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:59.782] INFO: Expecting 41600 events.
[18:00:03.068] INFO: 41600 events read in total (2759ms).
[18:00:03.069] INFO: Test took 3984ms.
[18:00:03.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:03.820] INFO: Expecting 41600 events.
[18:00:06.993] INFO: 41600 events read in total (2646ms).
[18:00:06.994] INFO: Test took 3866ms.
[18:00:07.032] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:07.386] INFO: enter test to run
[18:00:25.233] INFO: test: HighRate no parameter change
[18:00:25.233] INFO: running: highrate
[18:00:25.234] INFO: ----------------------------------------------------------------------
[18:00:25.234] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:00:25.234] INFO: ----------------------------------------------------------------------
[18:00:25.852] INFO: Expecting 208000 events.
[18:00:37.911] INFO: 208000 events read in total (11532ms).
[18:00:37.915] INFO: Test took 12671ms.
[18:00:38.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:38.336] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[18:00:38.336] INFO: number of red-efficiency pixels: 75 49 102 140 131 171 183 119 107 139 133 89 130 81 20 34
[18:00:38.337] INFO: number of X-ray hits detected: 73851 51863 82450 123506 128745 124171 125854 93397 88609 112026 108178 96516 98934 59942 27860 30810
[18:00:38.337] 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:00:38.337] INFO: number of Vcal hits detected: 207923 207950 207896 207852 207863 207825 207811 207827 207891 207860 207859 207910 207867 207918 207980 207966
[18:00:38.337] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[18:00:38.337] 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 100.0 99.9 100.0 100.0 100.0
[18:00:38.337] INFO: X-ray hit rate [MHz/cm2]: 21.6 15.2 24.2 36.2 37.7 36.4 36.9 27.4 26.0 32.8 31.7 28.3 29.0 17.6 8.2 9.0
[18:00:38.337] INFO: PixTestHighRate::doXPixelAlive() done
[18:00:38.385] INFO: PixTest:: pg_setup set to default.
[18:00:38.398] INFO: enter test to run
[18:01:18.537] INFO: test: HighRate no parameter change
[18:01:18.537] INFO: running: highrate
[18:01:18.538] INFO: ----------------------------------------------------------------------
[18:01:18.538] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:01:18.538] INFO: ----------------------------------------------------------------------
[18:01:19.154] INFO: Expecting 208000 events.
[18:01:33.181] INFO: 208000 events read in total (13500ms).
[18:01:33.187] INFO: Test took 14639ms.
[18:01:33.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:33.837] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[18:01:33.837] INFO: number of red-efficiency pixels: 296 128 419 454 490 589 613 373 303 418 516 285 364 201 64 84
[18:01:33.837] INFO: number of X-ray hits detected: 149952 105895 168666 252504 263405 254425 256562 191392 181212 229728 220411 196164 202047 122293 57496 63849
[18:01:33.837] 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:01:33.837] INFO: number of Vcal hits detected: 207671 207868 207506 207488 207455 207327 207323 207548 207683 207560 207442 207706 207615 207783 207936 207913
[18:01:33.837] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 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:01:33.837] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.8 99.8 99.7 99.9 99.8 99.9 100.0 100.0
[18:01:33.837] INFO: X-ray hit rate [MHz/cm2]: 44.0 31.0 49.4 74.0 77.2 74.6 75.2 56.1 53.1 67.3 64.6 57.5 59.2 35.8 16.9 18.7
[18:01:33.837] INFO: PixTestHighRate::doXPixelAlive() done
[18:01:33.884] INFO: PixTest:: pg_setup set to default.
[18:01:33.900] INFO: enter test to run
[18:03:03.920] INFO: test: HighRate no parameter change
[18:03:03.920] INFO: running: highrate
[18:03:03.921] INFO: ----------------------------------------------------------------------
[18:03:03.921] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:03:03.921] INFO: ----------------------------------------------------------------------
[18:03:04.549] INFO: Expecting 208000 events.
[18:03:21.257] INFO: 208000 events read in total (16181ms).
[18:03:21.265] INFO: Test took 17333ms.
[18:03:21.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:22.162] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[18:03:22.162] INFO: number of red-efficiency pixels: 594 297 930 1160 1303 1483 1529 763 777 932 1142 719 896 461 114 134
[18:03:22.162] INFO: number of X-ray hits detected: 228390 161680 257520 383982 401280 386144 389377 291010 276058 349079 335944 300684 308334 186848 87694 97067
[18:03:22.163] 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:03:22.163] INFO: number of Vcal hits detected: 207247 207674 206596 206509 206291 205926 205839 206992 207094 206868 206546 207132 206961 207453 207884 207864
[18:03:22.163] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.4 99.3 99.3 99.1 99.1 99.6 99.6 99.5 99.4 99.6 99.5 99.8 99.9 99.9
[18:03:22.163] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.3 99.3 99.2 99.0 99.0 99.5 99.6 99.5 99.3 99.6 99.5 99.7 99.9 99.9
[18:03:22.163] INFO: X-ray hit rate [MHz/cm2]: 66.9 47.4 75.5 112.5 117.6 113.2 114.1 85.3 80.9 102.3 98.5 88.1 90.4 54.8 25.7 28.5
[18:03:22.163] INFO: PixTestHighRate::doXPixelAlive() done
[18:03:22.208] INFO: PixTest:: pg_setup set to default.
[18:03:22.223] INFO: enter test to run
[18:03:30.975] INFO: test: exit no parameter change
[18:03:31.292] QUIET: Connection to board 32 closed.
[18:03:31.294] INFO: pXar: this is the end, my friend