[Spice-devel] [spice-common PATCH v1 4/13] log: allow filtering debug using domains
Victor Toso
victortoso at redhat.com
Sun Dec 13 23:45:49 PST 2015
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 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