[glib] Add more structured logging tests

[Matthias Clasen <matthiasc src gnome org>]

commit ca775518d800408d1bf330fdf7f9578437130d19
Author: Matthias Clasen <mclasen redhat com>
Date:   Fri Jul 22 15:11:30 2016 -0400

    Add more structured logging tests
    
    In particular, add a test to ensure that passing NULL
    as log_domain has no negative consequences.

 glib/tests/logging.c |  184 ++++++++++++++++++++++++++++++++------------------
 1 files changed, 118 insertions(+), 66 deletions(-)
---
diff --git a/glib/tests/logging.c b/glib/tests/logging.c
index f151ed9..c10e110 100644
--- a/glib/tests/logging.c
+++ b/glib/tests/logging.c
@@ -296,17 +296,97 @@ test_gibberish (void)
   g_test_trap_assert_stderr ("*bla bla \\x9e\\x9f\\u000190*");
 }
 
+static GLogWriterOutput
+null_log_writer (GLogLevelFlags   log_level,
+                 const GLogField *fields,
+                 gsize            n_fields,
+                 gpointer         user_data)
+{
+  log_count++;
+  return G_LOG_WRITER_HANDLED;
+}
+
+typedef struct {
+  const GLogField *fields;
+  gsize n_fields;
+} ExpectedMessage;
+
+static gboolean
+compare_field (const GLogField *f1, const GLogField *f2)
+{
+  if (strcmp (f1->key, f2->key) != 0)
+    return FALSE;
+  if (f1->length != f2->length)
+    return FALSE;
+
+  if (f1->length == -1)
+    return strcmp (f1->value, f2->value) == 0;
+  else
+    return memcmp (f1->value, f2->value, f1->length) == 0;
+}
+
+static gboolean
+compare_fields (const GLogField *f1, gsize n1, const GLogField *f2, gsize n2)
+{
+  int i, j;
+
+  for (i = 0; i < n1; i++)
+    {
+      for (j = 0; j < n2; j++)
+        {
+          if (compare_field (&f1[i], &f2[j]))
+            break;
+        }
+      if (j == n2)
+        return FALSE;
+    }
+
+  return TRUE;
+}
+
+static GSList *expected_messages = NULL;
+
+static GLogWriterOutput
+expect_log_writer (GLogLevelFlags   log_level,
+                   const GLogField *fields,
+                   gsize            n_fields,
+                   gpointer         user_data)
+{
+  ExpectedMessage *expected = expected_messages->data;
+
+  if (compare_fields (fields, n_fields, expected->fields, expected->n_fields))
+    {
+      expected_messages = g_slist_delete_link (expected_messages, expected_messages);
+    }
+  else if ((log_level & G_LOG_LEVEL_DEBUG) != G_LOG_LEVEL_DEBUG)
+    {
+      char *str;
+
+      str = g_log_writer_format_fields (log_level, fields, n_fields, FALSE);
+      g_test_message ("Unexpected message: %s", str);
+      g_free (str);
+      g_test_fail ();
+    }
+
+  return G_LOG_WRITER_HANDLED;
+}
+
 static void
 test_structured_logging_no_state (void)
 {
   gpointer some_pointer = GUINT_TO_POINTER (0x100);
   guint some_integer = 123;
 
+  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_assert_cmpint (log_count, ==, 1);
 }
 
 static void
@@ -320,57 +400,25 @@ test_structured_logging_some_state (void)
     { "MY_APPLICATION_STATE", state_object, 0 },
   };
 
-  g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
-}
+  log_count = 0;
+  g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-typedef struct {
-  const GLogField *fields;
-  gsize n_fields;
-} MyLogFields;
+  g_log_structured_array (G_LOG_LEVEL_DEBUG, fields, G_N_ELEMENTS (fields));
 
-static void
-compare_field (const GLogField *f1, const GLogField *f2)
-{
-  g_assert_cmpstr (f1->key, ==, f2->key);
-  g_assert_cmpuint (f1->length, ==, f2->length);
-  if (f1->length == -1)
-    g_assert_cmpstr (f1->value, ==, f2->value);
-  else
-    g_assert (memcmp (f1->value, f2->value, f1->length) == 0);
+  g_assert_cmpint (log_count, ==, 1);
 }
 
 static void
-compare_fields (const GLogField *f1, gsize n1, const GLogField *f2, gsize n2)
+test_structured_logging_robustness (void)
 {
-  int i, j;
+  log_count = 0;
+  g_log_set_writer_func (null_log_writer, NULL, NULL);
 
-  for (i = 0; i < n1; i++)
-    {
-      for (j = 0; j < n2; j++)
-        {
-          if (strcmp (f1[i].key, f2[j].key) == 0)
-            {
-              compare_field (&f1[i], &f2[j]);
-              break;
-            }
-        }
-      g_assert (j < n2);
-    }
+  /* 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 (n1, ==, n2);
-}
-
-static GLogWriterOutput
-my_writer_func (GLogLevelFlags   log_level,
-                const GLogField *fields,
-                gsize            n_fields,
-                gpointer         user_data)
-{
-  MyLogFields *data = user_data;
-
-  compare_fields (fields, n_fields, data->fields, data->n_fields);
-
-  return G_LOG_WRITER_HANDLED;
+  g_assert_cmpint (log_count, ==, 1);
 }
 
 static void
@@ -385,16 +433,27 @@ test_structured_logging_roundtrip1 (void)
     { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
     { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
   };
-  MyLogFields data = { fields, 5 };
+  ExpectedMessage expected = { fields, 5 };
 
-  g_log_set_writer_func (my_writer_func, &data, 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_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);
-  exit (0);
+
+  if (expected_messages != NULL)
+    {
+      char *str;
+      ExpectedMessage *expected = expected_messages->data;
+
+      str = g_log_writer_format_fields (0, expected->fields, expected->n_fields, FALSE);
+      g_test_message ("Unexpected message: %s", str);
+      g_free (str);
+      g_test_fail ();
+    }
 }
 
 static void
@@ -408,16 +467,18 @@ test_structured_logging_roundtrip2 (void)
     { "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893", -1 },
     { "MY_APPLICATION_CUSTOM_FIELD", "some debug string", -1 }
   };
-  MyLogFields data = { fields, 5 };
+  ExpectedMessage expected = { fields, 5 };
 
-  g_log_set_writer_func (my_writer_func, &data, 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_MESSAGE,
                     "MESSAGE_ID", "fcfb2e1e65c3494386b74878f1abf893",
                     "MY_APPLICATION_CUSTOM_FIELD", "some debug string",
                     "MESSAGE", "This is a debug message about string '%s'.",
                     some_string);
-  exit (0);
+
+  g_assert (expected_messages == NULL);
 }
 
 static void
@@ -428,24 +489,15 @@ test_structured_logging_roundtrip3 (void)
     { "PRIORITY", "4", 1 },
     { "MESSAGE", "Test test test.", -1 }
   };
-  MyLogFields data = { fields, 3 };
+  ExpectedMessage expected = { fields, 3 };
 
-  g_log_set_writer_func (my_writer_func, &data, 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.");
-  exit (0);
-}
 
-static void
-test_structured_logging_roundtrip (void)
-{
-  g_test_trap_subprocess ("/structured-logging/roundtrip/subprocess/1", 0, 0);
-  g_test_trap_assert_passed ();
-  g_test_trap_subprocess ("/structured-logging/roundtrip/subprocess/2", 0, 0);
-  g_test_trap_assert_passed ();
-  g_test_trap_subprocess ("/structured-logging/roundtrip/subprocess/3", 0, 0);
-  g_test_trap_assert_passed ();
+  g_assert (expected_messages == NULL);
 }
 
 int
@@ -475,10 +527,10 @@ main (int argc, char *argv[])
   g_test_add_func ("/logging/gibberish", test_gibberish);
   g_test_add_func ("/structured-logging/no-state", test_structured_logging_no_state);
   g_test_add_func ("/structured-logging/some-state", test_structured_logging_some_state);
-  g_test_add_func ("/structured-logging/roundtrip", test_structured_logging_roundtrip);
-  g_test_add_func ("/structured-logging/roundtrip/subprocess/1", test_structured_logging_roundtrip1);
-  g_test_add_func ("/structured-logging/roundtrip/subprocess/2", test_structured_logging_roundtrip2);
-  g_test_add_func ("/structured-logging/roundtrip/subprocess/3", test_structured_logging_roundtrip3);
+  g_test_add_func ("/structured-logging/robustness", test_structured_logging_robustness);
+  g_test_add_func ("/structured-logging/roundtrip1", test_structured_logging_roundtrip1);
+  g_test_add_func ("/structured-logging/roundtrip2", test_structured_logging_roundtrip2);
+  g_test_add_func ("/structured-logging/roundtrip3", test_structured_logging_roundtrip3);
 
   return g_test_run ();
 }