[gnome-settings-daemon/benzea/fix-xsettings-ci-race] xsettings: Fix race condition in fontconfig timestamp test

[Benjamin Berg <bberg src gnome org>]

commit 2e9ae0a9dc5bfd9623ae49e16508fa459b5d2498
Author: Benjamin Berg <bberg redhat com>
Date:   Tue Aug 18 11:07:03 2020 +0200

    xsettings: Fix race condition in fontconfig timestamp test
    
    gsd-xsettings needs some time to update the fontconfig caches before it
    also updates the corresponding timestamp in the X property. So add
    delay logic that first waits for the changes to be picked up and
    processed, and then waits a bit longer just to be sure we wait long
    enough.

 plugins/xsettings/test.py | 47 +++++++++++++++++++++++++++++++++++++----------
 1 file changed, 37 insertions(+), 10 deletions(-)
---
diff --git a/plugins/xsettings/test.py b/plugins/xsettings/test.py
index 9c1b4a09..89503de2 100755
--- a/plugins/xsettings/test.py
+++ b/plugins/xsettings/test.py
@@ -58,7 +58,7 @@ class XsettingsPluginTest(gsdtestcase.GSDTestCase):
         self.start_mutter()
 
         Gio.Settings.sync()
-        self.plugin_log_write = open(os.path.join(self.workdir, 'plugin_xsettings.log'), 'wb')
+        self.plugin_log_write = open(os.path.join(self.workdir, 'plugin_xsettings.log'), 'wb', buffering=0)
         os.environ['GSD_ignore_llvmpipe'] = '1'
 
         # Setup fontconfig config path before starting the daemon
@@ -94,7 +94,7 @@ class XsettingsPluginTest(gsdtestcase.GSDTestCase):
             env=env)
 
         # you can use this for reading the current daemon log in tests
-        self.plugin_log = open(self.plugin_log_write.name)
+        self.plugin_log = open(self.plugin_log_write.name, 'rb', buffering=0)
 
         # flush notification log
         try:
@@ -142,6 +142,33 @@ class XsettingsPluginTest(gsdtestcase.GSDTestCase):
         self.session_log_write.close()
         self.session_log.close()
 
+    def check_plugin_log(self, needle, timeout=0, failmsg=None):
+        '''Check that needle is found in the log within the given timeout.
+        Returns immediately when found.
+
+        Fail after the given timeout.
+        '''
+        if type(needle) == str:
+            needle = needle.encode('ascii')
+        # Fast path if the message was already logged
+        log = self.plugin_log.read()
+        if needle in log:
+            return
+
+        while timeout > 0:
+            time.sleep(0.5)
+            timeout -= 0.5
+
+            # read new data (lines) from the log
+            log = self.plugin_log.read()
+            if needle in log:
+                break
+        else:
+            if failmsg is not None:
+                self.fail(failmsg)
+            else:
+                self.fail('timed out waiting for needle "%s"' % needle)
+
     def test_gtk_modules(self):
         # Turn off event sounds
         self.settings_sound['event-sounds'] = False
@@ -161,22 +188,22 @@ class XsettingsPluginTest(gsdtestcase.GSDTestCase):
         self.assertEqual(values, ['canberra-gtk-module', 'pk-gtk-module'])
 
     def test_fontconfig_timestamp(self):
-        # gdbus_log_write = open(os.path.join(self.workdir, 'gdbus.log'), 'wb')
-        # process = subprocess.Popen(['gdbus', 'introspect', '--session', '--dest', 'org.gtk.Settings', 
'--object-path', '/org/gtk/Settings'],
-        #        stdout=gdbus_log_write, stderr=subprocess.STDOUT)
-        # time.sleep(1)
+        # We should see some updated initially
+        self.check_plugin_log("Fontconfig update", timeout=5, failmsg="Fontconfig was not updated!")
 
+        # Wait a bit to ensure that the setting is updated
+        time.sleep(1)
         before = self.obj_xsettings_props.Get('org.gtk.Settings', 'FontconfigTimestamp')
         self.assertEqual(before, 0)
 
         # Copy the fonts.conf again
         shutil.copy(os.path.join(os.path.dirname(__file__), 'fontconfig-test/fonts.conf'),
                 os.path.join(self.fc_dir, 'fonts.conf'))
-        time.sleep(1)
 
-        # gdbus_log_write = open(os.path.join(self.workdir, 'gdbus-after.log'), 'wb')
-        # process = subprocess.Popen(['gdbus', 'introspect', '--session', '--dest', 'org.gtk.Settings', 
'--object-path', '/org/gtk/Settings'],
-        #         stdout=gdbus_log_write, stderr=subprocess.STDOUT)
+        # Wait for gsd-xsettings to pick up the change (and process it)
+        self.check_plugin_log("Fontconfig update", timeout=5, failmsg="Fontconfig was not updated!")
+
+        # Sleep a bit to ensure that the setting is updated
         time.sleep(1)
 
         after = self.obj_xsettings_props.Get('org.gtk.Settings', 'FontconfigTimestamp')