[Spice-devel] [spice-common PATCH v1 4/13] log: allow filtering debug using domains

Marc-André Lureau mlureau at redhat.com
Fri Dec 11 09:19:30 PST 2015



----- Original Message -----
> 
> 
> ----- Original Message -----
> > ---
> >  common/log.c | 241
> >  ++++++++++++++++++++++++++++++++++++++++++++++++++++++++---
> >  common/log.h |  38 ++++++++--
> >  2 files changed, 264 insertions(+), 15 deletions(-)
> > 
> > diff --git a/common/log.c b/common/log.c
> > index 19a58f0..cfd2ba9 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"
> >  
> > +struct _SpiceLogDomain {
> > +  gchar *name;
> > +  SpiceLogLevel log_level;
> > +  gint ref;
> > +};
> > +
> > +/* This is our default log variable, in case on is not defined */
> > +SpiceLogDomain *SPICE_LOG_DOMAIN = NULL;
> > +
> >  static int debug_level = -1;
> >  static int abort_level = -1;
> >  
> > +static GSList *log_domains = NULL;
> > +
> >  #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,8 @@ 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 >= SPICE_LOG_LEVEL_NONE, 0);
> > +    g_return_val_if_fail (level < SPICE_LOG_LEVEL_LAST, 0);
> >  
> >      return glib_levels[level];
> >  }
> > @@ -93,7 +108,203 @@ static void spice_log_set_abort_level(void)
> >      }
> >  }
> >  
> > -static void spice_logv(const char *log_domain,
> > +static gchar *name2level[SPICE_LOG_LEVEL_LAST] = {
> > +    "none", "error", "warning", "message", "info", "debug"
> > +};
> > +
> > +static SpiceLogLevel get_log_level_from_spec(const gchar *level_spec)
> > +{
> > +  guint i;
> > +  long int level_num;
> > +  char *tail;
> > +
> > +  /* "-" or "none" (from name2level) can be used to disable all logging */
> > +  if (strcmp(level_spec, "-") == 0) {
> > +    return SPICE_LOG_LEVEL_NONE;
> > +  }
> > +
> > +  /* '*' means everything */
> > +  if (strcmp(level_spec, "*") == 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, name2level[i]) == 0)
> > +      return i;
> > +
> > +  /* If the spec does not match one of our levels, just return the current
> > +   * default log level */
> > +  return debug_level;
> > +}
> > +
> > +static SpiceLogDomain *find_domain_by_name (const gchar *name)
> > +{
> > +    GSList *list;
> > +
> > +    for (list = log_domains; list != NULL; list = g_slist_next (list)) {
> > +        SpiceLogDomain *log_domain = list->data;
> > +
> > +        if (g_strcmp0 (log_domain->name, name) == 0)
> > +            return log_domain;
> > +    }
> > +
> > +    return NULL;
> > +}
> > +
> > +static void spice_log_domain_set_level_all (SpiceLogLevel level)
> > +{
> > +    GSList *list;
> > +
> > +    debug_level = level;
> > +
> > +    for (list = log_domains; list; list = g_slist_next (list)) {
> > +        SpiceLogDomain *log_domain = list->data;
> > +        log_domain->log_level = level;
> > +    }
> > +}
> > +
> > +static gboolean set_debug_from_numeric_value(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) {
> > +        spice_log_domain_set_level_all (level_num);
> > +        g_debug("all domains are level '%s'", str);
> > +        return TRUE;
> > +    }
> > +
> > +    return FALSE;
> > +}
> > +
> > +static void configure_log_domains(const gchar *domains)
> > +{
> > +    gchar **pairs;
> > +    gchar **pair;
> > +
> > +    pair = pairs = g_strsplit(domains, ",", 0);
> > +
> > +    /* Backwards compatibility */
> > +    if (pair == NULL) {
> > +        set_debug_from_numeric_value(domains);
> > +        return;
> > +    }
> > +
> > +    while (*pair) {
> > +        SpiceLogDomain *domain;
> > +        gchar **pair_info;
> > +
> > +        pair_info = g_strsplit(*pair, ":", 2);
> > +        if (pair_info[0] && pair_info[1]) {
> > +            gchar *domain_spec = pair_info[0];
> > +            gchar *level_spec = pair_info[1];
> > +            SpiceLogLevel level;
> > +
> > +            level = get_log_level_from_spec(level_spec);
> > +
> > +            if (strcmp(domain_spec, "*") == 0) {
> > +                spice_log_domain_set_level_all (level);
> > +                g_debug("all domains are level '%s'", level_spec);
> > +                g_strfreev (pair_info);
> > +                pair++;
> > +                continue;
> > +            }
> > +
> > +            domain = spice_log_domain_new(domain_spec);
> > +            domain->log_level = level;
> > +            g_debug("domain: '%s', level: '%s'", domain_spec, level_spec);
> > +            g_strfreev(pair_info);
> > +        } else {
> > +            /* Backwards compatibility */
> > +            if (!set_debug_from_numeric_value(*pair)) {
> > +                g_debug("invalid log spec: '%s'", *pair);
> > +            }
> > +        }
> > +        pair++;
> > +    }
> > +    g_strfreev(pairs);
> > +}
> > +
> > +void spice_log_domain_free (SpiceLogDomain *domain)
> > +{
> > +    domain->ref -= 1;
> > +    if (domain->ref > 0) {
> > +        return;
> > +    }
> > +
> > +    log_domains = g_slist_remove (log_domains, domain);
> > +    g_free (domain->name);
> > +    g_slice_free (SpiceLogDomain, domain);
> > +
> > +    /* FIXME: We probably need to do the spice_log_domain_cleanup()
> > +     * in case all domains created by spice were freed. */
> > +}
> > +
> > +SpiceLogDomain *spice_log_domain_new (const gchar *name)
> > +{
> > +    SpiceLogDomain *domain;
> > +
> > +    if (*name == '\0') {
> > +        return SPICE_LOG_DOMAIN;
> > +    }
> > +
> > +    domain = find_domain_by_name(name);
> > +    if (domain == NULL) {
> > +        domain = g_slice_new0(SpiceLogDomain);
> > +        domain->log_level = debug_level;
> > +        domain->name = g_strdup(name);
> > +
> > +        log_domains = g_slist_prepend (log_domains, domain);
> > +    }
> > +    domain->ref += 1;
> > +
> > +    return domain;
> > +}
> > +
> > +static void domain_init(void)
> > +{
> > +    const gchar *log_env;
> > +    const gchar *messages_env;
> > +
> > +    spice_log_set_debug_level();
> > +    spice_log_set_abort_level();
> > +
> > +    /* Set default domain */
> > +    SPICE_LOG_DOMAIN = spice_log_domain_new ("log");
> > +
> > +    log_env = g_getenv("SPICE_DEBUG");
> > +    if (log_env == NULL) {
> > +        return;
> > +    }
> > +
> > +    configure_log_domains(log_env);
> > +
> > +    /* 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 spice_logv(SpiceLogDomain *domain,
> >                         SpiceLogLevel log_level,
> >                         const char *strloc,
> >                         const char *function,
> > @@ -101,13 +312,11 @@ static void spice_logv(const char *log_domain,
> >                         va_list args)
> >  {
> >      GString *log_msg;
> > -    static gsize logging_initialized = FALSE;
> >  
> >      g_return_if_fail(spice_log_level_to_glib(log_level) != 0);
> > -    if (g_once_init_enter(&logging_initialized)) {
> > -        spice_log_set_debug_level();
> > -        spice_log_set_abort_level();
> > -        g_once_init_leave (&logging_initialized, TRUE);
> > +
> > +    if (domain->log_level < log_level) {
> > +        return;
> >      }
> >  
> >      log_msg = g_string_new(NULL);
> > @@ -118,7 +327,7 @@ static void spice_logv(const char *log_domain,
> >          g_string_append_vprintf(log_msg, format, args);
> >      }
> >      g_log(G_LOG_DOMAIN, spice_log_level_to_glib(log_level),
> > -          "[%s] %s", log_domain, log_msg->str);
> > +          "[%s] %s", domain->name, log_msg->str);
> >      g_string_free(log_msg, TRUE);
> >  
> >      if (abort_level != -1 && abort_level >= (int) log_level) {
> > @@ -127,7 +336,7 @@ static void spice_logv(const char *log_domain,
> >      }
> >  }
> >  
> > -void spice_log(const char *log_domain,
> > +void spice_log(SpiceLogDomain *log_domain,
> >                 SpiceLogLevel log_level,
> >                 const char *strloc,
> >                 const char *function,
> > @@ -135,8 +344,20 @@ void spice_log(const char *log_domain,
> >                 ...)
> >  {
> >      va_list args;
> > +    static GOnce domain_init_once = G_ONCE_INIT;
> > +
> > +    g_once (&domain_init_once, (GThreadFunc) domain_init, NULL);
> > +
> > +    /* Use default log_domain when one is not set */
> > +    log_domain = (log_domain == NULL) ? SPICE_LOG_DOMAIN : log_domain;
> >  
> >      va_start (args, format);
> >      spice_logv (log_domain, log_level, strloc, function, format, args);
> >      va_end (args);
> >  }
> > +
> > +void spice_log_domain_cleanup (void)
> > +{
> > +    g_slist_free_full(log_domains, (GDestroyNotify)
> > spice_log_domain_free);
> > +    g_clear_pointer(&SPICE_LOG_DOMAIN, (GDestroyNotify)
> > spice_log_domain_free);
> > +}
> > diff --git a/common/log.h b/common/log.h
> > index 8a85369..86d7d5c 100644
> > --- a/common/log.h
> > +++ b/common/log.h
> > @@ -26,28 +26,56 @@
> >  
> >  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,
> > +/* Opaque */
> > +typedef struct _SpiceLogDomain SpiceLogDomain;
> > +
> > +/* Default */
> > +extern SpiceLogDomain *SPICE_LOG_DOMAIN;
> > +
> > +
> > +#define SPICE_LOG_DOMAIN_STATIC(domain) \
> > +    static SpiceLogDomain *domain = NULL
> > +
> > +#define SPICE_LOG_DOMAIN_INIT(domain, name) G_STMT_START {  \
> > +    if (domain == NULL)                                     \
> > +        domain = spice_log_domain_new (name);               \
> > +} G_STMT_END
> > +
> > +#define SPICE_LOG_DOMAIN_FINALIZE(domain) G_STMT_START {    \
> > +    if (domain != NULL) {                                   \
> > +        spice_log_domain_free (domain);                     \
> > +        domain = NULL;                                      \
> > +    }                                                       \
> > +} G_STMT_END
> > +
> > +#define SPICE_LOG_DOMAIN_CLEANUP() G_STMT_START {   \
> > +    spice_log_domain_cleanup ();                    \
> > +} G_STMT_END
> > +
> 
> 
> This looks pretty bad to me. Why do you need an extern SPICE_LOG_DOMAIN, and
> a static "domain" (this is all beyond my personal taste, maybe it's just me)
> 
> I understand you want to have some kind of "subdomain". Glib does well with
> domain+domainlevel without any horrid macros or variables.
> 
> Wouldn't it be possible to just have this subdomain in a way that extend
> glog? For example: spice_debug() would call spice_log(log_domain,
> log_subdomain, ...) (and in turn would call glog). Wouldn't it be way
> simpler?

Ok I think I understand you want to store the current filter level for the subdomain.

fwiw, I just looked at libvirt, that is yet another attempt to do something similar (sigh..). The way they do it is way cleaner imo. virLogDefineFilter() allows to change the current filters, while there is only a single statically allocated structure in each file, check VIR_LOG_INIT(). The struct is updated lazilly when calling virLogVMessage() -> virLogSourceUpdate() if the serial is more recent. I would really prefer such an approach that would make this code less intrusive and more acceptable, do you agree?



>  
>  
> > +SpiceLogDomain *spice_log_domain_new (const gchar *name);
> > +void spice_log_domain_free (SpiceLogDomain *domain);
> > +void spice_log(SpiceLogDomain *log_domain,
> >                 SpiceLogLevel log_level,
> >                 const char *strloc,
> >                 const char *function,
> >                 const char *format,
> >                 ...) SPICE_ATTR_PRINTF(5, 6);
> >  
> > +void spice_log_domain_cleanup(void);
> >  
> >  #define SPICE_LOG(domain, level, format, ...) G_STMT_START {            \
> >      spice_log((domain), (level), SPICE_STRLOC, G_STRFUNC,               \
> > --
> > 2.5.0
> > 
> > _______________________________________________
> > Spice-devel mailing list
> > Spice-devel at lists.freedesktop.org
> > http://lists.freedesktop.org/mailman/listinfo/spice-devel
> > 
> _______________________________________________
> 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