[GTK][WPE] Improve the way glib tests are run
authorcommit-queue@webkit.org <commit-queue@webkit.org@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Tue, 16 Jan 2018 10:42:49 +0000 (10:42 +0000)
committercommit-queue@webkit.org <commit-queue@webkit.org@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Tue, 16 Jan 2018 10:42:49 +0000 (10:42 +0000)
https://bugs.webkit.org/show_bug.cgi?id=181674

Patch by Carlos Garcia Campos <cgarcia@igalia.com> on 2018-01-16
Reviewed by Žan Doberšek.

Stop using gtester external program and use our own tester from python directly. This way we no longer need to
parse the tests output to get the results which is causing problems in WPE bot. We can now differentiate between
tests failing due to an expected assert in the test and unexpected crashes.
This also fixes a bug in previous code where we failed to properly detect tests timing out, because gtester was
not showing the subtest name in stdout in case of timeouts.
I've lowered the default timeout from 10 to 5, since we are now properly handling the timeout for every test
case. I've also removed the verbose option, since it was only used by gtester and we now always show the result
of every test case.

* glib/api_test_runner.py:
(TestRunner._run_test_glib): Use GLibTestRunner.
(TestRunner._run_google_test): Wrote tests timing out to stdout too.
(add_options):
* glib/glib_test_runner.py: Added.
(TestTimeout):
(Message):
(Message.__init__):
(Message.create):
(Message.create.read_unsigned):
(Message.create.read_double):
(Message.create.read_string):
(GLibTestRunner):
(GLibTestRunner.__init__):
(GLibTestRunner._process_data):
(GLibTestRunner._process_message):
(GLibTestRunner._read_from_pipe):
(GLibTestRunner._read_from_stderr):
(GLibTestRunner._start_timeout):
(GLibTestRunner._start_timeout._alarm_handler):
(GLibTestRunner._stop_timeout):
(GLibTestRunner._subtest_start):
(GLibTestRunner._subtest_message):
(GLibTestRunner._subtest_stderr):
(GLibTestRunner._subtest_end):
(GLibTestRunner.run):

git-svn-id: https://svn.webkit.org/repository/webkit/trunk@226967 268f45cc-cd09-0410-ab3c-d52691b4dbfc

Tools/ChangeLog
Tools/glib/api_test_runner.py
Tools/glib/glib_test_runner.py [new file with mode: 0644]

index 6934a35..15c114f 100644 (file)
@@ -1,3 +1,46 @@
+2018-01-16  Carlos Garcia Campos  <cgarcia@igalia.com>
+
+        [GTK][WPE] Improve the way glib tests are run
+        https://bugs.webkit.org/show_bug.cgi?id=181674
+
+        Reviewed by Žan Doberšek.
+
+        Stop using gtester external program and use our own tester from python directly. This way we no longer need to
+        parse the tests output to get the results which is causing problems in WPE bot. We can now differentiate between
+        tests failing due to an expected assert in the test and unexpected crashes.
+        This also fixes a bug in previous code where we failed to properly detect tests timing out, because gtester was
+        not showing the subtest name in stdout in case of timeouts.
+        I've lowered the default timeout from 10 to 5, since we are now properly handling the timeout for every test
+        case. I've also removed the verbose option, since it was only used by gtester and we now always show the result
+        of every test case.
+
+        * glib/api_test_runner.py:
+        (TestRunner._run_test_glib): Use GLibTestRunner.
+        (TestRunner._run_google_test): Wrote tests timing out to stdout too.
+        (add_options):
+        * glib/glib_test_runner.py: Added.
+        (TestTimeout):
+        (Message):
+        (Message.__init__):
+        (Message.create):
+        (Message.create.read_unsigned):
+        (Message.create.read_double):
+        (Message.create.read_string):
+        (GLibTestRunner):
+        (GLibTestRunner.__init__):
+        (GLibTestRunner._process_data):
+        (GLibTestRunner._process_message):
+        (GLibTestRunner._read_from_pipe):
+        (GLibTestRunner._read_from_stderr):
+        (GLibTestRunner._start_timeout):
+        (GLibTestRunner._start_timeout._alarm_handler):
+        (GLibTestRunner._stop_timeout):
+        (GLibTestRunner._subtest_start):
+        (GLibTestRunner._subtest_message):
+        (GLibTestRunner._subtest_stderr):
+        (GLibTestRunner._subtest_end):
+        (GLibTestRunner.run):
+
 2018-01-15  Michael Catanzaro  <mcatanzaro@igalia.com>
 
         Unreviewed, add Thibault to contributors.json
index f4a3daa..4e2e181 100755 (executable)
@@ -22,17 +22,15 @@ import os
 import errno
 import sys
 import re
-from signal import alarm, signal, SIGALRM, SIGKILL, SIGSEGV
+from signal import SIGKILL, SIGSEGV
+from glib_test_runner import GLibTestRunner
 
 top_level_directory = os.path.normpath(os.path.join(os.path.dirname(__file__), "..", ".."))
 sys.path.insert(0, os.path.join(top_level_directory, "Tools", "glib"))
 import common
 from webkitpy.common.host import Host
 from webkitpy.common.test_expectations import TestExpectations
-
-
-class TestTimeout(Exception):
-    pass
+from webkitpy.common.timeout_context import Timeout
 
 
 class TestRunner(object):
@@ -126,24 +124,6 @@ class TestRunner(object):
             # Process already died.
             pass
 
-    @staticmethod
-    def _start_timeout(timeout):
-        if timeout <= 0:
-            return
-
-        def _alarm_handler(signum, frame):
-            raise TestTimeout
-
-        signal(SIGALRM, _alarm_handler)
-        alarm(timeout)
-
-    @staticmethod
-    def _stop_timeout(timeout):
-        if timeout <= 0:
-            return
-
-        alarm(0)
-
     def _waitpid(self, pid):
         while True:
             try:
@@ -166,82 +146,11 @@ class TestRunner(object):
                 raise
 
     def _run_test_glib(self, test_program):
-        command = ['gtester', '-k']
-        if self._options.verbose:
-            command.append('--verbose')
-        for test_case in self._test_cases_to_skip(test_program):
-            command.extend(['-s', test_case])
-        command.append(test_program)
-
         timeout = self._options.timeout
         test = os.path.join(os.path.basename(os.path.dirname(test_program)), os.path.basename(test_program))
         if self._expectations.is_slow(os.path.basename(test_program)):
             timeout *= 5
-
-        test_context = {"child-pid": -1, "did-timeout": False, "current_test": None}
-
-        def parse_line(line, test_context=test_context):
-            if not line:
-                return
-
-            match = re.search(r'\(pid=(?P<child_pid>[0-9]+)\)', line)
-            if match:
-                test_context["child-pid"] = int(match.group('child_pid'))
-                sys.stdout.write(line)
-                return
-
-            def set_test_result(test, result):
-                if result == "FAIL":
-                    if test_context["did-timeout"] and result == "FAIL":
-                        test_context[test] = "TIMEOUT"
-                    else:
-                        test_context[test] = result
-                else:
-                    test_context[test] = 'PASS'
-                test_context["did-timeout"] = False
-                test_context["current_test"] = None
-                self._stop_timeout(timeout)
-                self._start_timeout(timeout)
-
-            normalized_line = line.strip().replace(' ', '')
-            if not normalized_line:
-                return
-
-            if normalized_line[0] == '/':
-                test, result = normalized_line.split(':', 1)
-                if result in ["OK", "FAIL"]:
-                    set_test_result(test, result)
-                else:
-                    test_context["current_test"] = test
-            elif normalized_line in ["OK", "FAIL"]:
-                set_test_result(test_context["current_test"], normalized_line)
-
-            sys.stdout.write(line)
-
-        pid, fd = os.forkpty()
-        if pid == 0:
-            os.execvpe(command[0], command, self._test_env)
-            sys.exit(0)
-
-        self._start_timeout(timeout)
-
-        while (True):
-            try:
-                common.parse_output_lines(fd, parse_line)
-                break
-            except TestTimeout:
-                assert test_context["child-pid"] > 0
-                self._kill_process(test_context["child-pid"])
-                test_context["child-pid"] = -1
-                test_context["did-timeout"] = True
-
-        self._stop_timeout(timeout)
-        del test_context["child-pid"]
-        del test_context["did-timeout"]
-        del test_context["current_test"]
-
-        self._waitpid(pid)
-        return test_context
+        return GLibTestRunner(test_program, timeout).run(skipped=self._test_cases_to_skip(test_program))
 
     def _get_tests_from_google_test_suite(self, test_program):
         try:
@@ -276,15 +185,15 @@ class TestRunner(object):
             os.execvpe(command[0], command, self._test_env)
             sys.exit(0)
 
-        self._start_timeout(timeout)
-        try:
-            common.parse_output_lines(fd, sys.stdout.write)
-            status = self._waitpid(pid)
-        except TestTimeout:
-            self._kill_process(pid)
-            return {subtest: "TIMEOUT"}
-
-        self._stop_timeout(timeout)
+        with Timeout(timeout):
+            try:
+                common.parse_output_lines(fd, sys.stdout.write)
+                status = self._waitpid(pid)
+            except RuntimeError:
+                self._kill_process(pid)
+                sys.stdout.write("**TIMEOUT** %s\n" % subtest)
+                sys.stdout.flush()
+                return {subtest: "TIMEOUT"}
 
         if status == -SIGSEGV:
             sys.stdout.write("**CRASH** %s\n" % subtest)
@@ -377,13 +286,10 @@ def add_options(option_parser):
     option_parser.add_option('-d', '--debug',
                              action='store_true', dest='debug',
                              help='Run in Debug')
-    option_parser.add_option('-v', '--verbose',
-                             action='store_true', dest='verbose',
-                             help='Run gtester in verbose mode')
     option_parser.add_option('--skipped', action='store', dest='skipped_action',
                              choices=['skip', 'ignore', 'only'], default='skip',
                              metavar='skip|ignore|only',
                              help='Specifies how to treat the skipped tests')
     option_parser.add_option('-t', '--timeout',
-                             action='store', type='int', dest='timeout', default=10,
+                             action='store', type='int', dest='timeout', default=5,
                              help='Time in seconds until a test times out')
diff --git a/Tools/glib/glib_test_runner.py b/Tools/glib/glib_test_runner.py
new file mode 100644 (file)
index 0000000..f7c9362
--- /dev/null
@@ -0,0 +1,276 @@
+# Copyright (C) 2018 Igalia S.L.
+#
+# This library is free software; you can redistribute it and/or
+# modify it under the terms of the GNU Library General Public
+# License as published by the Free Software Foundation; either
+# version 2 of the License, or (at your option) any later version.
+#
+# This library 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
+# Library General Public License for more details.
+#
+# You should have received a copy of the GNU Library General Public License
+# along with this library; see the file COPYING.LIB.  If not, write to
+# the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor,
+# Boston, MA 02110-1301, USA.
+
+import errno
+import os
+import select
+import socket
+import struct
+import subprocess
+import sys
+from signal import alarm, signal, SIGALRM
+from io import BytesIO
+
+
+(LOG_NONE,
+ LOG_ERROR,
+ LOG_START_BINARY,
+ LOG_LIST_CASE,
+ LOG_SKIP_CASE,
+ LOG_START_CASE,
+ LOG_STOP_CASE,
+ LOG_MIN_RESULT,
+ LOG_MAX_RESULT,
+ LOG_MESSAGE,
+ LOG_START_SUITE,
+ LOG_STOP_SUITE) = range(12)
+
+(TEST_RUN_SUCCESS,
+ TEST_RUN_SKIPPED,
+ TEST_RUN_FAILURE,
+ TEST_RUN_INCOMPLETE) = range(4)
+
+
+class TestTimeout(Exception):
+    pass
+
+
+class Message(object):
+
+    def __init__(self, log_type, strings, numbers):
+        self.log_type = log_type
+        self.strings = strings
+        self.numbers = numbers
+
+    @staticmethod
+    def create(data):
+        if len(data) < 5 * 4:
+            return 0, None
+
+        def read_unsigned(bytes, n=1):
+            values = struct.unpack('%dI' % n, bytes.read(4 * n))
+            return [socket.ntohl(v) for v in values if v is not None]
+
+        def read_double(bytes, n=1):
+            return struct.unpack('>%dd' % n, bytes.read(8 * n))
+
+        def read_string(bytes, n=1):
+            values = []
+            for i in range(n):
+                str_len = read_unsigned(bytes)[0]
+                values.append(struct.unpack('%ds' % str_len, bytes.read(str_len))[0])
+            return values
+
+        bytes = BytesIO(data)
+        msg_len = read_unsigned(bytes)[0]
+        if len(data) < msg_len:
+            return 0, None
+
+        log_type, n_strings, n_numbers, reserved = read_unsigned(bytes, 4)
+        if reserved != 0:
+            return 0, None
+
+        strings = read_string(bytes, n_strings)
+        numbers = read_double(bytes, n_numbers)
+
+        return msg_len, Message(log_type, strings, numbers)
+
+
+class GLibTestRunner(object):
+
+    def __init__(self, test_binary, timeout):
+        self._test_binary = test_binary
+        self._timeout = timeout
+
+        self._stderr_fd = None
+        self._subtest = None
+        self._subtest_messages = []
+        self._results = {}
+
+    def _process_data(self, data):
+        retval = []
+        msg_len, msg = Message.create(data)
+        while msg_len:
+            retval.append(msg)
+            data = data[msg_len:]
+            msg_len, msg = Message.create(data)
+
+        return data, retval
+
+    def _process_message(self, message):
+        if message.log_type == LOG_ERROR:
+            self._subtest_message(message.strings)
+        elif message.log_type == LOG_START_CASE:
+            self._subtest_start(message.strings[0])
+        elif message.log_type == LOG_STOP_CASE:
+            self._subtest_end(message.numbers[0])
+        elif message.log_type == LOG_MESSAGE:
+            self._subtest_message([message.strings[0]])
+
+    def _read_from_pipe(self, pipe_r):
+        data = ''
+        read_set = [pipe_r]
+        while read_set:
+            try:
+                rlist, _, _ = select.select(read_set, [], [])
+            except select.error, e:
+                if e.args[0] == errno.EINTR:
+                    continue
+                raise
+
+            if pipe_r in rlist:
+                buffer = os.read(pipe_r, 4096)
+                if not buffer:
+                    read_set.remove(pipe_r)
+
+                data += buffer
+                data, messages = self._process_data(data)
+                for message in messages:
+                    self._process_message(message)
+
+    def _read_from_stderr(self, fd):
+        data = ''
+        read_set = [fd]
+        while True:
+            try:
+                rlist, _, _ = select.select(read_set, [], [], 0)
+            except select.error, e:
+                if e.args[0] == errno.EINTR:
+                    continue
+                raise
+
+            if fd not in rlist:
+                return data
+
+            buffer = os.read(fd, 4096)
+            if not buffer:
+                return data
+
+            data += buffer
+
+    @staticmethod
+    def _start_timeout(timeout):
+        if timeout <= 0:
+            return
+
+        def _alarm_handler(signum, frame):
+            raise TestTimeout
+
+        signal(SIGALRM, _alarm_handler)
+        alarm(timeout)
+
+    @staticmethod
+    def _stop_timeout(timeout):
+        if timeout <= 0:
+            return
+
+        alarm(0)
+
+    def _subtest_start(self, subtest):
+        self._subtest = subtest
+        message = self._subtest + ':'
+        sys.stdout.write('  %-68s' % message)
+        sys.stdout.flush()
+        self._start_timeout(self._timeout)
+
+    def _subtest_message(self, message):
+        if self._subtest is None:
+            sys.stdout.write('%s\n' % '\n'.join(message))
+        else:
+            self._subtest_messages.extend(message)
+
+    def _subtest_stderr(self, errors):
+        ignore_next_line = False
+        for line in errors.rstrip('\n').split('\n'):
+            if ignore_next_line:
+                ignore_next_line = False
+                continue
+            if line == '**':
+                ignore_next_line = True
+                continue
+            sys.stderr.write('%s\n' % line)
+        sys.stderr.flush()
+
+    def _subtest_end(self, result, did_timeout=False):
+        self._stop_timeout(self._timeout)
+        if did_timeout:
+            self._results[self._subtest] = 'TIMEOUT'
+        elif result == TEST_RUN_SUCCESS:
+            self._results[self._subtest] = 'PASS'
+        elif result == TEST_RUN_SKIPPED:
+            self._results[self._subtest] = 'SKIP'
+        elif not self._subtest_messages:
+            self._results[self._subtest] = 'CRASH'
+        else:
+            self._results[self._subtest] = 'FAIL'
+
+        sys.stdout.write('%s\n' % self._results[self._subtest])
+        if self._subtest_messages:
+            sys.stdout.write('%s\n' % '\n'.join(self._subtest_messages))
+        sys.stdout.flush()
+
+        errors = self._read_from_stderr(self._stderr_fd)
+        if errors:
+            self._subtest_stderr(errors)
+
+        self._subtest = None
+        self._subtest_messages = []
+
+    def run(self, subtests=[], skipped=[]):
+        pipe_r, pipe_w = os.pipe()
+        command = [self._test_binary, '--quiet', '--keep-going', '--GTestLogFD=%d' % pipe_w]
+        if self._results:
+            command.append('--GTestSkipCount=%d' % len(self._results))
+        for subtest in subtests:
+            command.extend(['-p', subtest])
+        for skip in skipped:
+            command.extend(['-s', skip])
+
+        if not self._results:
+            sys.stdout.write('TEST: %s...\n' % self._test_binary)
+            sys.stdout.flush()
+        p = subprocess.Popen(command, stderr=subprocess.PIPE)
+        self._stderr_fd = p.stderr.fileno()
+        os.close(pipe_w)
+
+        need_restart = False
+
+        try:
+            self._read_from_pipe(pipe_r)
+            p.wait()
+        except TestTimeout:
+            self._subtest_end(0, did_timeout=True)
+            p.terminate()
+            need_restart = True
+        finally:
+            os.close(pipe_r)
+
+        if self._subtest is not None:
+            self._subtest_end(256)
+            need_restart = True
+
+        self._stderr_fd = None
+
+        if need_restart:
+            self.run()
+
+        return self._results
+
+if __name__ == '__main__':
+    for test in sys.argv[1:]:
+        runner = GLibTestRunner(test, 5)
+        runner.run()