[glib: 1/2] gmessages: Error if g_log_set_writer_func() is called multiple times

[Sebastian Dröge <sdroege src gnome org>]

commit dfb3517d3790c014f7c964414405cd9775ad4b9d
Author: Philip Withnall <pwithnall endlessos org>
Date:   Mon Apr 25 12:23:45 2022 +0100

    gmessages: Error if g_log_set_writer_func() is called multiple times
    
    Inspired by https://gitlab.gnome.org/GNOME/glib/-/issues/2638.
    
    This requires moving the tests to subprocesses, so that
    `g_log_set_writer_func()` is only called once per process.
    
    It also adds a test for the new error.
    
    Signed-off-by: Philip Withnall <pwithnall endlessos org>

 glib/gmessages.c     |   9 ++
 glib/tests/logging.c | 324 +++++++++++++++++++++++++++++++++------------------
 2 files changed, 220 insertions(+), 113 deletions(-)
---
diff --git a/glib/gmessages.c b/glib/gmessages.c
index 008bf5c13c..c1fa98cb20 100644
--- a/glib/gmessages.c
+++ b/glib/gmessages.c
@@ -2059,9 +2059,18 @@ g_log_set_writer_func (GLogWriterFunc func,
   g_return_if_fail (func != NULL);
 
   g_mutex_lock (&g_messages_lock);
+
+  if (log_writer_func != g_log_writer_default)
+    {
+      g_mutex_unlock (&g_messages_lock);
+      g_error ("g_log_set_writer_func() called multiple times");
+      return;
+    }
+
   log_writer_func = func;
   log_writer_user_data = user_data;
   log_writer_user_data_free = user_data_free;
+
   g_mutex_unlock (&g_messages_lock);
 }
 
diff --git a/glib/tests/logging.c b/glib/tests/logging.c
index e9c4e396cf..b79362a7d0 100644
--- a/glib/tests/logging.c
+++ b/glib/tests/logging.c
@@ -445,136 +445,196 @@ expect_log_writer (GLogLevelFlags   log_level,
 static void
 test_structured_logging_no_state (void)
 {
-  gpointer some_pointer = GUINT_TO_POINTER (0x100);
-  guint some_integer = 123;
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      gpointer some_pointer = GUINT_TO_POINTER (0x100);
+      guint some_integer = 123;
 
-  log_count = 0;
-  g_log_set_writer_func (null_log_writer, NULL, NULL);
+      log_count = 0;
+      g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-  g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
-                    "MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e",
-                    "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
-                    "MESSAGE", "This is a debug message about pointer %p and integer %u.",
-                    some_pointer, some_integer);
+      g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
+                        "MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e",
+                        "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
+                        "MESSAGE", "This is a debug message about pointer %p and integer %u.",
+                        some_pointer, some_integer);
 
-  g_assert_cmpint (log_count, ==, 1);
+      g_assert_cmpint (log_count, ==, 1);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static void
 test_structured_logging_some_state (void)
 {
-  gpointer state_object = NULL;  /* this must not be dereferenced */
-  const GLogField fields[] = {
-    { "MESSAGE", "This is a debug message.", -1 },
-    { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
-    { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
-    { "MY_APPLICATION_STATE", state_object, 0 },
-  };
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      gpointer state_object = NULL;  /* this must not be dereferenced */
+      const GLogField fields[] = {
+        { "MESSAGE", "This is a debug message.", -1 },
+        { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
+        { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
+        { "MY_APPLICATION_STATE", state_object, 0 },
+      };
 
-  log_count = 0;
-  g_log_set_writer_func (null_log_writer, NULL, NULL);
+      log_count = 0;
+      g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-  g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
+      g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
 
-  g_assert_cmpint (log_count, ==, 1);
+      g_assert_cmpint (log_count, ==, 1);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static void
 test_structured_logging_robustness (void)
 {
-  log_count = 0;
-  g_log_set_writer_func (null_log_writer, NULL, NULL);
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      log_count = 0;
+      g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-  /* NULL log_domain shouldn't crash */
-  g_log (NULL, G_LOG_LEVEL_MESSAGE, "Test");
-  g_log_structured (NULL, G_LOG_LEVEL_MESSAGE, "MESSAGE", "Test");
+      /* NULL log_domain shouldn't crash */
+      g_log (NULL, G_LOG_LEVEL_MESSAGE, "Test");
+      g_log_structured (NULL, G_LOG_LEVEL_MESSAGE, "MESSAGE", "Test");
 
-  g_assert_cmpint (log_count, ==, 1);
+      g_assert_cmpint (log_count, ==, 2);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static void
 test_structured_logging_roundtrip1 (void)
 {
-  gpointer some_pointer = GUINT_TO_POINTER (0x100);
-  gint some_integer = 123;
-  gchar message[200];
-  GLogField fields[] = {
-    { "GLIB_DOMAIN", "some-domain", -1 },
-    { "PRIORITY", "5", -1 },
-    { "MESSAGE", "String assigned using g_snprintf() below", -1 },
-    { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
-    { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
-  };
-  ExpectedMessage expected = { fields, 5 };
-
-  /* %p format is implementation defined and depends on the platform */
-  g_snprintf (message, sizeof (message),
-              "This is a debug message about pointer %p and integer %u.",
-              some_pointer, some_integer);
-  fields[2].value = message;
-
-  expected_messages = g_slist_append (NULL, &expected);
-  g_log_set_writer_func (expect_log_writer, NULL, NULL);
-
-  g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
-                    "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893",
-                    "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
-                    "MESSAGE", "This is a debug message about pointer %p and integer %u.",
-                    some_pointer, some_integer);
-
-  if (expected_messages != NULL)
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
     {
-      char *str;
-      ExpectedMessage *msg = expected_messages->data;
+      gpointer some_pointer = GUINT_TO_POINTER (0x100);
+      gint some_integer = 123;
+      gchar message[200];
+      GLogField fields[] = {
+        { "GLIB_DOMAIN", "some-domain", -1 },
+        { "PRIORITY", "5", -1 },
+        { "MESSAGE", "String assigned using g_snprintf() below", -1 },
+        { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
+        { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
+      };
+      ExpectedMessage expected = { fields, 5 };
+
+      /* %p format is implementation defined and depends on the platform */
+      g_snprintf (message, sizeof (message),
+                  "This is a debug message about pointer %p and integer %u.",
+                  some_pointer, some_integer);
+      fields[2].value = message;
+
+      expected_messages = g_slist_append (NULL, &expected);
+      g_log_set_writer_func (expect_log_writer, NULL, NULL);
+
+      g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
+                        "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893",
+                        "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
+                        "MESSAGE", "This is a debug message about pointer %p and integer %u.",
+                        some_pointer, some_integer);
+
+      if (expected_messages != NULL)
+        {
+          char *str;
+          ExpectedMessage *msg = expected_messages->data;
 
-      str = g_log_writer_format_fields (0, msg->fields, msg->n_fields, FALSE);
-      g_test_fail_printf ("Unexpected message: %s", str);
-      g_free (str);
+          str = g_log_writer_format_fields (0, msg->fields, msg->n_fields, FALSE);
+          g_test_fail_printf ("Unexpected message: %s", str);
+          g_free (str);
+        }
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
     }
 }
 
 static void
 test_structured_logging_roundtrip2 (void)
 {
-  const gchar *some_string = "abc";
-  const GLogField fields[] = {
-    { "GLIB_DOMAIN", "some-domain", -1 },
-    { "PRIORITY", "5", -1 },
-    { "MESSAGE", "This is a debug message about string 'abc'.", -1 },
-    { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
-    { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
-  };
-  ExpectedMessage expected = { fields, 5 };
-
-  expected_messages = g_slist_append (NULL, &expected);
-  g_log_set_writer_func (expect_log_writer, NULL, NULL);
-
-  g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
-                    "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893",
-                    "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
-                    "MESSAGE", "This is a debug message about string '%s'.",
-                    some_string);
-
-  g_assert (expected_messages == NULL);
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      const gchar *some_string = "abc";
+      const GLogField fields[] = {
+        { "GLIB_DOMAIN", "some-domain", -1 },
+        { "PRIORITY", "5", -1 },
+        { "MESSAGE", "This is a debug message about string 'abc'.", -1 },
+        { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
+        { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
+      };
+      ExpectedMessage expected = { fields, 5 };
+
+      expected_messages = g_slist_append (NULL, &expected);
+      g_log_set_writer_func (expect_log_writer, NULL, NULL);
+
+      g_log_structured ("some-domain", G_LOG_LEVEL_MESSAGE,
+                        "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893",
+                        "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
+                        "MESSAGE", "This is a debug message about string '%s'.",
+                        some_string);
+
+      g_assert (expected_messages == NULL);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static void
 test_structured_logging_roundtrip3 (void)
 {
-  const GLogField fields[] = {
-    { "GLIB_DOMAIN", "some-domain", -1 },
-    { "PRIORITY", "4", -1 },
-    { "MESSAGE", "Test test test.", -1 }
-  };
-  ExpectedMessage expected = { fields, 3 };
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      const GLogField fields[] = {
+        { "GLIB_DOMAIN", "some-domain", -1 },
+        { "PRIORITY", "4", -1 },
+        { "MESSAGE", "Test test test.", -1 }
+      };
+      ExpectedMessage expected = { fields, 3 };
 
-  expected_messages = g_slist_append (NULL, &expected);
-  g_log_set_writer_func (expect_log_writer, NULL, NULL);
+      expected_messages = g_slist_append (NULL, &expected);
+      g_log_set_writer_func (expect_log_writer, NULL, NULL);
 
-  g_log_structured ("some-domain", G_LOG_LEVEL_WARNING,
-                    "MESSAGE", "Test test test.");
+      g_log_structured ("some-domain", G_LOG_LEVEL_WARNING,
+                        "MESSAGE", "Test test test.");
 
-  g_assert (expected_messages == NULL);
+      g_assert (expected_messages == NULL);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static GVariant *
@@ -597,36 +657,73 @@ create_variant_fields (void)
 static void
 test_structured_logging_variant1 (void)
 {
-  GVariant *v = create_variant_fields ();
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      GVariant *v = create_variant_fields ();
 
-  log_count = 0;
-  g_log_set_writer_func (null_log_writer, NULL, NULL);
+      log_count = 0;
+      g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-  g_log_variant ("some-domain", G_LOG_LEVEL_MESSAGE, v);
-  g_variant_unref (v);
-  g_assert_cmpint (log_count, ==, 1);
+      g_log_variant ("some-domain", G_LOG_LEVEL_MESSAGE, v);
+      g_variant_unref (v);
+      g_assert_cmpint (log_count, ==, 1);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
 }
 
 static void
 test_structured_logging_variant2 (void)
 {
-  const GLogField fields[] = {
-    { "GLIB_DOMAIN", "some-domain", -1 },
-    { "PRIORITY", "5", -1 },
-    { "MESSAGE", "This is a debug message", -1 },
-    { "MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e", -1 },
-    { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
-    { "MY_APPLICATION_CUSTOM_FIELD_BINARY", binary_field, sizeof (binary_field) }
-  };
-  ExpectedMessage expected = { fields, 6 };
-  GVariant *v = create_variant_fields ();
-
-  expected_messages = g_slist_append (NULL, &expected);
-  g_log_set_writer_func (expect_log_writer, NULL, NULL);
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func(), which
+   * can only be called once per process. */
+  if (g_test_subprocess ())
+    {
+      const GLogField fields[] = {
+        { "GLIB_DOMAIN", "some-domain", -1 },
+        { "PRIORITY", "5", -1 },
+        { "MESSAGE", "This is a debug message", -1 },
+        { "MESSAGE_ID", "06d4df59e6c24647bfe69d2c27ef0b4e", -1 },
+        { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 },
+        { "MY_APPLICATION_CUSTOM_FIELD_BINARY", binary_field, sizeof (binary_field) }
+      };
+      ExpectedMessage expected = { fields, 6 };
+      GVariant *v = create_variant_fields ();
+
+      expected_messages = g_slist_append (NULL, &expected);
+      g_log_set_writer_func (expect_log_writer, NULL, NULL);
+
+      g_log_variant ("some-domain", G_LOG_LEVEL_MESSAGE, v);
+      g_variant_unref (v);
+      g_assert (expected_messages == NULL);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_passed ();
+    }
+}
 
-  g_log_variant ("some-domain", G_LOG_LEVEL_MESSAGE, v);
-  g_variant_unref (v);
-  g_assert (expected_messages == NULL);
+static void
+test_structured_logging_set_writer_func_twice (void)
+{
+  /* Test has to run in a subprocess as it calls g_log_set_writer_func() and
+   * causes an error. */
+  if (g_test_subprocess ())
+    {
+      g_log_set_writer_func (null_log_writer, NULL, NULL);
+      g_log_set_writer_func (expect_log_writer, NULL, NULL);
+    }
+  else
+    {
+      g_test_trap_subprocess (NULL, 0, 0);
+      g_test_trap_assert_failed ();
+    }
 }
 
 int
@@ -663,6 +760,7 @@ main (int argc, char *argv[])
   g_test_add_func ("/structured-logging/roundtrip3", test_structured_logging_roundtrip3);
   g_test_add_func ("/structured-logging/variant1", test_structured_logging_variant1);
   g_test_add_func ("/structured-logging/variant2", test_structured_logging_variant2);
+  g_test_add_func ("/structured-logging/set-writer-func-twice", 
test_structured_logging_set_writer_func_twice);
 
   return g_test_run ();
 }