From 4ad86c2a5a9bdb75c7dfcb9be4d2c08101c26857 Mon Sep 17 00:00:00 2001 From: Ammar Askar Date: Sat, 21 Jul 2018 05:26:19 -0700 Subject: [PATCH 1/4] bpo-34060: Report system load when running test suite for Windows While Windows exposes the system processor queue length: the raw value used for load calculations on Unix systems, it does not provide an API to access the averaged value. Hence to calculate the load we must track and average it ourselves. We can't use multiprocessing or a thread to read it in the background while the tests run since using those would conflict with test_multiprocessing and test_xxsubprocess. Thus, we use Window's asynchronous IO API to run the tracker in the background with it sampling at the correct rate. When we wish to access the load we check to see if there's new data on the stream, if there is, we update our load values. --- Lib/test/libregrtest/main.py | 18 +++- Lib/test/libregrtest/utils.py | 96 ++++++++++++++++++- .../2018-07-20-13-09-19.bpo-34060.v-z87j.rst | 2 + 3 files changed, 112 insertions(+), 4 deletions(-) create mode 100644 Misc/NEWS.d/next/Windows/2018-07-20-13-09-19.bpo-34060.v-z87j.rst diff --git a/Lib/test/libregrtest/main.py b/Lib/test/libregrtest/main.py index 32ac44029bc3a4..1bfe72b30414c3 100644 --- a/Lib/test/libregrtest/main.py +++ b/Lib/test/libregrtest/main.py @@ -18,7 +18,8 @@ INTERRUPTED, CHILD_ERROR, TEST_DID_NOT_RUN, PROGRESS_MIN_TIME, format_test_result) from test.libregrtest.setup import setup_tests -from test.libregrtest.utils import removepy, count, format_duration, printlist +from test.libregrtest.utils import ( + removepy, count, format_duration, printlist, WindowsLoadTracker) from test import support try: import gc @@ -146,8 +147,8 @@ def display_progress(self, test_index, test): line = f"[{line}] {test}" # add the system load prefix: "load avg: 1.80 " - if hasattr(os, 'getloadavg'): - load_avg_1min = os.getloadavg()[0] + if self.getloadavg: + load_avg_1min = self.getloadavg() line = f"load avg: {load_avg_1min:.2f} {line}" # add the timestamp prefix: "0:01:05 " @@ -586,6 +587,17 @@ def main(self, tests=None, **kwargs): self._main(tests, kwargs) def _main(self, tests, kwargs): + self.ns = self.parse_args(kwargs) + + self.getloadavg = None + if hasattr(os, 'getloadavg'): + def getloadavg_1m(): + return os.getloadavg()[0] + self.getloadavg = getloadavg_1m + elif sys.platform == 'win32' and (self.ns.slaveargs is None): + load_tracker = WindowsLoadTracker() + self.getloadavg = load_tracker.getloadavg + if self.ns.huntrleaks: warmup, repetitions, _ = self.ns.huntrleaks if warmup < 1 or repetitions < 1: diff --git a/Lib/test/libregrtest/utils.py b/Lib/test/libregrtest/utils.py index d36bf9196626db..1444603b15a551 100644 --- a/Lib/test/libregrtest/utils.py +++ b/Lib/test/libregrtest/utils.py @@ -1,6 +1,9 @@ -import os.path +import os import math import textwrap +import subprocess +import sys +from test import support def format_duration(seconds): @@ -54,3 +57,94 @@ def printlist(x, width=70, indent=4, file=None): print(textwrap.fill(' '.join(str(elt) for elt in sorted(x)), width, initial_indent=blanks, subsequent_indent=blanks), file=file) + +BUFSIZE = 8192 +LOAD_FACTOR_1 = 0.9200444146293232478931553241 +SAMPLING_INTERVAL = 5 +COUNTER_NAME = r'\System\Processor Queue Length' + +""" +This class asynchronously interacts with the `typeperf` command to read +the system load on Windows. Mulitprocessing and threads can't be used +here because they interfere with the test suite's cases for those +modules. +""" +class WindowsLoadTracker(): + def __init__(self): + self.load = 0.0 + self.start() + + def start(self): + import _winapi + import msvcrt + import uuid + + # Create a named pipe which allows for asynchronous IO in Windows + pipe_name = r'\\.\pipe\typeperf_output_' + str(uuid.uuid4()) + + open_mode = _winapi.PIPE_ACCESS_INBOUND + open_mode |= _winapi.FILE_FLAG_FIRST_PIPE_INSTANCE + open_mode |= _winapi.FILE_FLAG_OVERLAPPED + + # This is the read end of the pipe, where we will be grabbing output + self.pipe = _winapi.CreateNamedPipe( + pipe_name, open_mode, _winapi.PIPE_WAIT, + 1, BUFSIZE, BUFSIZE, _winapi.NMPWAIT_WAIT_FOREVER, _winapi.NULL + ) + # The write end of the pipe which is passed to the created process + pipe_write_end = _winapi.CreateFile( + pipe_name, _winapi.GENERIC_WRITE, 0, _winapi.NULL, + _winapi.OPEN_EXISTING, 0x80000000, _winapi.NULL + ) + # Open up the handle as a python file object so we can pass it to + # subprocess + command_stdout = msvcrt.open_osfhandle(pipe_write_end, 0) + + # Connect to the read end of the pipe in overlap/async mode + overlap = _winapi.ConnectNamedPipe(self.pipe, overlapped=True) + overlap.GetOverlappedResult(True) + + # Spawn off the load monitor + command = ['typeperf', COUNTER_NAME, '-si', str(SAMPLING_INTERVAL)] + self.p = subprocess.Popen(command, stdout=command_stdout, cwd=support.SAVEDCWD) + + # Close our copy of the write end of the pipe + os.close(command_stdout) + + def read_output(self): + import _winapi + + overlapped, _ = _winapi.ReadFile(self.pipe, BUFSIZE, True) + bytes_read, res = overlapped.GetOverlappedResult(False) + if res != 0: + return + + return overlapped.getbuffer().decode() + + def getloadavg(self): + typeperf_output = self.read_output() + # Nothing to update, just return the current load + if not typeperf_output: + return self.load + + # Process the backlog of load values + for line in typeperf_output.splitlines(): + # typeperf outputs in a CSV format like this: + # "07/19/2018 01:32:26.605","3.000000" + toks = line.split(',') + # Ignore blank lines and the initial header + if line.strip() == '' or (COUNTER_NAME in line) or len(toks) != 2: + continue + + load = float(toks[1].replace('"', '')) + # We use an exponentially weighted moving average, imitating the + # load calculation on Unix systems. + # https://en.wikipedia.org/wiki/Load_(computing)#Unix-style_load_calculation + new_load = self.load * LOAD_FACTOR_1 + load * (1.0 - LOAD_FACTOR_1) + self.load = new_load + + return self.load + + def __del__(self): + self.p.kill() + self.p.wait() diff --git a/Misc/NEWS.d/next/Windows/2018-07-20-13-09-19.bpo-34060.v-z87j.rst b/Misc/NEWS.d/next/Windows/2018-07-20-13-09-19.bpo-34060.v-z87j.rst new file mode 100644 index 00000000000000..b77d805b7f2aff --- /dev/null +++ b/Misc/NEWS.d/next/Windows/2018-07-20-13-09-19.bpo-34060.v-z87j.rst @@ -0,0 +1,2 @@ +Report system load when running test suite on Windows. Patch by Ammar Askar. +Based on prior work by Jeremy Kloth. From 00a0895aad79f8355b471f03d4c638a70a905bf2 Mon Sep 17 00:00:00 2001 From: Ammar Askar Date: Tue, 24 Jul 2018 19:37:15 -0700 Subject: [PATCH 2/4] Move windows specific code to its own file --- Lib/test/libregrtest/main.py | 5 +- Lib/test/libregrtest/utils.py | 96 +--------------------------- Lib/test/libregrtest/win_utils.py | 101 ++++++++++++++++++++++++++++++ 3 files changed, 105 insertions(+), 97 deletions(-) create mode 100644 Lib/test/libregrtest/win_utils.py diff --git a/Lib/test/libregrtest/main.py b/Lib/test/libregrtest/main.py index 1bfe72b30414c3..18a49fcbf07438 100644 --- a/Lib/test/libregrtest/main.py +++ b/Lib/test/libregrtest/main.py @@ -18,8 +18,7 @@ INTERRUPTED, CHILD_ERROR, TEST_DID_NOT_RUN, PROGRESS_MIN_TIME, format_test_result) from test.libregrtest.setup import setup_tests -from test.libregrtest.utils import ( - removepy, count, format_duration, printlist, WindowsLoadTracker) +from test.libregrtest.utils import removepy, count, format_duration, printlist from test import support try: import gc @@ -595,6 +594,8 @@ def getloadavg_1m(): return os.getloadavg()[0] self.getloadavg = getloadavg_1m elif sys.platform == 'win32' and (self.ns.slaveargs is None): + from test.libregrtest.win_utils import WindowsLoadTracker + load_tracker = WindowsLoadTracker() self.getloadavg = load_tracker.getloadavg diff --git a/Lib/test/libregrtest/utils.py b/Lib/test/libregrtest/utils.py index 1444603b15a551..d36bf9196626db 100644 --- a/Lib/test/libregrtest/utils.py +++ b/Lib/test/libregrtest/utils.py @@ -1,9 +1,6 @@ -import os +import os.path import math import textwrap -import subprocess -import sys -from test import support def format_duration(seconds): @@ -57,94 +54,3 @@ def printlist(x, width=70, indent=4, file=None): print(textwrap.fill(' '.join(str(elt) for elt in sorted(x)), width, initial_indent=blanks, subsequent_indent=blanks), file=file) - -BUFSIZE = 8192 -LOAD_FACTOR_1 = 0.9200444146293232478931553241 -SAMPLING_INTERVAL = 5 -COUNTER_NAME = r'\System\Processor Queue Length' - -""" -This class asynchronously interacts with the `typeperf` command to read -the system load on Windows. Mulitprocessing and threads can't be used -here because they interfere with the test suite's cases for those -modules. -""" -class WindowsLoadTracker(): - def __init__(self): - self.load = 0.0 - self.start() - - def start(self): - import _winapi - import msvcrt - import uuid - - # Create a named pipe which allows for asynchronous IO in Windows - pipe_name = r'\\.\pipe\typeperf_output_' + str(uuid.uuid4()) - - open_mode = _winapi.PIPE_ACCESS_INBOUND - open_mode |= _winapi.FILE_FLAG_FIRST_PIPE_INSTANCE - open_mode |= _winapi.FILE_FLAG_OVERLAPPED - - # This is the read end of the pipe, where we will be grabbing output - self.pipe = _winapi.CreateNamedPipe( - pipe_name, open_mode, _winapi.PIPE_WAIT, - 1, BUFSIZE, BUFSIZE, _winapi.NMPWAIT_WAIT_FOREVER, _winapi.NULL - ) - # The write end of the pipe which is passed to the created process - pipe_write_end = _winapi.CreateFile( - pipe_name, _winapi.GENERIC_WRITE, 0, _winapi.NULL, - _winapi.OPEN_EXISTING, 0x80000000, _winapi.NULL - ) - # Open up the handle as a python file object so we can pass it to - # subprocess - command_stdout = msvcrt.open_osfhandle(pipe_write_end, 0) - - # Connect to the read end of the pipe in overlap/async mode - overlap = _winapi.ConnectNamedPipe(self.pipe, overlapped=True) - overlap.GetOverlappedResult(True) - - # Spawn off the load monitor - command = ['typeperf', COUNTER_NAME, '-si', str(SAMPLING_INTERVAL)] - self.p = subprocess.Popen(command, stdout=command_stdout, cwd=support.SAVEDCWD) - - # Close our copy of the write end of the pipe - os.close(command_stdout) - - def read_output(self): - import _winapi - - overlapped, _ = _winapi.ReadFile(self.pipe, BUFSIZE, True) - bytes_read, res = overlapped.GetOverlappedResult(False) - if res != 0: - return - - return overlapped.getbuffer().decode() - - def getloadavg(self): - typeperf_output = self.read_output() - # Nothing to update, just return the current load - if not typeperf_output: - return self.load - - # Process the backlog of load values - for line in typeperf_output.splitlines(): - # typeperf outputs in a CSV format like this: - # "07/19/2018 01:32:26.605","3.000000" - toks = line.split(',') - # Ignore blank lines and the initial header - if line.strip() == '' or (COUNTER_NAME in line) or len(toks) != 2: - continue - - load = float(toks[1].replace('"', '')) - # We use an exponentially weighted moving average, imitating the - # load calculation on Unix systems. - # https://en.wikipedia.org/wiki/Load_(computing)#Unix-style_load_calculation - new_load = self.load * LOAD_FACTOR_1 + load * (1.0 - LOAD_FACTOR_1) - self.load = new_load - - return self.load - - def __del__(self): - self.p.kill() - self.p.wait() diff --git a/Lib/test/libregrtest/win_utils.py b/Lib/test/libregrtest/win_utils.py new file mode 100644 index 00000000000000..27ec9c200e3c55 --- /dev/null +++ b/Lib/test/libregrtest/win_utils.py @@ -0,0 +1,101 @@ +import subprocess +import sys +import os +from test import support + + +# Max size of asynchronous reads +BUFSIZE = 8192 +# Exponential damping factor (see below) +LOAD_FACTOR_1 = 0.9200444146293232478931553241 +# Seconds per measurement +SAMPLING_INTERVAL = 5 +COUNTER_NAME = r'\System\Processor Queue Length' + + +class WindowsLoadTracker(): + """ + This class asynchronously interacts with the `typeperf` command to read + the system load on Windows. Mulitprocessing and threads can't be used + here because they interfere with the test suite's cases for those + modules. + """ + + def __init__(self): + self.load = 0.0 + self.start() + + def start(self): + import _winapi + import msvcrt + import uuid + + # Create a named pipe which allows for asynchronous IO in Windows + pipe_name = r'\\.\pipe\typeperf_output_' + str(uuid.uuid4()) + + open_mode = _winapi.PIPE_ACCESS_INBOUND + open_mode |= _winapi.FILE_FLAG_FIRST_PIPE_INSTANCE + open_mode |= _winapi.FILE_FLAG_OVERLAPPED + + # This is the read end of the pipe, where we will be grabbing output + self.pipe = _winapi.CreateNamedPipe( + pipe_name, open_mode, _winapi.PIPE_WAIT, + 1, BUFSIZE, BUFSIZE, _winapi.NMPWAIT_WAIT_FOREVER, _winapi.NULL + ) + # The write end of the pipe which is passed to the created process + pipe_write_end = _winapi.CreateFile( + pipe_name, _winapi.GENERIC_WRITE, 0, _winapi.NULL, + _winapi.OPEN_EXISTING, 0, _winapi.NULL + ) + # Open up the handle as a python file object so we can pass it to + # subprocess + command_stdout = msvcrt.open_osfhandle(pipe_write_end, 0) + + # Connect to the read end of the pipe in overlap/async mode + overlap = _winapi.ConnectNamedPipe(self.pipe, overlapped=True) + overlap.GetOverlappedResult(True) + + # Spawn off the load monitor + command = ['typeperf', COUNTER_NAME, '-si', str(SAMPLING_INTERVAL)] + self.p = subprocess.Popen(command, stdout=command_stdout, cwd=support.SAVEDCWD) + + # Close our copy of the write end of the pipe + os.close(command_stdout) + + def __del__(self): + self.p.kill() + self.p.wait() + + def read_output(self): + import _winapi + + overlapped, _ = _winapi.ReadFile(self.pipe, BUFSIZE, True) + bytes_read, res = overlapped.GetOverlappedResult(False) + if res != 0: + return + + return overlapped.getbuffer().decode() + + def getloadavg(self): + typeperf_output = self.read_output() + # Nothing to update, just return the current load + if not typeperf_output: + return self.load + + # Process the backlog of load values + for line in typeperf_output.splitlines(): + # typeperf outputs in a CSV format like this: + # "07/19/2018 01:32:26.605","3.000000" + toks = line.split(',') + # Ignore blank lines and the initial header + if line.strip() == '' or (COUNTER_NAME in line) or len(toks) != 2: + continue + + load = float(toks[1].replace('"', '')) + # We use an exponentially weighted moving average, imitating the + # load calculation on Unix systems. + # https://en.wikipedia.org/wiki/Load_(computing)#Unix-style_load_calculation + new_load = self.load * LOAD_FACTOR_1 + load * (1.0 - LOAD_FACTOR_1) + self.load = new_load + + return self.load From 5c0e27553edca6252b35e8eda0e0655ab910e08e Mon Sep 17 00:00:00 2001 From: Ammar Askar Date: Wed, 25 Jul 2018 01:01:43 -0700 Subject: [PATCH 3/4] Move imports to top of file --- Lib/test/libregrtest/win_utils.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/Lib/test/libregrtest/win_utils.py b/Lib/test/libregrtest/win_utils.py index 27ec9c200e3c55..2e6492289e15dc 100644 --- a/Lib/test/libregrtest/win_utils.py +++ b/Lib/test/libregrtest/win_utils.py @@ -1,6 +1,9 @@ import subprocess import sys import os +import _winapi +import msvcrt +import uuid from test import support @@ -26,10 +29,6 @@ def __init__(self): self.start() def start(self): - import _winapi - import msvcrt - import uuid - # Create a named pipe which allows for asynchronous IO in Windows pipe_name = r'\\.\pipe\typeperf_output_' + str(uuid.uuid4()) From a8df864ce11df46a8632da9cfa55e3d53db1d856 Mon Sep 17 00:00:00 2001 From: Ammar Askar Date: Sat, 9 Feb 2019 17:10:50 -0500 Subject: [PATCH 4/4] Add comment explaining check in libregrtest --- Lib/test/libregrtest/main.py | 26 +++++++++++++------------- 1 file changed, 13 insertions(+), 13 deletions(-) diff --git a/Lib/test/libregrtest/main.py b/Lib/test/libregrtest/main.py index 18a49fcbf07438..18ef6d0609cd63 100644 --- a/Lib/test/libregrtest/main.py +++ b/Lib/test/libregrtest/main.py @@ -586,19 +586,6 @@ def main(self, tests=None, **kwargs): self._main(tests, kwargs) def _main(self, tests, kwargs): - self.ns = self.parse_args(kwargs) - - self.getloadavg = None - if hasattr(os, 'getloadavg'): - def getloadavg_1m(): - return os.getloadavg()[0] - self.getloadavg = getloadavg_1m - elif sys.platform == 'win32' and (self.ns.slaveargs is None): - from test.libregrtest.win_utils import WindowsLoadTracker - - load_tracker = WindowsLoadTracker() - self.getloadavg = load_tracker.getloadavg - if self.ns.huntrleaks: warmup, repetitions, _ = self.ns.huntrleaks if warmup < 1 or repetitions < 1: @@ -629,6 +616,19 @@ def getloadavg_1m(): self.list_cases() sys.exit(0) + self.getloadavg = None + # If we're on windows and this is the parent runner (not a worker), + # report the load average. + if hasattr(os, 'getloadavg'): + def getloadavg_1m(): + return os.getloadavg()[0] + self.getloadavg = getloadavg_1m + elif sys.platform == 'win32' and (self.ns.worker_args is None): + from test.libregrtest.win_utils import WindowsLoadTracker + + load_tracker = WindowsLoadTracker() + self.getloadavg = load_tracker.getloadavg + self.run_tests() self.display_result()