[Spice-commits] 6 commits - common/log.c common/log.h tests/Makefile.am tests/test-logging.c

Christophe Fergau teuf at kemper.freedesktop.org
Tue Jan 26 07:44:52 PST 2016


 common/log.c         |  165 ++++++++++++++------
 common/log.h         |  100 +++---------
 tests/Makefile.am    |   19 ++
 tests/test-logging.c |  408 +++++++++++++++++++++++++++++++++++++++++++++++++++
 4 files changed, 567 insertions(+), 125 deletions(-)

New commits:
commit 0a6580d2e636749f8aa9dfc7bffcc1f2aa9114fd
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Thu Nov 26 17:51:26 2015 +0100

    log: Kill spice_warn_if
    
    It's redundant with spice_warn_if_fail(), and can even be confusing.
    
    Acked-by: Jonathon Jongsma <jjongsma at redhat.com>

diff --git a/common/log.h b/common/log.h
index a56105a..0e03f59 100644
--- a/common/log.h
+++ b/common/log.h
@@ -95,12 +95,6 @@ void spice_log(const char *log_domain,
     }                                                   \
 } G_STMT_END
 
-#define spice_warn_if(x) G_STMT_START {                 \
-    if G_UNLIKELY(x) {                                  \
-        spice_warning("condition `%s' reached", #x);    \
-    }                                                   \
-} G_STMT_END
-
 #define spice_assert(x) G_STMT_START {                  \
     if G_LIKELY(x) { } else {                           \
         spice_error("assertion `%s' failed", #x);       \
commit df56d585cbc928698be6da7476acbc1dffcfcd5b
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Tue Dec 15 18:26:29 2015 +0100

    log: Add test case for logging code
    
    This gives us a baseline of how the SPICE/glib integration is supposed
    to behave.
    
    Everything goes through glib logging facilities, and is impacted by
    G_MESSAGES_DEBUG/G_DEBUG=fatal-{warnings,criticals}
    
    Messages in the SPICE_LOG_DOMAIN log domain (output either through
    spice_log() or g_log()) will also consider the legacy SPICE_DEBUG_LEVEL
    and SPICE_ABORT_LEVEL environment variables. Messages in other domains
    will not be impacted by these legacy environment variables.
    
    If spice-common is built without SPICE_DISABLE_ABORT,
    spice_return_if_fail()/spice_critical() will abort the program.
    g_return_if_fail()/g_critical() will not abort the program.

diff --git a/tests/Makefile.am b/tests/Makefile.am
index 92d2f62..248f467 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -1,7 +1,22 @@
 NULL =
 
-TESTS = test_marshallers
+TESTS = test_logging test_marshallers
 noinst_PROGRAMS = $(TESTS)
+
+test_logging_SOURCES = test-logging.c
+test_logging_CFLAGS =			\
+	-I$(top_srcdir)			\
+	$(GLIB2_CFLAGS)			\
+	$(GIO_UNIX_CFLAGS)		\
+	$(PROTOCOL_CFLAGS)		\
+	$(NULL)
+test_logging_LDADD =					\
+	$(top_builddir)/common/libspice-common.la	\
+	$(GLIB2_LIBS)			\
+	$(GIO_UNIX_LIBS)		\
+	$(NULL)
+
+
 test_marshallers_SOURCES =		\
 	generated_test_marshallers.c	\
 	generated_test_marshallers.h	\
diff --git a/tests/test-logging.c b/tests/test-logging.c
new file mode 100644
index 0000000..008ce48
--- /dev/null
+++ b/tests/test-logging.c
@@ -0,0 +1,408 @@
+/*
+   Copyright (C) 2015 Red Hat, Inc.
+
+   This library is free software; you can redistribute it and/or
+   modify it under the terms of the GNU Lesser General Public
+   License as published by the Free Software Foundation; either
+   version 2.1 of the License, or (at your option) any later version.
+
+   This library is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+   Lesser General Public License for more details.
+
+   You should have received a copy of the GNU Lesser General Public
+   License along with this library; if not, see <http://www.gnu.org/licenses/>.
+*/
+#ifdef HAVE_CONFIG_H
+#include <config.h>
+#endif
+
+#define G_LOG_DOMAIN "Spice"
+#define SPICE_LOG_DOMAIN G_LOG_DOMAIN
+
+#include <glib.h>
+
+#include "common/log.h"
+
+#define OTHER_LOG_DOMAIN "Other"
+#define LOG_OTHER_HELPER(suffix, level)                                          \
+    static void G_PASTE(other_, suffix)(const gchar *format, ...)                \
+    {                                                                            \
+        va_list args;                                                            \
+                                                                                 \
+        va_start (args, format);                                                 \
+        g_logv(OTHER_LOG_DOMAIN, G_PASTE(G_LOG_LEVEL_, level), format, args);    \
+        va_end (args);                                                           \
+    }
+
+/* Set of helpers to log in a different log domain than "Spice" */
+LOG_OTHER_HELPER(debug, DEBUG)
+LOG_OTHER_HELPER(info, INFO)
+LOG_OTHER_HELPER(message, MESSAGE)
+LOG_OTHER_HELPER(warning, WARNING)
+LOG_OTHER_HELPER(critical, CRITICAL)
+
+/* Checks that spice_warning() aborts after changing SPICE_ABORT_LEVEL */
+static void test_spice_abort_level(void)
+{
+    if (g_test_subprocess()) {
+        /* 2 = SPICE_LOG_LEVEL_WARNING  */
+        g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
+        g_test_expect_message(NULL,
+                              G_LOG_LEVEL_WARNING,
+                              "*SPICE_ABORT_LEVEL*deprecated*");
+        spice_debug("trigger deprecation warning");
+        g_test_assert_expected_messages();
+        spice_warning("spice_warning");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stderr("*spice_warning*");
+}
+
+/* Checks that g_warning() aborts after changing SPICE_ABORT_LEVEL */
+static void test_spice_abort_level_g_warning(void)
+{
+    if (g_test_subprocess()) {
+        /* 2 = SPICE_LOG_LEVEL_WARNING  */
+        g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
+        g_test_expect_message(NULL,
+                              G_LOG_LEVEL_WARNING,
+                              "*SPICE_ABORT_LEVEL*deprecated*");
+        spice_debug("trigger deprecation warning");
+        g_test_assert_expected_messages();
+        g_warning("g_warning");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stderr("*g_warning*");
+}
+
+/* Checks that spice_warning() aborts after setting G_DEBUG=fatal-warnings */
+static void test_spice_fatal_warning(void)
+{
+    g_setenv("G_DEBUG", "fatal-warnings", TRUE);
+    if (g_test_subprocess()) {
+        spice_warning("spice_warning");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stderr("*spice_warning*");
+    g_unsetenv("G_DEBUG");
+}
+
+/* Checks that spice_critical() aborts by default if SPICE_DISABLE_ABORT is not
+ * defined at compile-time */
+static void test_spice_fatal_critical(void)
+{
+    if (g_test_subprocess()) {
+        spice_critical("spice_critical");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+#ifdef SPICE_DISABLE_ABORT
+    g_test_trap_assert_passed();
+#else
+    g_test_trap_assert_failed();
+#endif
+    g_test_trap_assert_stderr("*spice_critical*");
+}
+
+/* Checks that g_critical() does not abort by default */
+static void test_spice_non_fatal_g_critical(void)
+{
+    if (g_test_subprocess()) {
+        g_critical("g_critical");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stderr("*g_critical*");
+}
+
+/* Checks that g_critical() aborts after setting G_DEBUG=fatal-criticals */
+static void test_spice_fatal_g_critical(void)
+{
+    g_setenv("G_DEBUG", "fatal-criticals", TRUE);
+    if (g_test_subprocess()) {
+        g_critical("g_critical");
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stderr("*g_critical*");
+    g_unsetenv("G_DEBUG");
+}
+
+/* Checks that spice_return_if_fail() aborts by default unless
+ * SPICE_DISABLE_ABORT was defined at compile time*/
+static void test_spice_fatal_return_if_fail(void)
+{
+    if (g_test_subprocess()) {
+        spice_return_if_fail(FALSE);
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+#ifdef SPICE_DISABLE_ABORT
+    g_test_trap_assert_passed();
+#else
+    g_test_trap_assert_failed();
+#endif
+    g_test_trap_assert_stderr("*test_spice_fatal_return_if_fail*");
+}
+
+/* Checks that g_return_if_fail() does not abort by default */
+static void test_spice_non_fatal_g_return_if_fail(void)
+{
+    if (g_test_subprocess()) {
+        g_return_if_fail(FALSE);
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+}
+
+/* Checks that spice_*, g_* and other_* (different log domain as g_*) all
+ * go through g_log() with the correct domain/log level. This then checks
+ * that only logs with level 'message' or higher are shown by default.
+ */
+static void test_log_levels(void)
+{
+    if (g_test_subprocess()) {
+        g_test_expect_message(SPICE_LOG_DOMAIN,
+                              G_LOG_LEVEL_WARNING,
+                              "*spice_warning");
+        spice_warning("spice_warning");
+        g_test_expect_message(SPICE_LOG_DOMAIN,
+                              G_LOG_LEVEL_INFO,
+                              "*spice_info");
+        spice_info("spice_info");
+        g_test_expect_message(SPICE_LOG_DOMAIN,
+                              G_LOG_LEVEL_DEBUG,
+                              "*spice_debug");
+        spice_debug("spice_debug");
+
+        g_test_expect_message(G_LOG_DOMAIN,
+                              G_LOG_LEVEL_CRITICAL,
+                              "*g_critical");
+        g_critical("g_critical");
+        g_test_expect_message(G_LOG_DOMAIN,
+                              G_LOG_LEVEL_WARNING,
+                              "*g_warning");
+        g_warning("g_warning");
+        g_test_expect_message(G_LOG_DOMAIN,
+                              G_LOG_LEVEL_MESSAGE,
+                              "*g_message");
+        g_message("g_message");
+        g_test_expect_message(G_LOG_DOMAIN,
+                              G_LOG_LEVEL_INFO,
+                              "*g_info");
+        g_info("g_info");
+        g_test_expect_message(G_LOG_DOMAIN,
+                              G_LOG_LEVEL_DEBUG,
+                              "*g_debug");
+        g_debug("g_debug");
+
+        g_test_expect_message(OTHER_LOG_DOMAIN,
+                              G_LOG_LEVEL_CRITICAL,
+                              "*other_critical");
+        other_critical("other_critical");
+        g_test_expect_message(OTHER_LOG_DOMAIN,
+                              G_LOG_LEVEL_WARNING,
+                              "*other_warning");
+        other_warning("other_warning");
+        g_test_expect_message(OTHER_LOG_DOMAIN,
+                              G_LOG_LEVEL_MESSAGE,
+                              "*other_message");
+        other_message("other_message");
+        g_test_expect_message(OTHER_LOG_DOMAIN,
+                              G_LOG_LEVEL_INFO,
+                              "*other_info");
+        other_info("other_info");
+        g_test_expect_message(OTHER_LOG_DOMAIN,
+                              G_LOG_LEVEL_DEBUG,
+                              "*other_debug");
+        other_debug("other_debug");
+
+        g_test_assert_expected_messages();
+
+
+        /* g_test_expected_message only checks whether the appropriate messages got up to g_log()
+         * The following calls will be caught by the parent process to check what was (not) printed
+         * to stdout/stderr
+         */
+        spice_warning("spice_warning");
+        spice_info("spice_info");
+        spice_debug("spice_debug");
+
+        g_critical("g_critical");
+        g_warning("g_warning");
+        g_message("g_message");
+        g_info("g_info");
+        g_debug("g_debug");
+
+        other_critical("other_critical");
+        other_warning("other_warning");
+        other_message("other_message");
+        other_info("other_info");
+        other_debug("other_debug");
+
+        return;
+    }
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stderr("*spice_warning\n*g_critical\n*g_warning\n*g_message\n*other_critical\n*other_warning\n*other_message\n");
+}
+
+/* Checks that SPICE_DEBUG_LEVEL impacts spice_debug(), g_debug() but not other_debug() */
+static void test_spice_debug_level(void)
+{
+    if (g_test_subprocess()) {
+        g_setenv("SPICE_DEBUG_LEVEL", "5", TRUE);
+        g_test_expect_message(NULL,
+                              G_LOG_LEVEL_WARNING,
+                              "*SPICE_DEBUG_LEVEL*deprecated*");
+        spice_debug("trigger deprecation warning");
+        g_test_assert_expected_messages();
+
+        /* g_test_expected_message only checks whether the appropriate messages got up to g_log()
+         * The following calls will be caught by the parent process to check what was (not) printed
+         * to stdout/stderr
+         */
+        spice_info("spice_info");
+        g_debug("g_debug");
+        spice_debug("spice_debug");
+        other_debug("other_debug");
+
+        return;
+    }
+
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stdout("*spice_info\n*g_debug\n*spice_debug\n");
+}
+
+/* Checks that raising SPICE_DEBUG_LEVEL allows to only show spice_warning() and spice_critical()
+ * messages, as well as g_warning() and g_critical(), but does not impact other_message()
+ */
+static void test_spice_debug_level_warning(void)
+{
+    if (g_test_subprocess()) {
+        g_setenv("SPICE_ABORT_LEVEL", "0", TRUE);
+        g_setenv("SPICE_DEBUG_LEVEL", "1", TRUE);
+        g_test_expect_message(NULL,
+                              G_LOG_LEVEL_WARNING,
+                              "*SPICE_DEBUG_LEVEL*deprecated*");
+        g_test_expect_message(NULL,
+                              G_LOG_LEVEL_WARNING,
+                              "*SPICE_ABORT_LEVEL*deprecated*");
+        spice_debug("trigger deprecation warning");
+        g_test_assert_expected_messages();
+
+        spice_info("spice_info");
+        spice_debug("spice_debug");
+        spice_warning("spice_warning");
+        spice_critical("spice_critical");
+        g_debug("g_debug");
+        g_info("g_info");
+        g_message("g_message");
+        g_warning("g_warning");
+        g_critical("g_critical");
+        other_debug("other_debug");
+        other_info("other_info");
+        other_message("other_message");
+        other_warning("other_warning");
+        other_critical("other_critical");
+
+        return;
+    }
+
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stderr("*spice_critical\n*g_critical\n*other_message\n*other_warning\n*other_critical\n");
+}
+
+/* Checks that setting G_MESSAGES_DEBUG to 'Spice' impacts spice_debug() and
+ * g_debug() but not other_debug() */
+static void test_spice_g_messages_debug(void)
+{
+    if (g_test_subprocess()) {
+        g_setenv("G_MESSAGES_DEBUG", "Spice", TRUE);
+
+        spice_debug("spice_debug");
+        spice_info("spice_info");
+        g_debug("g_debug");
+        g_info("g_info");
+        g_message("g_message");
+        other_debug("other_debug");
+        other_info("other_info");
+        other_message("other_message");
+
+        return;
+    }
+
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stdout("*spice_debug\n*spice_info\n*g_debug\n*g_info\n");
+    g_test_trap_assert_stderr("*g_message\n*other_message\n");
+}
+
+/* Checks that setting G_MESSAGES_DEBUG to 'all' impacts spice_debug(),
+ * g_debug() and other_debug() */
+static void test_spice_g_messages_debug_all(void)
+{
+    if (g_test_subprocess()) {
+        g_setenv("G_MESSAGES_DEBUG", "all", TRUE);
+
+        spice_debug("spice_debug");
+        spice_info("spice_info");
+        g_debug("g_debug");
+        g_info("g_info");
+        g_message("g_message");
+        other_debug("other_debug");
+        other_info("other_info");
+        other_message("other_message");
+
+        return;
+    }
+
+    g_test_trap_subprocess(NULL, 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stdout("*spice_debug\n*spice_info\n*g_debug\n*g_info\n*other_debug\n*other_info\n");
+    g_test_trap_assert_stderr("*g_message\n*other_message\n");
+}
+
+
+int main(int argc, char **argv)
+{
+    GLogLevelFlags fatal_mask;
+
+    fatal_mask = (GLogLevelFlags)g_log_set_always_fatal((GLogLevelFlags) G_LOG_FATAL_MASK);
+
+    g_test_init(&argc, &argv, NULL);
+
+    /* Reset fatal mask set by g_test_init() as we don't want
+     * warnings/criticals to be fatal by default since this is what some of the
+     * test cases are going to test */
+    g_log_set_always_fatal(fatal_mask & G_LOG_LEVEL_MASK);
+
+    g_test_add_func("/spice-common/spice-abort-level", test_spice_abort_level);
+    g_test_add_func("/spice-common/spice-abort-level-gwarning", test_spice_abort_level_g_warning);
+    g_test_add_func("/spice-common/spice-debug-level", test_spice_debug_level);
+    g_test_add_func("/spice-common/spice-debug-level-warning", test_spice_debug_level_warning);
+    g_test_add_func("/spice-common/spice-g-messages-debug", test_spice_g_messages_debug);
+    g_test_add_func("/spice-common/spice-g-messages-debug-all", test_spice_g_messages_debug_all);
+    g_test_add_func("/spice-common/spice-log-levels", test_log_levels);
+    g_test_add_func("/spice-common/spice-fatal-critical", test_spice_fatal_critical);
+    g_test_add_func("/spice-common/spice-non-fatal-gcritical", test_spice_non_fatal_g_critical);
+    g_test_add_func("/spice-common/spice-fatal-gcritical", test_spice_fatal_g_critical);
+    g_test_add_func("/spice-common/spice-fatal-return-if-fail", test_spice_fatal_return_if_fail);
+    g_test_add_func("/spice-common/spice-non-fatal-greturn-if-fail", test_spice_non_fatal_g_return_if_fail);
+    g_test_add_func("/spice-common/spice-fatal-warning", test_spice_fatal_warning);
+
+    return g_test_run();
+}
commit 417dbedc0b91a7a6aa00c97f7341689cc8de40b2
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Thu Jan 21 11:15:14 2016 +0100

    tests: Always build tests
    
    The next commit will introduce a test for log messages. As
    libspice-common.la behaviour varies depending on whether
    SPICE_DISABLE_ASSERT was defined at compile-time, this test will also
    take into account this preprocessor define.
    We are more likely to get a consistent build (SPICE_DISABLE_ASSERT being
    the same when building libspice-common.la and the test) if both are
    built at the same time.
    
    This commit changes that, tests are now built (but not run) at 'make'
    time rather than 'make check' time.

diff --git a/tests/Makefile.am b/tests/Makefile.am
index d612d44..92d2f62 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -1,7 +1,7 @@
 NULL =
 
 TESTS = test_marshallers
-check_PROGRAMS = test_marshallers
+noinst_PROGRAMS = $(TESTS)
 test_marshallers_SOURCES =		\
 	generated_test_marshallers.c	\
 	generated_test_marshallers.h	\
commit efd1d3cb4d8eee5e5aff61a796daf2dcf980e3c2
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Wed Nov 25 11:48:23 2015 +0100

    log: Use glib for logging
    
    spice-common has been duplicating glib logging methods for a long while.
    Now that spice-common is depending on glib, it's more consistent to use
    glib logging too. However, the code base is still using spice logging
    functions.
    This commit aims to make spice logging go through glib logging system,
    while keeping the same behaviour for the SPICE_ABORT_LEVEL and
    SPICE_DEBUG_LEVEL environment variables. They are deprecated however in
    favour of the glib alternatives (G_DEBUG and G_MESSAGES_DEBUG).
    
    Reviewed-by: Jonathon Jongsma <jjongsma at redhat.com>

diff --git a/common/log.c b/common/log.c
index df394d2..607aa82 100644
--- a/common/log.c
+++ b/common/log.c
@@ -1,5 +1,5 @@
 /*
-   Copyright (C) 2012 Red Hat, Inc.
+   Copyright (C) 2012-2015 Red Hat, Inc.
 
    This library is free software; you can redistribute it and/or
    modify it under the terms of the GNU Lesser General Public
@@ -19,6 +19,7 @@
 #include <config.h>
 #endif
 
+#include <glib.h>
 #include <stdlib.h>
 #include <stdio.h>
 #include <sys/types.h>
@@ -29,37 +30,9 @@
 #include "log.h"
 #include "backtrace.h"
 
-static int debug_level = -1;
+static int glib_debug_level = 0;
 static int abort_level = -1;
 
-static const char * spice_log_level_to_string(SpiceLogLevel level)
-{
-#ifdef _MSC_VER
-    /* MSVC++ does not implement C99 */
-    static const char *to_string[] = {
-         "ERROR",
-         "CRITICAL",
-         "Warning",
-         "Info",
-         "Debug"};
-#else
-    static const char *to_string[] = {
-        [ SPICE_LOG_LEVEL_ERROR ] = "ERROR",
-        [ SPICE_LOG_LEVEL_CRITICAL ] = "CRITICAL",
-        [ SPICE_LOG_LEVEL_WARNING ] = "Warning",
-        [ SPICE_LOG_LEVEL_INFO ] = "Info",
-        [ SPICE_LOG_LEVEL_DEBUG ] = "Debug",
-    };
-#endif
-    const char *str = NULL;
-
-    if (level < SPICE_N_ELEMENTS(to_string)) {
-        str = to_string[level];
-    }
-
-    return str;
-}
-
 #ifndef SPICE_ABORT_LEVEL_DEFAULT
 #ifdef SPICE_DISABLE_ABORT
 #define SPICE_ABORT_LEVEL_DEFAULT -1
@@ -68,41 +41,127 @@ static const char * spice_log_level_to_string(SpiceLogLevel level)
 #endif
 #endif
 
-void spice_logv(const char *log_domain,
-                SpiceLogLevel log_level,
-                const char *strloc,
-                const char *function,
-                const char *format,
-                va_list args)
+static GLogLevelFlags spice_log_level_to_glib(SpiceLogLevel level)
 {
-    const char *level = spice_log_level_to_string(log_level);
+    static GLogLevelFlags glib_levels[] = {
+        [ SPICE_LOG_LEVEL_ERROR ] = G_LOG_LEVEL_ERROR,
+        [ SPICE_LOG_LEVEL_CRITICAL ] = G_LOG_LEVEL_CRITICAL,
+        [ SPICE_LOG_LEVEL_WARNING ] = G_LOG_LEVEL_WARNING,
+        [ SPICE_LOG_LEVEL_INFO ] = G_LOG_LEVEL_INFO,
+        [ SPICE_LOG_LEVEL_DEBUG ] = G_LOG_LEVEL_DEBUG,
+    };
+    g_return_val_if_fail ((level >= 0) || (level < G_N_ELEMENTS(glib_levels)), 0);
+
+    return glib_levels[level];
+}
 
-    if (debug_level == -1) {
-        debug_level = getenv("SPICE_DEBUG_LEVEL") ? atoi(getenv("SPICE_DEBUG_LEVEL")) : SPICE_LOG_LEVEL_WARNING;
+static void spice_log_set_debug_level(void)
+{
+    if (glib_debug_level == 0) {
+        char *debug_str = getenv("SPICE_DEBUG_LEVEL");
+        if (debug_str != NULL) {
+            int debug_level;
+            char *debug_env;
+
+            /* FIXME: To be removed after enough deprecation time */
+            g_warning("Setting SPICE_DEBUG_LEVEL is deprecated, use G_MESSAGES_DEBUG instead");
+            debug_level = atoi(debug_str);
+            glib_debug_level = spice_log_level_to_glib(debug_level);
+
+            /* If the debug level is too high, make sure we don't try to enable
+             * display of glib debug logs */
+            if (debug_level < SPICE_LOG_LEVEL_INFO)
+                return;
+
+            /* Make sure GLib default log handler will show the debug messages. Messing with
+             * environment variables like this is ugly, but this only happens when the legacy
+             * SPICE_DEBUG_LEVEL is used
+             */
+            debug_env = (char *)g_getenv("G_MESSAGES_DEBUG");
+            if (debug_env == NULL) {
+                g_setenv("G_MESSAGES_DEBUG", SPICE_LOG_DOMAIN, FALSE);
+            } else {
+                debug_env = g_strconcat(debug_env, ":", SPICE_LOG_DOMAIN, NULL);
+                g_setenv("G_MESSAGES_DEBUG", SPICE_LOG_DOMAIN, FALSE);
+                g_free(debug_env);
+            }
+        }
     }
+}
+
+static void spice_log_set_abort_level(void)
+{
     if (abort_level == -1) {
-        abort_level = getenv("SPICE_ABORT_LEVEL") ? atoi(getenv("SPICE_ABORT_LEVEL")) : SPICE_ABORT_LEVEL_DEFAULT;
+        char *abort_str = getenv("SPICE_ABORT_LEVEL");
+        if (abort_str != NULL) {
+            GLogLevelFlags glib_abort_level;
+
+            /* FIXME: To be removed after enough deprecation time */
+            g_warning("Setting SPICE_ABORT_LEVEL is deprecated, use G_DEBUG instead");
+            abort_level = atoi(abort_str);
+            glib_abort_level = spice_log_level_to_glib(abort_level);
+            if (glib_abort_level != 0) {
+                unsigned int fatal_mask = G_LOG_FATAL_MASK;
+                while (glib_abort_level >= G_LOG_LEVEL_ERROR) {
+                    fatal_mask |= glib_abort_level;
+                    glib_abort_level >>= 1;
+                }
+                g_log_set_fatal_mask(SPICE_LOG_DOMAIN, fatal_mask);
+            }
+        } else {
+            abort_level = SPICE_ABORT_LEVEL_DEFAULT;
+        }
     }
+}
 
-    if (debug_level < (int) log_level)
-        return;
-
-    fprintf(stderr, "(%s:%d): ", getenv("_"), getpid());
-
-    if (log_domain) {
-        fprintf(stderr, "%s-", log_domain);
+static void spice_logger(const gchar *log_domain,
+                         GLogLevelFlags log_level,
+                         const gchar *message,
+                         gpointer user_data)
+{
+    if (glib_debug_level != 0) {
+        if ((log_level & G_LOG_LEVEL_MASK) > glib_debug_level)
+            return; // do not print anything
     }
-    if (level) {
-        fprintf(stderr, "%s **: ", level);
+    g_log_default_handler(log_domain, log_level, message, NULL);
+}
+
+static inline void spice_log_init_once(void)
+{
+    static gsize logging_initialized = FALSE;
+
+    if (g_once_init_enter(&logging_initialized)) {
+        spice_log_set_debug_level();
+        spice_log_set_abort_level();
+        g_once_init_leave (&logging_initialized, TRUE);
+        g_log_set_handler(SPICE_LOG_DOMAIN,
+                          G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
+                          spice_logger, NULL);
     }
+}
+
+static void spice_logv(const char *log_domain,
+                       SpiceLogLevel log_level,
+                       const char *strloc,
+                       const char *function,
+                       const char *format,
+                       va_list args)
+{
+    GString *log_msg;
+
+    spice_log_init_once();
+
+    g_return_if_fail(spice_log_level_to_glib(log_level) != 0);
+
+    log_msg = g_string_new(NULL);
     if (strloc && function) {
-        fprintf(stderr, "%s:%s: ", strloc, function);
+        g_string_append_printf(log_msg, "%s:%s: ", strloc, function);
     }
     if (format) {
-        vfprintf(stderr, format, args);
+        g_string_append_vprintf(log_msg, format, args);
     }
-
-    fprintf(stderr, "\n");
+    g_log(log_domain, spice_log_level_to_glib(log_level), "%s", log_msg->str);
+    g_string_free(log_msg, TRUE);
 
     if (abort_level != -1 && abort_level >= (int) log_level) {
         spice_backtrace();
diff --git a/common/log.h b/common/log.h
index 38a7988..a56105a 100644
--- a/common/log.h
+++ b/common/log.h
@@ -40,13 +40,6 @@ typedef enum {
     SPICE_LOG_LEVEL_DEBUG,
 } SpiceLogLevel;
 
-void spice_logv(const char *log_domain,
-                SpiceLogLevel log_level,
-                const char *strloc,
-                const char *function,
-                const char *format,
-                va_list args) SPICE_ATTR_PRINTF(5, 0);
-
 void spice_log(const char *log_domain,
                SpiceLogLevel log_level,
                const char *strloc,
commit 2ff25b75674d0df2d7e2f6e66f3d1e1be5c02606
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Thu Nov 26 17:52:38 2015 +0100

    log: Remove unneeded #ifdef/#endif
    
    If header guards are working as expected, there should not be multiple
    definitions of these macros. If they are redefined somewhere else, this
    is a bug we want to fix.
    
    Acked-by: Frediano Ziglio <fziglio at redhat.com>
    Acked-by: Jonathon Jongsma <jjongsma at redhat.com>

diff --git a/common/log.h b/common/log.h
index 1c54b0f..38a7988 100644
--- a/common/log.h
+++ b/common/log.h
@@ -54,96 +54,70 @@ void spice_log(const char *log_domain,
                const char *format,
                ...) SPICE_ATTR_PRINTF(5, 6);
 
-#ifndef spice_return_if_fail
 #define spice_return_if_fail(x) G_STMT_START {                          \
     if G_LIKELY(x) { } else {                                           \
         spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, G_STRFUNC, "condition `%s' failed", #x); \
         return;                                                         \
     }                                                                   \
 } G_STMT_END
-#endif
 
-#ifndef spice_return_val_if_fail
 #define spice_return_val_if_fail(x, val) G_STMT_START {                 \
     if G_LIKELY(x) { } else {                                           \
         spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, __FUNCTION__, "condition `%s' failed", #x); \
         return (val);                                                   \
     }                                                                   \
 } G_STMT_END
-#endif
 
-#ifndef spice_warn_if_reached
 #define spice_warn_if_reached() G_STMT_START {                          \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_WARNING, SPICE_STRLOC, __FUNCTION__, "should not be reached"); \
 } G_STMT_END
-#endif
 
-#ifndef spice_printerr
 #define spice_printerr(format, ...) G_STMT_START {                      \
     fprintf(stderr, "%s: " format "\n", __FUNCTION__, ## __VA_ARGS__);  \
 } G_STMT_END
-#endif
 
-#ifndef spice_info
 #define spice_info(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_INFO, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
 } G_STMT_END
-#endif
 
-#ifndef spice_debug
 #define spice_debug(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_DEBUG, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
 } G_STMT_END
-#endif
 
-#ifndef spice_warning
 #define spice_warning(format, ...) G_STMT_START {                       \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_WARNING, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
 } G_STMT_END
-#endif
 
-#ifndef spice_critical
 #define spice_critical(format, ...) G_STMT_START {                          \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
 } G_STMT_END
-#endif
 
-#ifndef spice_error
 #define spice_error(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_ERROR, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
 } G_STMT_END
-#endif
 
-#ifndef spice_warn_if_fail
 #define spice_warn_if_fail(x) G_STMT_START {            \
     if G_LIKELY(x) { } else {                           \
         spice_warning("condition `%s' failed", #x);     \
     }                                                   \
 } G_STMT_END
-#endif
 
-#ifndef spice_warn_if
 #define spice_warn_if(x) G_STMT_START {                 \
     if G_UNLIKELY(x) {                                  \
         spice_warning("condition `%s' reached", #x);    \
     }                                                   \
 } G_STMT_END
-#endif
 
-#ifndef spice_assert
 #define spice_assert(x) G_STMT_START {                  \
     if G_LIKELY(x) { } else {                           \
         spice_error("assertion `%s' failed", #x);       \
     }                                                   \
 } G_STMT_END
-#endif
 
 /* FIXME: improve that some day.. */
-#ifndef spice_static_assert
 #define spice_static_assert(x) SPICE_STMT_START {       \
     spice_assert(x);                                    \
 } SPICE_STMT_END
-#endif
 
 SPICE_END_DECLS
 
commit 838596a257f1c103b6d82729c6563cc61d50cca1
Author: Christophe Fergeau <cfergeau at redhat.com>
Date:   Thu Nov 26 17:49:11 2015 +0100

    log: Use more glib macros
    
    No need to have our own SPICE_STMT_BEGIN/END and SPICE_STRINGIFY
    
    Acked-by: Jonathon Jongsma <jjongsma at redhat.com>

diff --git a/common/log.h b/common/log.h
index d9e6023..1c54b0f 100644
--- a/common/log.h
+++ b/common/log.h
@@ -18,6 +18,8 @@
 #ifndef H_SPICE_LOG
 #define H_SPICE_LOG
 
+#include <glib.h>
+
 #include <spice/macros.h>
 #include <stdarg.h>
 #include "macros.h"
@@ -28,10 +30,7 @@ SPICE_BEGIN_DECLS
 #define SPICE_LOG_DOMAIN "Spice"
 #endif
 
-#define SPICE_STRINGIFY(x) SPICE_STRINGIFY_ARG (x)
-#define SPICE_STRINGIFY_ARG(x) #x
-
-#define SPICE_STRLOC  __FILE__ ":" SPICE_STRINGIFY (__LINE__)
+#define SPICE_STRLOC  __FILE__ ":" G_STRINGIFY (__LINE__)
 
 typedef enum {
     SPICE_LOG_LEVEL_ERROR,
@@ -56,87 +55,87 @@ void spice_log(const char *log_domain,
                ...) SPICE_ATTR_PRINTF(5, 6);
 
 #ifndef spice_return_if_fail
-#define spice_return_if_fail(x) SPICE_STMT_START {                      \
-    if SPICE_LIKELY(x) { } else {                                       \
-        spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, __FUNCTION__, "condition `%s' failed", #x); \
+#define spice_return_if_fail(x) G_STMT_START {                          \
+    if G_LIKELY(x) { } else {                                           \
+        spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, G_STRFUNC, "condition `%s' failed", #x); \
         return;                                                         \
     }                                                                   \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_return_val_if_fail
-#define spice_return_val_if_fail(x, val) SPICE_STMT_START {             \
-    if SPICE_LIKELY(x) { } else {                                       \
+#define spice_return_val_if_fail(x, val) G_STMT_START {                 \
+    if G_LIKELY(x) { } else {                                           \
         spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, __FUNCTION__, "condition `%s' failed", #x); \
         return (val);                                                   \
     }                                                                   \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_warn_if_reached
-#define spice_warn_if_reached() SPICE_STMT_START {                      \
+#define spice_warn_if_reached() G_STMT_START {                          \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_WARNING, SPICE_STRLOC, __FUNCTION__, "should not be reached"); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_printerr
-#define spice_printerr(format, ...) SPICE_STMT_START {                  \
+#define spice_printerr(format, ...) G_STMT_START {                      \
     fprintf(stderr, "%s: " format "\n", __FUNCTION__, ## __VA_ARGS__);  \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_info
-#define spice_info(format, ...) SPICE_STMT_START {                     \
+#define spice_info(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_INFO, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_debug
-#define spice_debug(format, ...) SPICE_STMT_START {                     \
+#define spice_debug(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_DEBUG, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_warning
-#define spice_warning(format, ...) SPICE_STMT_START {                   \
+#define spice_warning(format, ...) G_STMT_START {                       \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_WARNING, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_critical
-#define spice_critical(format, ...) SPICE_STMT_START {                      \
+#define spice_critical(format, ...) G_STMT_START {                          \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_CRITICAL, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_error
-#define spice_error(format, ...) SPICE_STMT_START {                     \
+#define spice_error(format, ...) G_STMT_START {                         \
     spice_log(SPICE_LOG_DOMAIN, SPICE_LOG_LEVEL_ERROR, SPICE_STRLOC, __FUNCTION__, format, ## __VA_ARGS__); \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_warn_if_fail
-#define spice_warn_if_fail(x) SPICE_STMT_START {        \
-    if SPICE_LIKELY(x) { } else {                       \
+#define spice_warn_if_fail(x) G_STMT_START {            \
+    if G_LIKELY(x) { } else {                           \
         spice_warning("condition `%s' failed", #x);     \
     }                                                   \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_warn_if
-#define spice_warn_if(x) SPICE_STMT_START {             \
-    if SPICE_UNLIKELY(x) {                              \
+#define spice_warn_if(x) G_STMT_START {                 \
+    if G_UNLIKELY(x) {                                  \
         spice_warning("condition `%s' reached", #x);    \
     }                                                   \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 #ifndef spice_assert
-#define spice_assert(x) SPICE_STMT_START {              \
-    if SPICE_LIKELY(x) { } else {                       \
+#define spice_assert(x) G_STMT_START {                  \
+    if G_LIKELY(x) { } else {                           \
         spice_error("assertion `%s' failed", #x);       \
     }                                                   \
-} SPICE_STMT_END
+} G_STMT_END
 #endif
 
 /* FIXME: improve that some day.. */


More information about the Spice-commits mailing list