[Spice-devel] [spice-common PATCH v2 04/17] log: allow filtering logs with subdomains

Victor Toso victortoso at redhat.com
Fri Jan 8 00:51:34 PST 2016


Each .c file that want to use spice logging must include common/log.h
and define its subdomain with SPICE_LOG_DOMAIN_STATIC (name) helper.

This static variable is initialized in its first use depending on
SPICE_DEBUG env var.

examples:

- debug level for all subdomains
export SPICE_DEBUG=6
export SPICE_DEBUG=*:debug
export SPICE_DEBUG=*:*

- only debug audio subdomain
export SPICE_DEBUG=*:-,audio:*
export SPICE_DEBUG=*:none,audio:debug

- warn or worse for everything, debug usb
export SPICE_DEBUG=*:warning,usb:*
export SPICE_DEBUG=3,usb:debug

spice-common subdomains created in this patch are:
"log"        : log.c, rop3.c (should be generic subdomain)
"canvas"     : canvas_utils.c and canvas_base.c
"compression": lz.c, quic.c
"memory"     : mem.c
"pixman"     : pixman_utils.c
"region"     : region.c
"ssl"        : ssl_verify.c
---
 common/canvas_base.c  |   3 +-
 common/canvas_utils.c |   1 +
 common/log.c          | 173 ++++++++++++++++++++++++++++++++++++++++++++++----
 common/log.h          |  25 ++++++--
 common/lz.c           |   2 +
 common/mem.c          |   2 +
 common/pixman_utils.c |   1 +
 common/quic.c         |   4 +-
 common/region.c       |   2 +
 common/rop3.c         |   4 +-
 common/ssl_verify.c   |   3 +-
 11 files changed, 196 insertions(+), 24 deletions(-)

diff --git a/common/canvas_base.c b/common/canvas_base.c
index d918441..0b3450a 100644
--- a/common/canvas_base.c
+++ b/common/canvas_base.c
@@ -19,6 +19,8 @@
 #ifdef HAVE_CONFIG_H
 #include <config.h>
 #endif
+#include "log.h"
+SPICE_LOG_DOMAIN_STATIC("canvas");
 
 #include <stdarg.h>
 #include <stdlib.h>
@@ -33,7 +35,6 @@
 #include <lz4.h>
 #endif
 #include <spice/macros.h>
-#include "log.h"
 #include "quic.h"
 #include "lz.h"
 #include "canvas_base.h"
diff --git a/common/canvas_utils.c b/common/canvas_utils.c
index c5813f4..f86451b 100644
--- a/common/canvas_utils.c
+++ b/common/canvas_utils.c
@@ -19,6 +19,7 @@
 #include <config.h>
 #endif
 #include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("canvas");
 
 #include "canvas_utils.h"
 #include "mem.h"
diff --git a/common/log.c b/common/log.c
index 697c983..cc87170 100644
--- a/common/log.c
+++ b/common/log.c
@@ -23,6 +23,8 @@
 #include <stdlib.h>
 #include <stdio.h>
 #include <sys/types.h>
+#include <string.h>
+#include <errno.h>
 #ifndef _MSC_VER
 #include <unistd.h>
 #endif
@@ -30,9 +32,20 @@
 #include "log.h"
 #include "backtrace.h"
 
+SPICE_LOG_DOMAIN_STATIC("log");
+
+const gchar *spice_debug_env = NULL;
+
 static int glib_debug_level = 0;
 static int abort_level = -1;
 
+static gchar *level2name[SPICE_LOG_LEVEL_LAST] = {
+    "none", "error", "critical", "warning", "message", "info", "debug"
+};
+
+#define SPICE_DOMAIN_STR_ALL    "*"
+#define SPICE_DOMAIN_STR_NONE   "-"
+
 #ifndef SPICE_ABORT_LEVEL_DEFAULT
 #ifdef SPICE_DISABLE_ABORT
 #define SPICE_ABORT_LEVEL_DEFAULT -1
@@ -43,7 +56,8 @@ static int abort_level = -1;
 
 static GLogLevelFlags spice_log_level_to_glib(SpiceLogLevel level)
 {
-    static GLogLevelFlags glib_levels[] = {
+    static GLogLevelFlags glib_levels[SPICE_LOG_LEVEL_LAST] = {
+        [ SPICE_LOG_LEVEL_NONE ] = 0,
         [ SPICE_LOG_LEVEL_ERROR ] = G_LOG_LEVEL_ERROR,
         [ SPICE_LOG_LEVEL_CRITICAL ] = G_LOG_LEVEL_CRITICAL,
         [ SPICE_LOG_LEVEL_WARNING ] = G_LOG_LEVEL_WARNING,
@@ -51,7 +65,7 @@ static GLogLevelFlags spice_log_level_to_glib(SpiceLogLevel level)
         [ 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);
+    g_return_val_if_fail ((level >= 0) && (level < SPICE_LOG_LEVEL_LAST), 0);
 
     return glib_levels[level];
 }
@@ -112,33 +126,161 @@ static void spice_log_set_abort_level(void)
     }
 }
 
+static SpiceLogLevel domain_get_level_from_spec_str(const gchar *level_spec)
+{
+  guint i;
+  long int level_num;
+  char *tail;
+
+  /* "-" or "none" (from level2name) can be used to disable all logging */
+  if (strcmp(level_spec, SPICE_DOMAIN_STR_NONE) == 0) {
+    return SPICE_LOG_LEVEL_NONE;
+  }
+
+  /* '*' means everything */
+  if (strcmp(level_spec, SPICE_DOMAIN_STR_ALL) == 0) {
+    return SPICE_LOG_LEVEL_LAST - 1;
+  }
+
+  errno = 0;
+  level_num = strtol(level_spec, &tail, 0);
+  if (!errno
+      && tail != level_spec
+      && level_num >= SPICE_LOG_LEVEL_NONE
+      && level_num < SPICE_LOG_LEVEL_LAST)
+      return (SpiceLogLevel) level_num;
+
+  /* match level by name */
+  for (i = 0; i < SPICE_LOG_LEVEL_LAST; i++)
+    if (g_ascii_strcasecmp(level_spec, level2name[i]) == 0)
+      return i;
+
+  /* If the spec does not match one of our levels, just return the current
+   * default log level */
+  return glib_debug_level;
+}
+
+static SpiceLogLevel domain_get_level_from_numeric_str(const gchar *str)
+{
+    /* Try for backwards compatiblity */
+    char *tail;
+    long int level_num = SPICE_LOG_LEVEL_LAST;
+
+    level_num = strtol(str, &tail, 0);
+    if (level_num >= SPICE_LOG_LEVEL_NONE
+        && level_num < SPICE_LOG_LEVEL_LAST) {
+        return (SpiceLogLevel) level_num;
+    }
+
+    return glib_debug_level;
+}
+
+/* Look by @domain in SPICE_DEBUG and returns its level */
+static SpiceLogLevel domain_get_domain_level_from_env(const gchar *domain_name)
+{
+    gchar **pairs;
+    gchar **pair;
+
+    if (spice_debug_env == NULL || domain_name == NULL) {
+        return glib_debug_level;
+    }
+
+    pair = pairs = g_strsplit(spice_debug_env, ",", 0);
+
+    while (*pair) {
+        SpiceLogDomain *domain;
+        gchar **info;
+
+        /* [0] is the domain and [1] the domain's level */
+        info = g_strsplit(*pair, ":", 2);
+        if (info[0] && info[1]) {
+            if (g_strcmp0(domain_name, info[0]) == 0) {
+                SpiceLogLevel level = domain_get_level_from_spec_str(info[1]);
+                g_strfreev(info);
+                g_strfreev(pairs);
+                return level;
+            }
+            g_strfreev(info);
+        } else {
+            if (strcmp(domain_name, SPICE_DOMAIN_STR_ALL) == 0) {
+                /* Backwards compatibility for SPICE_DEBUG=<log-level> */
+                SpiceLogLevel level = domain_get_level_from_numeric_str(*pair);
+                g_strfreev(info);
+                g_strfreev(pairs);
+                return level;
+            }
+            g_strfreev(info);
+        }
+
+        pair++;
+    }
+
+    g_strfreev(pairs);
+    return glib_debug_level;
+}
+
+static void domain_init(void)
+{
+    const gchar *messages_env;
+
+    spice_debug_env = g_getenv("SPICE_DEBUG");
+    if (spice_debug_env == NULL) {
+        return;
+    }
+
+    glib_debug_level = domain_get_domain_level_from_env(SPICE_DOMAIN_STR_ALL);
+
+    /* Add Spice log domain to G_MESSAGES_DEBUG, so the messages are not
+     * filtered by default handler */
+    messages_env = g_getenv ("G_MESSAGES_DEBUG");
+    if (!messages_env) {
+        g_setenv ("G_MESSAGES_DEBUG", G_LOG_DOMAIN, FALSE);
+    } else if (g_strcmp0 (messages_env, "all") != 0) {
+        gchar *new_messages_env;
+        new_messages_env = g_strconcat (messages_env, ":" G_LOG_DOMAIN, NULL);
+        g_setenv ("G_MESSAGES_DEBUG", new_messages_env, TRUE);
+        g_free (new_messages_env);
+    }
+}
+
+static void domain_set_domain_level(SpiceLogDomain *domain)
+{
+    if (domain == NULL || domain->initialized == TRUE) {
+        return;
+    }
+
+    domain->initialized = TRUE;
+    domain->log_level = domain_get_domain_level_from_env(domain->name);
+    spice_debug ("Domain: %s, Level: %s", domain->name,
+                 level2name[domain->log_level]);
+}
+
 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
-    }
-    g_log_default_handler(log_domain, log_level, message, NULL);
+    g_log_default_handler(G_LOG_DOMAIN, log_level, message, NULL);
 }
 
-static void spice_log_init_once(void)
+static void spice_log_init_once(SpiceLogDomain *domain)
 {
     static gsize logging_initialized = FALSE;
 
     if (g_once_init_enter(&logging_initialized)) {
         spice_log_set_debug_level();
         spice_log_set_abort_level();
+        domain_init();
         g_once_init_leave (&logging_initialized, TRUE);
         g_log_set_handler(G_LOG_DOMAIN,
                           G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
                           spice_logger, NULL);
     }
+
+    domain_set_domain_level(domain);
 }
 
-static void spice_logv(const char *log_domain,
+static void spice_logv(SpiceLogDomain *domain,
                        SpiceLogLevel log_level,
                        const char *strloc,
                        const char *function,
@@ -147,10 +289,14 @@ static void spice_logv(const char *log_domain,
 {
     GString *log_msg;
 
-    spice_log_init_once();
+    spice_log_init_once(domain);
 
     g_return_if_fail(spice_log_level_to_glib(log_level) != 0);
 
+    if (domain->log_level < log_level) {
+        return;
+    }
+
     log_msg = g_string_new(NULL);
     if (strloc && function) {
         g_string_append_printf(log_msg, "%s:%s: ", strloc, function);
@@ -158,7 +304,8 @@ static void spice_logv(const char *log_domain,
     if (format) {
         g_string_append_vprintf(log_msg, format, args);
     }
-    g_log(log_domain, spice_log_level_to_glib(log_level), "%s", log_msg->str);
+    g_log(G_LOG_DOMAIN, spice_log_level_to_glib(log_level),
+          "[%s] %s", domain->name, log_msg->str);
     g_string_free(log_msg, TRUE);
 
     if (abort_level != -1 && abort_level >= (int) log_level) {
@@ -167,7 +314,7 @@ static void spice_logv(const char *log_domain,
     }
 }
 
-void spice_log(const char *log_domain,
+void spice_log(SpiceLogDomain *domain,
                SpiceLogLevel log_level,
                const char *strloc,
                const char *function,
@@ -177,6 +324,6 @@ void spice_log(const char *log_domain,
     va_list args;
 
     va_start (args, format);
-    spice_logv (log_domain, log_level, strloc, function, format, args);
+    spice_logv (domain, log_level, strloc, function, format, args);
     va_end (args);
 }
diff --git a/common/log.h b/common/log.h
index 238df82..a9e9c44 100644
--- a/common/log.h
+++ b/common/log.h
@@ -26,31 +26,42 @@
 
 SPICE_BEGIN_DECLS
 
-#ifndef SPICE_LOG_DOMAIN
-#define SPICE_LOG_DOMAIN "Spice"
-#endif
-
 #define SPICE_STRLOC  __FILE__ ":" G_STRINGIFY (__LINE__)
 
 typedef enum {
+    SPICE_LOG_LEVEL_NONE,
     SPICE_LOG_LEVEL_ERROR,
     SPICE_LOG_LEVEL_CRITICAL,
     SPICE_LOG_LEVEL_WARNING,
     SPICE_LOG_LEVEL_MESSAGE,
     SPICE_LOG_LEVEL_INFO,
     SPICE_LOG_LEVEL_DEBUG,
+
+    SPICE_LOG_LEVEL_LAST
 } SpiceLogLevel;
 
-void spice_log(const char *log_domain,
+typedef struct {
+  const gchar *name;
+  SpiceLogLevel log_level;
+  gboolean initialized;
+} SpiceLogDomain;
+
+#define SPICE_LOG_DOMAIN_STATIC(n)                                  \
+    static SPICE_GNUC_UNUSED SpiceLogDomain SPICE_LOG_DOMAIN = {    \
+        .name = "" n "",                                            \
+        .log_level = SPICE_LOG_LEVEL_ERROR,                         \
+        .initialized = FALSE,                                       \
+    };
+
+void spice_log(SpiceLogDomain *domain,
                SpiceLogLevel log_level,
                const char *strloc,
                const char *function,
                const char *format,
                ...) SPICE_ATTR_PRINTF(5, 6);
 
-
 #define SPICE_LOG(level, format, ...) G_STMT_START {    \
-    spice_log(SPICE_LOG_DOMAIN,                         \
+    spice_log(&SPICE_LOG_DOMAIN,                        \
               (level),                                  \
               SPICE_STRLOC,                             \
               G_STRFUNC,                                \
diff --git a/common/lz.c b/common/lz.c
index d1c4033..7bfaed8 100644
--- a/common/lz.c
+++ b/common/lz.c
@@ -48,6 +48,8 @@
 #endif
 
 #include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("compression")
+
 #include "lz.h"
 
 #define HASH_LOG 13
diff --git a/common/mem.c b/common/mem.c
index 2fda6f3..0128e2b 100644
--- a/common/mem.c
+++ b/common/mem.c
@@ -20,6 +20,8 @@
 #endif
 
 #include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("memory")
+
 #include "mem.h"
 
 #include <string.h>
diff --git a/common/pixman_utils.c b/common/pixman_utils.c
index 81806c9..7007c41 100644
--- a/common/pixman_utils.c
+++ b/common/pixman_utils.c
@@ -19,6 +19,7 @@
 #include <config.h>
 #endif
 #include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("pixman")
 
 #include "pixman_utils.h"
 
diff --git a/common/quic.c b/common/quic.c
index a9bd215..71556d1 100644
--- a/common/quic.c
+++ b/common/quic.c
@@ -23,10 +23,12 @@
 #include <config.h>
 #endif
 
+#include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("compression");
+
 #include <glib.h>
 
 #include "quic.h"
-#include "spice_common.h"
 #include "bitops.h"
 
 #define RLE
diff --git a/common/region.c b/common/region.c
index 14a27ed..f00a912 100644
--- a/common/region.c
+++ b/common/region.c
@@ -18,6 +18,8 @@
 #ifdef HAVE_CONFIG_H
 #include <config.h>
 #endif
+#include "log.h"
+SPICE_LOG_DOMAIN_STATIC("region");
 
 #include <stdio.h>
 #include <string.h>
diff --git a/common/rop3.c b/common/rop3.c
index 1a18fe9..4f79a03 100644
--- a/common/rop3.c
+++ b/common/rop3.c
@@ -19,8 +19,10 @@
 #include <config.h>
 #endif
 
-#include "rop3.h"
 #include "spice_common.h"
+SPICE_LOG_DOMAIN_STATIC("common");
+
+#include "rop3.h"
 
 typedef void (*rop3_with_pattern_handler_t)(pixman_image_t *d, pixman_image_t *s,
                                             SpicePoint *src_pos, pixman_image_t *p,
diff --git a/common/ssl_verify.c b/common/ssl_verify.c
index 601252e..1ef1d19 100644
--- a/common/ssl_verify.c
+++ b/common/ssl_verify.c
@@ -19,10 +19,11 @@
 #ifdef HAVE_CONFIG_H
 #include <config.h>
 #endif
+#include "log.h"
+SPICE_LOG_DOMAIN_STATIC("ssl");
 
 #include "mem.h"
 #include "ssl_verify.h"
-#include "log.h"
 
 #ifndef WIN32
 #include <sys/socket.h>
-- 
2.5.0



More information about the Spice-devel mailing list