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

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

On Fri, Dec 11, 2015 at 12:19:30PM -0500, Marc-André Lureau wrote:
> 
> 
> ----- 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.

Yes

>
> fwiw, I just looked at libvirt, that is yet another attempt to do something
> similar (sigh..).

Hehe, because it is useful ;)

> 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?

Yes, I totally agree. I'll take a better looking in how libvirt does the
logging and send a v2.

Many thanks for the review,
  toso

>
>
> >
> >
> > > +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@xxxxxxxxxxxxxxxxxxxxx
> > > http://lists.freedesktop.org/mailman/listinfo/spice-devel
> > > 
> > _______________________________________________
> > Spice-devel mailing list
> > Spice-devel@xxxxxxxxxxxxxxxxxxxxx
> > http://lists.freedesktop.org/mailman/listinfo/spice-devel
> > 
_______________________________________________
Spice-devel mailing list
Spice-devel@xxxxxxxxxxxxxxxxxxxxx
http://lists.freedesktop.org/mailman/listinfo/spice-devel




[Index of Archives]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [ECOS]     [Asterisk Internet PBX]     [Linux API]     [Monitors]