[GTK] The Xvfb display server may fail to start sometimes causing tes…

…ts to randomly crash (v3)

https://bugs.webkit.org/show_bug.cgi?id=229758

Reviewed by Philippe Normand.

Add a new function in XvfbDriver() to ensure that the display server
at a given display_id is replying as expected. Ask it for the screen
size at monitor 0 and compare the result with the one we expect to
have inside Xvfb. For doing this check a external python program is
called which does the query using GTK. Using a external program is
more robust against possible failures calling into GTK and also will
allow re-using this program also to check that the weston server is
also replying as expected for the weston driver (on a future patch).

If the Xvfb driver is not replying as expected then restart it and
try again, up to 3 retries.

Use this also on the weston driver to check that the Xvfb driver is
ready.

The code is both compatible with python2 and python3, when running on
python2 it will try first to use subprocess32 if available, otherwise
will use standard python2 subprocess without using the timeout feature.

On this v3 fix an error that caused that the subprocess stderr was
redirected to stdout by mistake.

* Scripts/webkitpy/common/system/executive_mock.py:
(MockProcess.__init__):
(MockProcess.communicate):
* Scripts/webkitpy/port/westondriver.py:
(WestonDriver._setup_environ_for_test):
* Scripts/webkitpy/port/westondriver_unittest.py:
(WestonXvfbDriverDisplayTest._xvfb_check_if_ready):
* Scripts/webkitpy/port/xvfbdriver.py:
(XvfbDriver):
(XvfbDriver.__init__):
(XvfbDriver.check_driver):
(XvfbDriver._xvfb_run):
(XvfbDriver._xvfb_screen_size):
(XvfbDriver._xvfb_stop):
(XvfbDriver._xvfb_check_if_ready):
(XvfbDriver._setup_environ_for_test):
(XvfbDriver.has_crashed):
(XvfbDriver.stop):
* Scripts/webkitpy/port/xvfbdriver_unittest.py:
(XvfbDriverTest.make_driver):
(XvfbDriverTest.assertDriverStartSuccessful):
(XvfbDriverTest.test_xvfb_start_and_ready):
(XvfbDriverTest.test_xvfb_start_arbitrary_worker_number):
(XvfbDriverTest.test_xvfb_not_replying):
* gtk/print-screen-size: Added.

Canonical link: https://commits.webkit.org/241382@main
git-svn-id: https://svn.webkit.org/repository/webkit/trunk@282082 268f45cc-cd09-0410-ab3c-d52691b4dbfc

Tools/ChangeLog

@@ -1,3 +1,58 @@
+2021-09-07  Carlos Alberto Lopez Perez  <clopez@igalia.com>
+
+        [GTK] The Xvfb display server may fail to start sometimes causing tests to randomly crash (v3)
+        https://bugs.webkit.org/show_bug.cgi?id=229758
+
+        Reviewed by Philippe Normand.
+
+        Add a new function in XvfbDriver() to ensure that the display server
+        at a given display_id is replying as expected. Ask it for the screen
+        size at monitor 0 and compare the result with the one we expect to
+        have inside Xvfb. For doing this check a external python program is
+        called which does the query using GTK. Using a external program is
+        more robust against possible failures calling into GTK and also will
+        allow re-using this program also to check that the weston server is
+        also replying as expected for the weston driver (on a future patch).
+
+        If the Xvfb driver is not replying as expected then restart it and
+        try again, up to 3 retries.
+
+        Use this also on the weston driver to check that the Xvfb driver is
+        ready.
+
+        The code is both compatible with python2 and python3, when running on
+        python2 it will try first to use subprocess32 if available, otherwise
+        will use standard python2 subprocess without using the timeout feature.
+
+        On this v3 fix an error that caused that the subprocess stderr was
+        redirected to stdout by mistake.
+
+        * Scripts/webkitpy/common/system/executive_mock.py:
+        (MockProcess.__init__):
+        (MockProcess.communicate):
+        * Scripts/webkitpy/port/westondriver.py:
+        (WestonDriver._setup_environ_for_test):
+        * Scripts/webkitpy/port/westondriver_unittest.py:
+        (WestonXvfbDriverDisplayTest._xvfb_check_if_ready):
+        * Scripts/webkitpy/port/xvfbdriver.py:
+        (XvfbDriver):
+        (XvfbDriver.__init__):
+        (XvfbDriver.check_driver):
+        (XvfbDriver._xvfb_run):
+        (XvfbDriver._xvfb_screen_size):
+        (XvfbDriver._xvfb_stop):
+        (XvfbDriver._xvfb_check_if_ready):
+        (XvfbDriver._setup_environ_for_test):
+        (XvfbDriver.has_crashed):
+        (XvfbDriver.stop):
+        * Scripts/webkitpy/port/xvfbdriver_unittest.py:
+        (XvfbDriverTest.make_driver):
+        (XvfbDriverTest.assertDriverStartSuccessful):
+        (XvfbDriverTest.test_xvfb_start_and_ready):
+        (XvfbDriverTest.test_xvfb_start_arbitrary_worker_number):
+        (XvfbDriverTest.test_xvfb_not_replying):
+        * gtk/print-screen-size: Added.
+
 2021-09-07  Aakash Jain  <aakash_jain@apple.com>
 
         TestWebKitAPI.EventAttribution.Basic is extremely flaky on api-ios

Tools/Scripts/webkitpy/common/system/executive_mock.py

@@ -37,21 +37,23 @@
 
 
 class MockProcess(object):
-    def __init__(self, stdout='MOCK STDOUT\n', stderr=''):
+    def __init__(self, stdout='MOCK STDOUT\n', stderr='', returncode=0):
         self.pid = 42
         self.stdout = BytesIO(string_utils.encode(stdout))
         self.stderr = BytesIO(string_utils.encode(stderr))
         self.stdin = BytesIO()
-        self.returncode = 0
+        self.returncode = returncode
         self._is_running = False
 
     def wait(self):
         self._is_running = False
         return self.returncode
 
-    def communicate(self, input=None):
+    def communicate(self, input=None, timeout=None):
         self._is_running = False
-        return (self.stdout, self.stderr)
+        stdout = self.stdout.read() if isinstance(self.stdout, BytesIO) else self.stdout
+        stderr = self.stderr.read() if isinstance(self.stderr, BytesIO) else self.stderr
+        return (stdout, stderr)
 
     def poll(self):
         if self._is_running:

Tools/Scripts/webkitpy/port/westondriver.py

@@ -56,7 +56,18 @@ def __init__(self, *args, **kwargs):
 
     def _setup_environ_for_test(self):
         driver_environment = super(WestonDriver, self)._setup_environ_for_test()
-        driver_environment['DISPLAY'] = ":%d" % self._xvfbdriver._xvfb_run(driver_environment)
+        xvfb_display_id = self._xvfbdriver._xvfb_run(driver_environment)
+        driver_environment['DISPLAY'] = ':%d' % xvfb_display_id
+
+        # Ensure that Xvfb is ready and replying and expected before continuing, give it 3 tries.
+        if not self._xvfbdriver._xvfb_check_if_ready(xvfb_display_id):
+            self._xvfbdriver._current_retry_start_xvfb += 1
+            if self._xvfbdriver._current_retry_start_xvfb > 3:
+                _log.error('Failed to start Xvfb display server ... giving up after 3 retries.')
+                raise RuntimeError('Unable to start Xvfb display server')
+            _log.error('Failed to start Xvfb display server ... retrying [ %s of 3 ].' % self._xvfbdriver._current_retry_start_xvfb)
+            return self._setup_environ_for_test()
+
         weston_socket = 'WKTesting-weston-%032x' % random.getrandbits(128)
         weston_command = ['weston', '--socket=%s' % weston_socket, '--width=1024', '--height=768', '--use-pixman']
         if self._port._should_use_jhbuild():

Tools/Scripts/webkitpy/port/westondriver_unittest.py

@@ -50,6 +50,9 @@ def __init__(self, expected_xvfbdisplay):
     def _xvfb_run(self, environment):
         return self._expected_xvfbdisplay
 
+    def _xvfb_check_if_ready(self, display_id):
+        return True
+
 
 class WestonDriverTest(unittest.TestCase):
     def make_driver(self):

Tools/Scripts/webkitpy/port/xvfbdriver.py

@@ -1,5 +1,5 @@
 # Copyright (C) 2010 Google Inc. All rights reserved.
-# Copyright (C) 2014 Igalia S.L.
+# Copyright (C) 2014-2021 Igalia S.L.
 #
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
@@ -33,6 +33,14 @@
 import re
 import time
 
+if sys.version_info[0] < 3:
+    try:
+        import subprocess32 as subprocess
+    except ImportError:
+        import subprocess
+else:
+    import subprocess
+
 from webkitcorepy import string_utils
 from webkitpy.port.server_process import ServerProcess
 from webkitpy.port.driver import Driver
@@ -41,14 +49,21 @@
 
 
 class XvfbDriver(Driver):
+
+    def __init__(self, *args, **kwargs):
+        Driver.__init__(self, *args, **kwargs)
+        self._xvfb_process = None
+        self._current_retry_start_xvfb = 0
+        self._print_screen_size_process_for_testing = None  # required for unit tests
+
     @staticmethod
     def check_driver(port):
         xvfb_findcmd = ['which', 'Xvfb']
         if port._should_use_jhbuild():
                 xvfb_findcmd = port._jhbuild_wrapper + xvfb_findcmd
         xvfb_found = port.host.executive.run_command(xvfb_findcmd, return_exit_code=True) == 0
         if not xvfb_found:
-            _log.error("No Xvfb found. Cannot run layout tests.")
+            _log.error('No Xvfb found. Cannot run layout tests.')
         return xvfb_found
 
     def _xvfb_pipe(self):
@@ -86,21 +101,78 @@ def _xvfb_close_pipe(self, pipe_fds):
 
     def _xvfb_run(self, environment):
         read_fd, write_fd = self._xvfb_pipe()
-        run_xvfb = ["Xvfb", "-displayfd", str(write_fd), "-screen",  "0", "1024x768x%s" % self._xvfb_screen_depth(), "-nolisten", "tcp"]
+        run_xvfb = ['Xvfb', '-displayfd', str(write_fd), '-nolisten', 'tcp',
+                    '+extension', 'GLX', '-ac', '-screen', '0',
+                    '%sx%s' % (self._xvfb_screen_size(), self._xvfb_screen_depth())]
         if self._port._should_use_jhbuild():
             run_xvfb = self._port._jhbuild_wrapper + run_xvfb
-        with open(os.devnull, 'w') as devnull:
-            # python3 will try to close the file descriptors by default
-            self._xvfb_process = self._port.host.executive.popen(run_xvfb, stderr=devnull, env=environment, close_fds=False)
-            display_id = self._xvfb_read_display_id(read_fd)
-
+        self._xvfb_process = self._port.host.executive.popen(run_xvfb, stdout=self._port.host.executive.PIPE, stderr=self._port.host.executive.PIPE, env=environment, close_fds=False)
+        display_id = self._xvfb_read_display_id(read_fd)
         self._xvfb_close_pipe((read_fd, write_fd))
-
         return display_id
 
     def _xvfb_screen_depth(self):
         return os.environ.get('XVFB_SCREEN_DEPTH', '24')
 
+    def _xvfb_screen_size(self):
+        return os.environ.get('XVFB_SCREEN_SIZE', '1024x768')
+
+    def _xvfb_stop(self):
+        if self._xvfb_process:
+            self._port.host.executive.kill_process(self._xvfb_process.pid)
+            self._xvfb_process = None
+
+    def _xvfb_check_if_ready(self, display_id):
+        environment_print_screen_size_process = super(XvfbDriver, self)._setup_environ_for_test()
+        environment_print_screen_size_process['DISPLAY'] = ':%d' % display_id
+        environment_print_screen_size_process['GDK_BACKEND'] = 'x11'
+        waited_seconds_for_xvfb_ready = 0
+        xvfb_server_replying_as_expected = False
+        while True:
+            timeout_expired = False
+            query_failed = False
+            print_screen_size_process = self._print_screen_size_process_for_testing if self._print_screen_size_process_for_testing else \
+                subprocess.Popen([self._port.path_from_webkit_base('Tools', 'gtk', 'print-screen-size')],
+                                 stdout=subprocess.PIPE, stderr=subprocess.PIPE, env=environment_print_screen_size_process)
+            # Python2 standard subprocess don't allows setting a timeout
+            if not hasattr(subprocess, 'TimeoutExpired'):
+                stdout, stderr = print_screen_size_process.communicate()
+            else:
+                try:
+                    stdout, stderr = print_screen_size_process.communicate(timeout=2)
+                except subprocess.TimeoutExpired:
+                    _log.debug('Timeout expired trying to query the Xvfb display server.')
+                    timeout_expired = True
+                    print_screen_size_process.kill()
+                    stdout, stderr = print_screen_size_process.communicate()
+                    waited_seconds_for_xvfb_ready += 2
+
+            if not timeout_expired:
+                if print_screen_size_process.returncode == 0:
+                    queried_screen_size = stdout.decode('UTF-8').strip()
+                    if queried_screen_size == self._xvfb_screen_size():
+                        xvfb_server_replying_as_expected = True
+                        _log.debug('The Xvfb display server ":%d" is ready and replying as expected.' % display_id)
+                        break
+                    else:
+                        _log.warning('The queried Xvfb screen size "%s" does not match the expectation "%s".' % (queried_screen_size, self._xvfb_screen_size()))
+                else:
+                    _log.warning('The print-screen-size tool returned non-zero status. stdout is "%s" and stderr is "%s"' % (stdout, stderr))
+                    query_failed = True
+            if timeout_expired or query_failed:
+                if self._xvfb_process.poll():
+                    xvfb_stdout, xvfb_stderr = self._xvfb_process.communicate()
+                    _log.error('The Xvfb display server has exited unexpectedly with a return code of %s. stdout is "%s" and stderr is "%s"' % (self._xvfb_process.poll(), xvfb_stdout, xvfb_stderr))
+                    break
+            if waited_seconds_for_xvfb_ready > 5:
+                _log.error('Timeout reached meanwhile waiting for the Xvfb display server to be ready')
+                break
+            _log.debug('Waiting for Xvfb display server to be ready.')
+            if not self._print_screen_size_process_for_testing:
+                time.sleep(1)  # only wait when not running unit tests
+            waited_seconds_for_xvfb_ready += 1
+        return xvfb_server_replying_as_expected
+
     def _setup_environ_for_test(self):
         port_server_environment = self._port.setup_environ_for_server(self._server_name)
         driver_environment = super(XvfbDriver, self)._setup_environ_for_test()
@@ -111,10 +183,25 @@ def _setup_environ_for_test(self):
         driver_environment['UNDER_XVFB'] = 'yes'
         driver_environment['GDK_BACKEND'] = 'x11'
         driver_environment['LOCAL_RESOURCE_ROOT'] = self._port.layout_tests_dir()
+
+        # Ensure that Xvfb is ready and replying and expected before continuing, give it 3 tries.
+        if not self._xvfb_check_if_ready(display_id):
+            self._current_retry_start_xvfb += 1
+            if self._current_retry_start_xvfb > 3:
+                _log.error('Failed to start Xvfb display server ... giving up after 3 retries.')
+                raise RuntimeError('Unable to start Xvfb display server')
+            _log.error('Failed to start Xvfb display server ... retrying [ %s of 3 ].' % self._current_retry_start_xvfb)
+            return self._setup_environ_for_test()
+
         return driver_environment
 
+    def has_crashed(self):
+        if self._xvfb_process and self._xvfb_process.poll():
+            self._crashed_process_name = 'Xvfb'
+            self._crashed_pid = self._xvfb_process.pid
+            return True
+        return super(XvfbDriver, self).has_crashed()
+
     def stop(self):
         super(XvfbDriver, self).stop()
-        if getattr(self, '_xvfb_process', None):
-            self._port.host.executive.kill_process(self._xvfb_process.pid)
-            self._xvfb_process = None
+        self._xvfb_stop()

Tools/Scripts/webkitpy/port/xvfbdriver_unittest.py

@@ -31,7 +31,7 @@
 import unittest
 
 from webkitpy.common.system.filesystem_mock import MockFileSystem
-from webkitpy.common.system.executive_mock import MockExecutive2
+from webkitpy.common.system.executive_mock import MockProcess
 from webkitpy.common.system.systemhost_mock import MockSystemHost
 from webkitpy.port import Port
 from webkitpy.port.server_process_mock import MockServerProcess
@@ -44,7 +44,7 @@
 
 
 class XvfbDriverTest(unittest.TestCase):
-    def make_driver(self, worker_number=0, xorg_running=False, executive=None):
+    def make_driver(self, worker_number=0, xorg_running=False, executive=None, print_screen_size_process=None):
         port = Port(MockSystemHost(log_executive=True, executive=executive), 'xvfbdrivertestport', options=MockOptions(configuration='Release'))
         port._config.build_directory = lambda configuration: "/mock-build"
         port._test_runner_process_constructor = MockServerProcess
@@ -57,6 +57,7 @@ def make_driver(self, worker_number=0, xorg_running=False, executive=None):
         driver._xvfb_pipe = lambda: (3, 4)
         driver._xvfb_read_display_id = lambda x: 1
         driver._xvfb_close_pipe = lambda p: None
+        driver._print_screen_size_process_for_testing = print_screen_size_process if print_screen_size_process else MockProcess(driver._xvfb_screen_size())
         driver._port_server_environment = port.setup_environ_for_server(port.driver_name())
         return driver
 
@@ -67,26 +68,43 @@ def cleanup_driver(self, driver):
         driver._xvfb_process = None
 
     def assertDriverStartSuccessful(self, driver, expected_logs, expected_display, pixel_tests=False):
-        with OutputCapture(level=logging.INFO) as captured:
+        with OutputCapture(level=logging.DEBUG) as captured:
             driver.start(pixel_tests, [])
         self.assertEqual(captured.root.log.getvalue(), expected_logs)
 
         self.assertTrue(driver._server_process.started)
         self.assertEqual(driver._server_process.env['DISPLAY'], expected_display)
         self.assertEqual(driver._server_process.env['GDK_BACKEND'], 'x11')
 
-    def test_start(self):
+    def test_xvfb_start_and_ready(self):
         driver = self.make_driver()
-        expected_logs = ("MOCK popen: ['Xvfb', '-displayfd', '4', '-screen', '0', '1024x768x24', '-nolisten', 'tcp'], env=%s\n" % driver._port_server_environment)
-        self.assertDriverStartSuccessful(driver, expected_logs=expected_logs, expected_display=":1")
+        expected_display = ':1'
+        expected_logs = ("MOCK popen: ['Xvfb', '-displayfd', '4', '-nolisten', 'tcp', '+extension', 'GLX', '-ac', '-screen', '0', '1024x768x24'], env=%s\n" % driver._port_server_environment)
+        expected_logs += ('The Xvfb display server "%s" is ready and replying as expected.\n' % expected_display)
+        self.assertDriverStartSuccessful(driver, expected_logs=expected_logs, expected_display=expected_display)
         self.cleanup_driver(driver)
 
-    def test_start_arbitrary_worker_number(self):
+    def test_xvfb_start_arbitrary_worker_number(self):
         driver = self.make_driver(worker_number=17)
-        expected_logs = ("MOCK popen: ['Xvfb', '-displayfd', '4', '-screen', '0', '1024x768x24', '-nolisten', 'tcp'], env=%s\n" % driver._port_server_environment)
+        expected_display = ':1'
+        expected_logs = ("MOCK popen: ['Xvfb', '-displayfd', '4', '-nolisten', 'tcp', '+extension', 'GLX', '-ac', '-screen', '0', '1024x768x24'], env=%s\n" % driver._port_server_environment)
+        expected_logs += ('The Xvfb display server "%s" is ready and replying as expected.\n' % expected_display)
         self.assertDriverStartSuccessful(driver, expected_logs=expected_logs, expected_display=":1", pixel_tests=True)
         self.cleanup_driver(driver)
 
+    def test_xvfb_not_replying(self):
+        failing_print_screen_size_process = MockProcess(returncode=1)
+        driver = self.make_driver(print_screen_size_process=failing_print_screen_size_process)
+        with OutputCapture(level=logging.INFO) as captured:
+            self.assertRaisesRegexp(RuntimeError, 'Unable to start Xvfb display server', driver.start, False, [])
+            captured_log = captured.root.log.getvalue()
+            for retry in [1, 2, 3]:
+                self.assertTrue('Failed to start Xvfb display server ... retrying [ {} of 3 ].'.format(retry) in captured_log)
+                self.assertFalse('Failed to start Xvfb display server ... retrying [ 4 of 3 ].' in captured_log)
+            self.assertTrue('Failed to start Xvfb display server ... giving up after 3 retries.' in captured_log)
+            self.assertTrue('The print-screen-size tool returned non-zero status' in captured_log)
+        self.cleanup_driver(driver)
+
     def test_stop(self):
         port = Port(MockSystemHost(log_executive=True), 'xvfbdrivertestport', options=MockOptions(configuration='Release'))
         port._executive.kill_process = lambda x: _log.info("MOCK kill_process pid: " + str(x))