[Piglit] [PATCH v3 4/4] framework/test/base.py: use subprocess32 for timeouts.

Thomas Wood thomas.wood at intel.com
Tue Dec 1 02:25:59 PST 2015


On 30 November 2015 at 18:34, Dylan Baker <baker.dylan.c at gmail.com> wrote:
> On Fri, Nov 27, 2015 at 12:04:34PM +0000, Thomas Wood wrote:
>> On 12 November 2015 at 22:52,  <baker.dylan.c at gmail.com> wrote:
>> > From: Dylan Baker <baker.dylan.c at gmail.com>
>> >
>> > Subprocess32 provides a backport of (ironically) python 3.3's subprocess
>> > module, which has a timeout parameter. When the timeout runs out then an
>> > exception is raised, and when that exception is caught we can kill the
>> > process.
>> >
>> > This is fairly similar to the way the current timeout mechanism works,
>> > except that the current mechanism is not thread safe. Since one of the
>> > major features of piglit is that it offer's processes isolated
>> > concurrency of tests, it makes sense to make the effort to provide a
>> > timeout mechanism that can be used outside of IGT, which is a
>> > non-concurrent test suite.
>> >
>> > This patch look pretty substantial. It's not as big as it looks, since
>> > it adds some fairly big tests.
>> >
>> > v3: - Wait before terminating process
>> >     - use os.getgrpid instead of os.getsid
>>
>> os.getpgid?
>>
>>
>> >     - use subprocess32 for accel profile in tox
>> >     - Add warning when using the dummy version of TimeoutMixin
>>
>> TimeoutExpired?
>>
>
> Both of these fixed locally
>
>>
>> >     - mark more unittests as slow and add timeouts to them
>> >     - Remove the use of a Mixin, timeouts are an important enough
>> >       feature every test suite should have the option to use them, and
>> >       by not using a mixin there is no need for the ugly interface.
>> >
>> > Signed-off-by: Dylan Baker <dylanx.c.baker at intel.com>
>> > ---
>> >  framework/results.py          |   2 +
>> >  framework/test/base.py        | 130 ++++++++++++++++--------------------------
>> >  framework/tests/base_tests.py | 117 ++++++++++++++++++++++++++++++++++++-
>> >  tox.ini                       |  10 ++--
>> >  4 files changed, 171 insertions(+), 88 deletions(-)
>> >
>> > diff --git a/framework/results.py b/framework/results.py
>> > index eeffcb7..ee41126 100644
>> > --- a/framework/results.py
>> > +++ b/framework/results.py
>> > @@ -96,6 +96,8 @@ class StringDescriptor(object):  # pylint: disable=too-few-public-methods
>> >              setattr(instance, self.__name, value.decode('utf-8', 'replace'))
>> >          elif isinstance(value, unicode):
>> >              setattr(instance, self.__name, value)
>> > +        elif value is None:
>> > +            setattr(instance, self.__name, u'')
>>
>> Unrelated change?
>>
>
> I'll have to look to be sure, but I think this actually was required in
> the timeout case.
>
>>
>> >          else:
>> >              raise TypeError('{} attribute must be a str or unicode instance, '
>> >                              'but was {}.'.format(self.__name, type(value)))
>> > diff --git a/framework/test/base.py b/framework/test/base.py
>> > index 7c7c410..d1b0c35 100644
>> > --- a/framework/test/base.py
>> > +++ b/framework/test/base.py
>> > @@ -25,16 +25,36 @@
>> >  from __future__ import print_function, absolute_import
>> >  import errno
>> >  import os
>> > -import subprocess
>> >  import time
>> >  import sys
>> >  import traceback
>> > -from datetime import datetime
>> > -import threading
>> > -import signal
>> >  import itertools
>> >  import abc
>> >  import copy
>> > +import signal
>> > +import warnings
>> > +
>> > +try:
>> > +    import subprocess32 as subprocess
>> > +    _EXTRA_POPEN_ARGS = {'start_new_session': True}
>> > +except ImportError:
>> > +    import subprocess
>> > +
>> > +    class TimeoutExpired(Exception):
>> > +        pass
>> > +
>> > +    class Popen(subprocess.Popen):
>> > +        """Sublcass of Popen that accepts and ignores a timeout argument."""
>> > +        def communicate(self, *args, **kwargs):
>> > +            if 'timeout' in kwargs:
>> > +                del kwargs['timeout']
>> > +            return super(Popen, self).communicate(*args, **kwargs)
>> > +
>> > +    subprocess.TimeoutExpired = TimeoutExpired
>> > +    subprocess.Popen = Popen
>> > +    _EXTRA_POPEN_ARGS = {}
>> > +
>> > +    warnings.warn('Timeouts are not available')
>> >
>> >  from framework import exceptions, options
>> >  from framework.results import TestResult
>> > @@ -61,56 +81,6 @@ class TestRunError(exceptions.PiglitException):
>> >          self.status = status
>> >
>> >
>> > -class ProcessTimeout(threading.Thread):
>> > -    """ Timeout class for test processes
>> > -
>> > -    This class is for terminating tests that run for longer than a certain
>> > -    amount of time. Create an instance by passing it a timeout in seconds
>> > -    and the Popen object that is running your test. Then call the start
>> > -    method (inherited from Thread) to start the timer. The Popen object is
>> > -    killed if the timeout is reached and it has not completed. Wait for the
>> > -    outcome by calling the join() method from the parent.
>> > -
>> > -    """
>> > -
>> > -    def __init__(self, timeout, proc):
>> > -        threading.Thread.__init__(self)
>> > -        self.proc = proc
>> > -        self.timeout = timeout
>> > -        self.status = 0
>> > -
>> > -    def run(self):
>> > -        start_time = datetime.now()
>> > -        delta = 0
>> > -
>> > -        # poll() returns the returncode attribute, which is either the return
>> > -        # code of the child process (which could be zero), or None if the
>> > -        # process has not yet terminated.
>> > -
>> > -        while delta < self.timeout and self.proc.poll() is None:
>> > -            time.sleep(1)
>> > -            delta = (datetime.now() - start_time).total_seconds()
>> > -
>> > -        # if the test is not finished after timeout, first try to terminate it
>> > -        # and if that fails, send SIGKILL to all processes in the test's
>> > -        # process group
>> > -
>> > -        if self.proc.poll() is None:
>> > -            self.status = 1
>> > -            self.proc.terminate()
>> > -            time.sleep(5)
>> > -
>> > -        if self.proc.poll() is None:
>> > -            self.status = 2
>> > -            if hasattr(os, 'killpg'):
>> > -                os.killpg(self.proc.pid, signal.SIGKILL)
>> > -            self.proc.wait()
>> > -
>> > -    def join(self):
>> > -        threading.Thread.join(self)
>> > -        return self.status
>> > -
>> > -
>> >  def _is_crash_returncode(returncode):
>> >      """Determine whether the given process return code correspond to a
>> >      crash.
>> > @@ -146,10 +116,10 @@ class Test(object):
>> >      """
>> >      __metaclass__ = abc.ABCMeta
>> >      __slots__ = ['run_concurrent', 'env', 'result', 'cwd', '_command',
>> > -                 '__proc_timeout']
>> > +                 'timeout']
>> >      timeout = 0
>> >
>> > -    def __init__(self, command, run_concurrent=False):
>> > +    def __init__(self, command, run_concurrent=False, timeout=None):
>> >          assert isinstance(command, list), command
>> >
>> >          self.run_concurrent = run_concurrent
>> > @@ -157,7 +127,9 @@ class Test(object):
>> >          self.env = {}
>> >          self.result = TestResult()
>> >          self.cwd = None
>> > -        self.__proc_timeout = None
>> > +        if timeout is not None:
>> > +            assert isinstance(timeout, int)
>> > +            self.timeout = timeout
>> >
>> >      def execute(self, path, log, dmesg):
>> >          """ Run a test
>> > @@ -203,11 +175,7 @@ class Test(object):
>> >          """Convert the raw output of the test into a form piglit understands.
>> >          """
>> >          if _is_crash_returncode(self.result.returncode):
>> > -            # check if the process was terminated by the timeout
>> > -            if self.timeout > 0 and self.__proc_timeout.join() > 0:
>> > -                self.result.result = 'timeout'
>> > -            else:
>> > -                self.result.result = 'crash'
>> > +            self.result.result = 'crash'
>> >          elif self.result.returncode != 0 and self.result.result == 'pass':
>> >              self.result.result = 'warn'
>> >
>> > @@ -253,10 +221,6 @@ class Test(object):
>> >          """
>> >          pass
>> >
>> > -    def __set_process_group(self):
>> > -        if hasattr(os, 'setpgrp'):
>> > -            os.setpgrp()
>> > -
>> >      def _run_command(self):
>> >          """ Run the test command and get the result
>> >
>> > @@ -283,29 +247,17 @@ class Test(object):
>> >                                            self.env.iteritems()):
>> >              fullenv[key] = str(value)
>> >
>> > -        # preexec_fn is not supported on Windows platforms
>> > -        if sys.platform == 'win32':
>> > -            preexec_fn = None
>> > -        else:
>> > -            preexec_fn = self.__set_process_group
>> >
>> >          try:
>> >              proc = subprocess.Popen(self.command,
>> > +                                    env=fullenv,
>> >                                      stdout=subprocess.PIPE,
>> >                                      stderr=subprocess.PIPE,
>> >                                      cwd=self.cwd,
>> > -                                    env=fullenv,
>>
>> Unrelated change?
>>
>>
>
> Yup, rebasing artifact. Fixed locally.
>
>> >                                      universal_newlines=True,
>> > -                                    preexec_fn=preexec_fn)
>> > -            # create a ProcessTimeout object to watch out for test hang if the
>> > -            # process is still going after the timeout, then it will be killed
>> > -            # forcing the communicate function (which is a blocking call) to
>> > -            # return
>> > -            if self.timeout > 0:
>> > -                self.__proc_timeout = ProcessTimeout(self.timeout, proc)
>> > -                self.__proc_timeout.start()
>> > -
>> > -            out, err = proc.communicate()
>> > +                                    **_EXTRA_POPEN_ARGS)
>> > +
>> > +            out, err = proc.communicate(timeout=self.timeout)
>> >              returncode = proc.returncode
>> >          except OSError as e:
>> >              # Different sets of tests get built under different build
>> > @@ -315,6 +267,20 @@ class Test(object):
>> >                  raise TestRunError("Test executable not found.\n", 'skip')
>> >              else:
>> >                  raise e
>> > +        except subprocess.TimeoutExpired:
>> > +            if proc.poll() is None:
>> > +                time.sleep(3)
>>
>> The terminate signal can be sent straight away if a timeout has occurred.
>
> fixed locally
>
>>
>>
>> > +                proc.terminate()
>> > +
>> > +            if proc.poll() is None:
>> > +                time.sleep(3)
>> > +                os.killpg(os.getpgid(proc.pid), signal.SIGKILL)
>> > +
>> > +            self.result.out, self.result.err = proc.communicate()
>> > +
>> > +            raise TestRunError(
>> > +                'Test run time exceeded timeout out {}\n'.format(self.timeout),
>>
>> "... timeout out {}\n" should perhaps be something like "... timeout
>> value ({} seconds)\n"?
>
> Your way sounds better. Also changed locally.
>
>>
>>
>> > +                'timeout')
>> >
>> >          # The setter handles the bytes/unicode conversion
>> >          self.result.out = out
>> > diff --git a/framework/tests/base_tests.py b/framework/tests/base_tests.py
>> > index 1b5ed9e..b1df9d4 100644
>> > --- a/framework/tests/base_tests.py
>> > +++ b/framework/tests/base_tests.py
>> > @@ -21,11 +21,19 @@
>> >  """ Tests for the exectest module """
>> >
>> >  from __future__ import print_function, absolute_import
>> > +import tempfile
>> > +import textwrap
>> > +import os
>> >
>> >  import mock
>> >  import nose.tools as nt
>> >  from nose.plugins.attrib import attr
>> >
>> > +try:
>> > +    import psutil
>> > +except ImportError:
>> > +    pass
>> > +
>> >  import framework.tests.utils as utils
>> >  from framework.test.base import (
>> >      Test, WindowResizeMixin, ValgrindMixin, TestRunError
>> > @@ -68,8 +76,111 @@ def test_run_return_early():
>> >
>> >
>> >  @attr('slow')
>> > + at nt.timed(8)
>> > +def test_timeout_kill_children():
>> > +    """test.base.Test: kill children if terminate fails
>> > +
>> > +    This creates a process that forks multiple times, and then checks that the
>> > +    children have been killed.
>> > +
>> > +    This test could leave processes running if it fails.
>> > +
>> > +    """
>> > +    utils.module_check('subprocess32')
>> > +    utils.module_check('psutil')
>> > +
>> > +    import subprocess32  # pylint: disable=import-error
>> > +
>> > +    class PopenProxy(object):
>> > +        """An object that proxies Popen, and saves the Popen instance as an
>> > +        attribute.
>> > +
>> > +        This is useful for testing the Popen instance.
>> > +
>> > +        """
>> > +        def __init__(self):
>> > +            self.popen = None
>> > +
>> > +        def __call__(self, *args, **kwargs):
>> > +            self.popen = subprocess32.Popen(*args, **kwargs)
>> > +
>> > +            # if commuincate cis called successfully then the proc will be
>> > +            # reset to None, whic will make the test fail.
>> > +            self.popen.communicate = mock.Mock(return_value=('out', 'err'))
>> > +
>> > +            return self.popen
>> > +
>> > +    with tempfile.NamedTemporaryFile() as f:
>> > +        # Create a file that will be executed as a python script
>> > +        # Create a process with two subproccesses (not threads) that will run
>> > +        # for a long time.
>> > +        f.write(textwrap.dedent("""\
>> > +            import time
>> > +            from multiprocessing import Process
>> > +
>> > +            def p():
>> > +                for _ in range(100):
>> > +                    time.sleep(1)
>> > +
>> > +            a = Process(target=p)
>> > +            b = Process(target=p)
>> > +            a.start()
>> > +            b.start()
>> > +            a.join()
>> > +            b.join()
>> > +        """))
>> > +        f.seek(0)  # we'll need to read the file back
>> > +
>> > +        # Create an object that will return a popen object, but also store it
>> > +        # so we can access it later
>> > +        proxy = PopenProxy()
>> > +
>> > +        test = TimeoutTest(['python', f.name])
>> > +        test.timeout = 1
>> > +
>> > +        # mock out subprocess.Popen with our proxy object
>> > +        with mock.patch('framework.test.base.subprocess') as mock_subp:
>> > +            mock_subp.Popen = proxy
>> > +            mock_subp.TimeoutExpired = subprocess32.TimeoutExpired
>> > +            test.run()
>> > +
>> > +        # Check to see if the Popen has children, even after it should have
>> > +        # recieved a TimeoutExpired.
>> > +        proc = psutil.Process(os.getsid(proxy.popen.pid))
>> > +        children = proc.children(recursive=True)
>> > +
>> > +        if children:
>> > +            # If there are still running children attempt to clean them up,
>> > +            # starting with the final generation and working back to the first
>> > +            for child in reversed(children):
>> > +                child.kill()
>> > +
>> > +            raise utils.TestFailure(
>> > +                'Test process had children when it should not')
>> > +
>> > +
>> > + at attr('slow')
>> > + at nt.timed(8)
>> >  def test_timeout():
>> > -    """test.base.Test.run(): Sets status to 'timeout' when timeout exceeded"""
>> > +    """test.base.TimeoutMixin: Stops running test after timeout expires
>>
>> Perhaps tests.base.TimeoutExpired rather than tests.base.TimeoutMixin
>> here and in the following tests?
>>
>>
>
> I would have set them to tests.base.Test like the previous test, do you
> prefer TimeoutExpired?

That's fine since it removes any mention of TimeoutMixin, which no
longer exists.


>
>> > +
>> > +    This is a little bit of extra time here, but without a sleep of 60 seconds
>> > +    if the test runs 5 seconds it's run too long
>> > +
>> > +    """
>> > +    utils.module_check('subprocess32')
>> > +    utils.binary_check('sleep', 1)
>> > +
>> > +    test = TimeoutTest(['sleep', '60'])
>> > +    test.timeout = 1
>> > +    test.run()
>> > +
>> > +
>> > + at attr('slow')
>> > + at nt.timed(8)
>> > +def test_timeout_timeout():
>> > +    """test.base.TimeoutMixin: Sets status to 'timeout' when timeout exceeded"""
>> > +    utils.module_check('subprocess32')
>> >      utils.binary_check('sleep', 1)
>> >
>> >      test = TimeoutTest(['sleep', '60'])
>> > @@ -78,9 +189,11 @@ def test_timeout():
>> >      nt.eq_(test.result.result, 'timeout')
>> >
>> >
>> > + at nt.timed(2)
>> >  def test_timeout_pass():
>> > -    """test.base.Test.run(): Doesn't change status when timeout not exceeded
>> > +    """test.base.TimeoutMixin: Doesn't change status when timeout not exceeded
>> >      """
>> > +    utils.module_check('subprocess32')
>> >      utils.binary_check('true')
>> >
>> >      test = TimeoutTest(['true'])
>> > diff --git a/tox.ini b/tox.ini
>> > index d1f1f16..3dd1851 100644
>> > --- a/tox.ini
>> > +++ b/tox.ini
>> > @@ -13,20 +13,22 @@ commands = nosetests generated_tests/test_generators.py
>> >  [testenv:py27-noaccel]
>> >  passenv=HOME
>> >  deps =
>> > -    mako
>> > -    nose
>> >      coverage
>> > +    mako
>> >      mock
>> > +    nose
>> >  commands = nosetests framework/tests --attr="!privileged" --with-cover --cover-package=framework --cover-tests
>> >
>> >  [testenv:py27-accel]
>> >  passenv=HOME
>> >  deps =
>> > -    mako
>> > -    nose
>> >      coverage
>> > +    mako
>> >      mock
>> > +    nose
>> > +    psutil
>> >      simplejson
>> >      lxml
>> >      backports.lzma
>> > +    subprocess32
>> >  commands = nosetests framework/tests --attr="!privileged" --with-cover --cover-package=framework --cover-tests
>> > --
>> > 2.6.2
>> >
>> > _______________________________________________
>> > Piglit mailing list
>> > Piglit at lists.freedesktop.org
>> > http://lists.freedesktop.org/mailman/listinfo/piglit
>
>
> I'll look into whether that None case is necessary. Do you want to see a
> v5?

I think it will be v4? The patch didn't apply cleanly to master so it
would be good to have a new version to test.


>
> Dylan
>
> _______________________________________________
> Piglit mailing list
> Piglit at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/piglit
>


More information about the Piglit mailing list