Merge lp:~thomir-deactivatedaccount/autopilot/1.3-fix-scan-speed into lp:autopilot/1.3

[Thomi Richards]

Performance improvments for launching and closing applications under test with autopilot.

Merge performance improvments for autopilot.

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:335
http://jenkins.qa.ubuntu.com/job/autopilot-1.3-ci/18/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-amd64-ci/18/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-armhf-ci/18/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-i386-ci/2/console

Click here to trigger a rebuild:
http://s-jenkins:8080/job/autopilot-1.3-ci/18/rebuild

review: Needs Fixing (continuous-integration)

[lp:~thomir-deactivatedaccount/autopilot/1.3-fix-scan-speed]

336. By Thomi Richards on 2013-09-17

Fix PEP8 issues.

[Martin Pitt (pitti)]

I'm a bit sceptical that this is going to be long enough for ARM:

+ with maximum_runtime(5.0):

Also, I don't believe the rather complicated retry loop in _kill_process() isn't necessary, as in both py2 and py3 communicate() is documented to actually wait for the process to terminate.

Otherwise, LGTM. Still waiting for CI tests.

review: Approve

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:336
http://jenkins.qa.ubuntu.com/job/autopilot-1.3-ci/19/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-amd64-ci/19
    SUCCESS: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-armhf-ci/19
    SUCCESS: http://jenkins.qa.ubuntu.com/job/autopilot-1.3-saucy-i386-ci/3

Click here to trigger a rebuild:
http://s-jenkins:8080/job/autopilot-1.3-ci/19/rebuild

review: Approve (continuous-integration)

=== modified file 'autopilot/introspection/__init__.py'
--- autopilot/introspection/__init__.py	2013-09-11 16:16:00 +0000
+++ autopilot/introspection/__init__.py	2013-09-17 18:50:22 +0000
@@ -33,6 +33,7 @@
 from time import sleep
 from functools import partial
 import os
+import psutil
 
 from autopilot.introspection.backends import DBusAddress
 from autopilot.introspection.constants import (
@@ -239,8 +240,10 @@
     :param emulator_base: The custom emulator to create the resulting proxy
         object with.
 
-    :raises: RuntimeError if no search criteria match.
-    :raises: RuntimeError if the search criteria results in many matches.
+    :raises ProcessSearchError: if no search criteria match.
+    :raises RuntimeError: if the search criteria results in many matches.
+    :raises RuntimeError: if both ``process`` and ``pid`` are supplied, but
+        ``process.pid != pid``.
 
     """
     if process is not None:
@@ -282,6 +285,7 @@
     _reset_known_connection_list()
 
     for i in range(10):
+        _get_child_pids.reset_cache()
         if process is not None and not _process_is_running(process):
             return_code = process.poll()
             raise ProcessSearchError(
@@ -430,26 +434,32 @@
     obj_iface.GetVersion()
 
 
-def _get_child_pids(pid):
+class _cached_get_child_pids(object):
     """Get a list of all child process Ids, for the given parent.
 
+    Since we call this often, and it's a very expensive call, we optimise this
+    such that the return value will be cached for each scan through the dbus
+    bus.
+
+    Calling reset_cache() at the end of each dbus scan will ensure that you get
+    fresh values on the next call.
     """
-    def get_children(pid):
-        command = ['ps', '-o', 'pid', '--ppid', str(pid), '--noheaders']
-        try:
-            raw_output = subprocess.check_output(command)
-        except subprocess.CalledProcessError:
-            return []
-        return [int(p) for p in raw_output.split()]
-
-    result = []
-    data = get_children(pid)
-    while data:
-        pid = data.pop(0)
-        result.append(pid)
-        data.extend(get_children(pid))
-
-    return result
+
+    def __init__(self):
+        self._cached_result = None
+
+    def __call__(self, pid):
+        if self._cached_result is None:
+            self._cached_result = [
+                p.pid for p in psutil.Process(pid).get_children(recursive=True)
+            ]
+        return self._cached_result
+
+    def reset_cache(self):
+        self._cached_result = None
+
+
+_get_child_pids = _cached_get_child_pids()
 
 
 def _make_proxy_object(data_source, emulator_base):

=== modified file 'autopilot/testcase.py'
--- autopilot/testcase.py	2013-09-13 18:52:37 +0000
+++ autopilot/testcase.py	2013-09-17 18:50:22 +0000
@@ -345,7 +345,7 @@
                     if app_id in line and "start/running" in line:
                         target_pid = int(line.split()[-1])
 
-                        self.addCleanup(self._kill_process, target_pid)
+                        self.addCleanup(self._kill_pid, target_pid)
                         logger.info(
                             "Click package %s has been launched with PID %d",
                             app_id,
@@ -525,16 +525,11 @@
         # default implementation is in autopilot.introspection:
         return get_application_launcher(app_path)
 
-    def _attach_process_logs(self, process):
-        stdout, stderr = process.communicate()
-        return_code = process.returncode
-        self.addDetail('process-return-code', text_content(str(return_code)))
-        self.addDetail('process-stdout', text_content(stdout))
-        self.addDetail('process-stderr', text_content(stderr))
-
-    def _kill_process(self, pid):
+    def _kill_pid(self, pid):
+        """Kill the process with the specified pid."""
         logger.info("waiting for process to exit.")
         try:
+            logger.info("Killing process %d", pid)
             os.killpg(pid, signal.SIGTERM)
         except OSError:
             logger.info("Appears process has already exited.")
@@ -548,10 +543,39 @@
                 )
                 os.killpg(pid, signal.SIGKILL)
             sleep(1)
+        return stdout, stderr, process.returncode
+
+    def _kill_process(self, process):
+        """Kill the process, and return the stdout, stderr and return code."""
+        stdout = ""
+        stderr = ""
+        return_code = -1
+        logger.info("waiting for process to exit.")
+        try:
+            logger.info("Killing process %d", process.pid)
+            os.killpg(process.pid, signal.SIGTERM)
+        except OSError:
+            logger.info("Appears process has already exited.")
+        for i in range(10):
+            tmp_out, tmp_err = process.communicate()
+            stdout += tmp_out
+            stderr += tmp_err
+            if not _is_process_running(process.pid):
+                break
+            if i == 9:
+                logger.info(
+                    "Killing process group, since it hasn't exited after "
+                    "10 seconds."
+                )
+                os.killpg(process.pid, signal.SIGKILL)
+            sleep(1)
+        return stdout, stderr, process.returncode
 
     def _kill_process_and_attach_logs(self, process):
-        self._kill_process(process.pid)
-        self._attach_process_logs(process)
+        stdout, stderr, return_code = self._kill_process(process)
+        self.addDetail('process-return-code', text_content(str(return_code)))
+        self.addDetail('process-stdout', text_content(stdout))
+        self.addDetail('process-stderr', text_content(stderr))
 
 
 def _is_process_running(pid):

=== modified file 'autopilot/tests/functional/__init__.py'
--- autopilot/tests/functional/__init__.py	2013-05-05 02:39:14 +0000
+++ autopilot/tests/functional/__init__.py	2013-09-17 18:50:22 +0000
@@ -16,3 +16,140 @@
 # You should have received a copy of the GNU General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
+
+
+from __future__ import absolute_import
+
+from codecs import open
+import os
+import os.path
+import logging
+from shutil import rmtree
+import subprocess
+from tempfile import mkdtemp
+from testtools.content import Content, text_content
+from testtools.content_type import ContentType
+
+from autopilot.testcase import AutopilotTestCase
+
+
+def remove_if_exists(path):
+    if os.path.exists(path):
+        if os.path.isdir(path):
+            rmtree(path)
+        else:
+            os.remove(path)
+
+
+logger = logging.getLogger(__name__)
+
+
+class AutopilotRunTestBase(AutopilotTestCase):
+
+    """The base class for the autopilot functional tests."""
+
+    def setUp(self):
+        super(AutopilotRunTestBase, self).setUp()
+        self.base_path = self.create_empty_test_module()
+
+    def create_empty_test_module(self):
+        """Create an empty temp directory, with an empty test directory inside
+        it.
+
+        This method handles cleaning up the directory once the test completes.
+
+        Returns the full path to the temp directory.
+
+        """
+
+        # create the base directory:
+        base_path = mkdtemp()
+        self.addDetail('base path', text_content(base_path))
+        self.addCleanup(rmtree, base_path)
+
+        # create the tests directory:
+        os.mkdir(
+            os.path.join(base_path, 'tests')
+        )
+
+        # make tests importable:
+        open(
+            os.path.join(
+                base_path,
+                'tests',
+                '__init__.py'),
+            'w').write('# Auto-generated file.')
+        return base_path
+
+    def run_autopilot(self, arguments):
+        ap_base_path = os.path.abspath(
+            os.path.join(
+                os.path.dirname(__file__),
+                '..',
+                '..',
+                '..'
+            )
+        )
+
+        environment_patch = dict(DISPLAY=':0')
+        if not os.getcwd().startswith('/usr/'):
+            environment_patch['PYTHONPATH'] = ap_base_path
+        bin_path = os.path.join(ap_base_path, 'bin', 'autopilot')
+        if not os.path.exists(bin_path):
+            bin_path = subprocess.check_output(['which', 'autopilot']).strip()
+            logger.info(
+                "Not running from source, setting bin_path to %s", bin_path)
+
+        environ = os.environ
+        environ.update(environment_patch)
+
+        logger.info("Starting autopilot command with:")
+        logger.info("Autopilot command = %s", bin_path)
+        logger.info("Arguments = %s", arguments)
+        logger.info("CWD = %r", self.base_path)
+
+        arg = [bin_path]
+        arg.extend(arguments)
+        process = subprocess.Popen(
+            arg,
+            cwd=self.base_path,
+            env=environ,
+            stdout=subprocess.PIPE,
+            stderr=subprocess.PIPE,
+        )
+
+        stdout, stderr = process.communicate()
+        retcode = process.poll()
+
+        self.addDetail('retcode', text_content(str(retcode)))
+        self.addDetail(
+            'stdout',
+            Content(
+                ContentType('text', 'plain', {'charset': 'iso-8859-1'}),
+                lambda: [stdout]
+            )
+        )
+        self.addDetail(
+            'stderr',
+            Content(
+                ContentType('text', 'plain', {'charset': 'iso-8859-1'}),
+                lambda: [stderr]
+            )
+        )
+
+        return (retcode, stdout, stderr)
+
+    def create_test_file(self, name, contents):
+        """Create a test file with the given name and contents.
+
+        'name' must end in '.py' if it is to be importable.
+        'contents' must be valid python code.
+
+        """
+        open(
+            os.path.join(
+                self.base_path,
+                'tests',
+                name),
+            'w',
+            encoding='utf8').write(contents)

=== modified file 'autopilot/tests/functional/test_autopilot_functional.py'
--- autopilot/tests/functional/test_autopilot_functional.py	2013-09-13 15:00:35 +0000
+++ autopilot/tests/functional/test_autopilot_functional.py	2013-09-17 18:50:22 +0000
@@ -23,142 +23,16 @@
 from codecs import open
 import os
 import os.path
-import logging
-from shutil import rmtree
-import subprocess
-from tempfile import mktemp, mkdtemp
-from testtools.content import Content, text_content
-from testtools.content_type import ContentType
+from tempfile import mktemp
 from testtools.matchers import Contains, Equals, MatchesRegex, Not
 from textwrap import dedent
 import re
 
 from autopilot.testcase import AutopilotTestCase
-
-
-def remove_if_exists(path):
-    if os.path.exists(path):
-        if os.path.isdir(path):
-            rmtree(path)
-        else:
-            os.remove(path)
-
-
-logger = logging.getLogger(__name__)
-
-
-class AutopilotFunctionalTestsBase(AutopilotTestCase):
-
-    """The base class for the autopilot functional tests."""
-
-    def setUp(self):
-        super(AutopilotFunctionalTestsBase, self).setUp()
-        self.base_path = self.create_empty_test_module()
-
-    def create_empty_test_module(self):
-        """Create an empty temp directory, with an empty test directory inside
-        it.
-
-        This method handles cleaning up the directory once the test completes.
-
-        Returns the full path to the temp directory.
-
-        """
-
-        # create the base directory:
-        base_path = mkdtemp()
-        self.addDetail('base path', text_content(base_path))
-        self.addCleanup(rmtree, base_path)
-
-        # create the tests directory:
-        os.mkdir(
-            os.path.join(base_path, 'tests')
-        )
-
-        # make tests importable:
-        open(
-            os.path.join(
-                base_path,
-                'tests',
-                '__init__.py'),
-            'w').write('# Auto-generated file.')
-        return base_path
-
-    def run_autopilot(self, arguments):
-        ap_base_path = os.path.abspath(
-            os.path.join(
-                os.path.dirname(__file__),
-                '..',
-                '..',
-                '..'
-            )
-        )
-
-        environment_patch = dict(DISPLAY=':0')
-        if not os.getcwd().startswith('/usr/'):
-            environment_patch['PYTHONPATH'] = ap_base_path
-        bin_path = os.path.join(ap_base_path, 'bin', 'autopilot')
-        if not os.path.exists(bin_path):
-            bin_path = subprocess.check_output(['which', 'autopilot']).strip()
-            logger.info(
-                "Not running from source, setting bin_path to %s", bin_path)
-
-        environ = os.environ
-        environ.update(environment_patch)
-
-        logger.info("Starting autopilot command with:")
-        logger.info("Autopilot command = %s", bin_path)
-        logger.info("Arguments = %s", arguments)
-        logger.info("CWD = %r", self.base_path)
-
-        arg = [bin_path]
-        arg.extend(arguments)
-        process = subprocess.Popen(
-            arg,
-            cwd=self.base_path,
-            env=environ,
-            stdout=subprocess.PIPE,
-            stderr=subprocess.PIPE,
-        )
-
-        stdout, stderr = process.communicate()
-        retcode = process.poll()
-
-        self.addDetail('retcode', text_content(str(retcode)))
-        self.addDetail(
-            'stdout',
-            Content(
-                ContentType('text', 'plain', {'charset': 'iso-8859-1'}),
-                lambda: [stdout]
-            )
-        )
-        self.addDetail(
-            'stderr',
-            Content(
-                ContentType('text', 'plain', {'charset': 'iso-8859-1'}),
-                lambda: [stderr]
-            )
-        )
-
-        return (retcode, stdout, stderr)
-
-    def create_test_file(self, name, contents):
-        """Create a test file with the given name and contents.
-
-        'name' must end in '.py' if it is to be importable.
-        'contents' must be valid python code.
-
-        """
-        open(
-            os.path.join(
-                self.base_path,
-                'tests',
-                name),
-            'w',
-            encoding='utf8').write(contents)
-
-
-class AutopilotFunctionalTests(AutopilotFunctionalTestsBase):
+from autopilot.tests.functional import AutopilotRunTestBase, remove_if_exists
+
+
+class AutopilotFunctionalTestsBase(AutopilotRunTestBase):
 
     """A collection of functional tests for autopilot."""
 

=== added file 'autopilot/tests/functional/test_autopilot_performance.py'
--- autopilot/tests/functional/test_autopilot_performance.py	1970-01-01 00:00:00 +0000
+++ autopilot/tests/functional/test_autopilot_performance.py	2013-09-17 18:50:22 +0000
@@ -0,0 +1,81 @@
+# -*- Mode: Python; coding: utf-8; indent-tabs-mode: nil; tab-width: 4 -*-
+#
+# Autopilot Functional Test Tool
+# Copyright (C) 2012-2013 Canonical
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+
+from __future__ import absolute_import
+
+
+from contextlib import contextmanager
+from time import time
+from textwrap import dedent
+from testtools.matchers import Equals
+
+import logging
+from autopilot.tests.functional import AutopilotRunTestBase
+
+
+logger = logging.getLogger(__name__)
+
+
+@contextmanager
+def maximum_runtime(max_time):
+    start_time = time()
+    yield
+    total_time = abs(time() - start_time)
+    if total_time >= max_time:
+        raise AssertionError(
+            "Runtime of %f was not within defined "
+            "limit of %f" % (total_time, max_time)
+        )
+    else:
+        logger.info(
+            "Test completed in %f seconds, which is below the "
+            " threshold of %f.",
+            total_time,
+            max_time
+        )
+
+
+class AutopilotPerformanceTests(AutopilotRunTestBase):
+
+    """A suite of functional tests that will fail if autopilot performance
+    regresses below certain strictly defined limits.
+
+    Each test must be named after the feature we are benchmarking, and should
+    use the maximum_runtime contextmanager defined above.
+
+    """
+
+    def test_autopilot_launch_test_app(self):
+        self.create_test_file(
+            'test_something.py',
+            dedent("""
+                from autopilot.testcase import AutopilotTestCase
+
+                class LaunchTestAppTests(AutopilotTestCase):
+
+                    def test_launch_test_app(self):
+                        app_proxy = self.launch_test_application(
+                            'window-mocker',
+                            app_type='qt'
+                        )
+                """)
+            )
+        with maximum_runtime(5.0):
+            rc, out, err = self.run_autopilot(['run', 'tests'])
+            self.assertThat(rc, Equals(0))