From ca775518d800408d1bf330fdf7f9578437130d19 Mon Sep 17 00:00:00 2001 From: Matthias Clasen Date: Fri, 22 Jul 2016 15:11:30 -0400 Subject: [PATCH] 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 file changed, 118 insertions(+), 66 deletions(-) diff --git a/glib/tests/logging.c b/glib/tests/logging.c index f151ed9a1..c10e11086 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 (); } -- 2.11.4.GIT