[Spice-devel] [spice-common v3 2/7] log: Use glib for logging

Victor Toso lists at victortoso.com
Wed Dec 16 06:05:07 PST 2015


Hi,

On Wed, Dec 16, 2015 at 02:27:08PM +0100, Christophe Fergeau wrote:
> 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).

Have you consider using G_LOG_DOMAIN for default domain?

>
> Reviewed-by: Jonathon Jongsma <jjongsma at redhat.com>
Reviewed-by: Victor Toso <victortoso at redhat.com>

> ---
>  common/log.c | 162 ++++++++++++++++++++++++++++++++++++++++-------------------
>  common/log.h |   7 ---
>  2 files changed, 109 insertions(+), 60 deletions(-)
>
> diff --git a/common/log.c b/common/log.c
> index fc5c129..7d45623 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,124 @@ 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);
> -
> -    if (debug_level == -1) {
> -        debug_level = getenv("SPICE_DEBUG_LEVEL") ? atoi(getenv("SPICE_DEBUG_LEVEL")) : SPICE_LOG_LEVEL_WARNING;
> +    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);

I think this should be an AND instead of OR

It might be useful to have SPICE_LOG_LEVEL_LAST for checks without the
need of G_N_ELEMENTS.

I'm particulary interested in having SPICE_LOG_LEVEL_NONE = 0 instead
of SPICE_LOG_LEVEL_ERROR holding that value.

SPICE_DEBUG=1 wold be ERROR instead of CRITICAL then.

> +
> +    return glib_levels[level];
> +}
> +
> +static void spice_log_set_debug_level(void)
> +{
> +    if (glib_debug_level == 0) {

  if (glib_debug_level > 0) {
      return;
  }

to decrease indentation level?

> +        char *debug_str = getenv("SPICE_DEBUG_LEVEL");
> +        if (debug_str != NULL) {

same for if (debug_str == NULL)

> +            int debug_level;
> +            char *debug_env;
> +
> +            g_warning("Setting SPICE_DEBUG_LEVEL is deprecated, use G_MESSAGES_DEBUG instead");
> +            debug_level = atoi(getenv("SPICE_DEBUG_LEVEL"));
> +            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;
> +            g_warning("Setting SPICE_ABORT_LEVEL is deprecated, use G_DEBUG instead");
> +            abort_level = atoi(getenv("SPICE_ABORT_LEVEL"));
> +            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;
> +        }

Same comment of indentation by using early returns... but that's just a
suggestion, feel free to ignore it.

>      }
> +}
>
> -    if (debug_level < (int) log_level)
> -        return;
> +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);
> +}
>
> -    fprintf(stderr, "(%s:%d): ", getenv("_"), getpid());
> +static void spice_log_init_once(void)
> +{
> +    static gsize logging_initialized = FALSE;
>
> -    if (log_domain) {
> -        fprintf(stderr, "%s-", log_domain);
> -    }
> -    if (level) {
> -        fprintf(stderr, "%s **: ", level);
> +    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 d9e6023..f336909 100644
> --- a/common/log.h
> +++ b/common/log.h
> @@ -41,13 +41,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,
> -- 
> 2.5.0
> 
> _______________________________________________
> Spice-devel mailing list
> Spice-devel at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/spice-devel


More information about the Spice-devel mailing list