Re: [PATCH spice-common 3/4] RFC: Add spice log categories

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

 



Hi

----- Original Message -----
> > 
> > From: Marc-André Lureau <marcandre.lureau@xxxxxxxxxx>
> > 
> > A log category is defined with SPICE_LOG_CATEGORY(). The macro will
> > register a structure with a constructor (and unregister it on
> > unloading with a destructor).
> > 
> > spice_log_init() must be called at initialization time, to set enabled
> > categories and add the 'Spice' glib domain to G_MESSAGES_DEBUG (NB: if
> > useful, we could have other log domains automatically associated with
> > categories and enable them too).
> > 
> > A category can be enabled with SPICE_DEBUG="cat_name foo*" (*? are
> > accepted glob-like wildcards). All categories are enabled with
> > SPICE_DEBUG=1 or 'all'. To list available categories, you can run the
> > program with SPICE_DEBUG=help.
> > 
> > spice_log() will log the debug message using structured logging if
> > available (or fallback on regular glog). The associated Spice log in
> > the journal will have the SPICE_LOG_CATEGORY field set accordingly.
> > 
> > If deemed necessary, you can also avoid expensive log computation with
> > SPICE_LOG_ENABLED() macro help.
> > 
> > TODO: add tests
> > 
> > Signed-off-by: Marc-André Lureau <marcandre.lureau@xxxxxxxxxx>
> > ---
> >  common/log.c         | 67 ++++++++++++++++++++++++++++++++++++++++++++++++
> >  common/log.h         | 72
> >  +++++++++++++++++++++++++++++++++++++++++++++++++++-
> >  tests/test-logging.c |  1 +
> >  3 files changed, 139 insertions(+), 1 deletion(-)
> > 
> > diff --git a/common/log.c b/common/log.c
> > index 6a15a30..029e279 100644
> > --- a/common/log.c
> > +++ b/common/log.c
> > @@ -18,3 +18,70 @@
> >  #ifdef HAVE_CONFIG_H
> >  #include <config.h>
> >  #endif
> > +
> > +#include "log.h"
> > +
> > +static GSList *log_categories = NULL; /* all registered log categories */
> > +
> > +void spice_log_category_register(SpiceLogCategory *cat)
> > +{
> > +    if (!g_slist_find(log_categories, cat)) {
> > +        log_categories = g_slist_prepend(log_categories, cat);
> > +    }
> > +}
> > +
> > +void spice_log_category_unregister(SpiceLogCategory *cat)
> > +{
> > +    log_categories = g_slist_remove(log_categories, cat);
> > +}
> > +
> > +void spice_log_init(void)
> > +{
> > +    bool all = false;
> > +    const char *env = g_getenv("SPICE_DEBUG");
> > +    const char *genv = g_getenv("G_MESSAGES_DEBUG");
> > +
> > +    if (g_strcmp0(env, "help") == 0) {
> 
> I agree with other people that this "help" usage is weird.

Not weird for a gnome/glib developper (G*_DEBUG).

In any case, this is going to be exposed in --spice-debug as Christophe F. suggested.

> 
> > +        g_printerr("SPICE_DEBUG=1 or 'all' to enable all debug\n");
> > +        g_printerr("SPICE_DEBUG=\"cat1* cat2\" to enable specific
> > categories\n");
> > +        g_printerr("Available Spice debug categories:\n");
> > +        for (GSList *l = log_categories; l != NULL; l = g_slist_next(l)) {
> > +            SpiceLogCategory *cat = l->data;
> > +            g_printerr("%-20s - %s\n", cat->name, cat->desc);
> > +        }
> > +        return;
> > +    }
> > +
> > +    /* Make sure GLib default log handler will show the debug
> > +     * messages. Messing with environment variables like this is
> > +     * rather ugly, but done for historical reasons.
> > +     */
> > +    if (env && *env != '\0') {
> > +        if (genv == NULL) {
> > +            g_setenv("G_MESSAGES_DEBUG", G_LOG_DOMAIN, TRUE);
> > +        } else if (!g_str_equal(genv, "all")) {
> > +            char *new_env = g_strconcat(genv, " ", G_LOG_DOMAIN, NULL);
> > +            g_setenv("G_MESSAGES_DEBUG", new_env, TRUE);
> > +            g_free(new_env);
> > +        }
> > +    }
> > +
> > +    all = g_strcmp0(env, "1") == 0 || g_strcmp0(env, "all") == 0;
> > +    if (all) {
> > +        for (GSList *l = log_categories; l != NULL; l = g_slist_next(l)) {
> > +            SpiceLogCategory *cat = l->data;
> > +            cat->enabled = true;
> > +        }
> > +    } else if (env) {
> > +        char **cat_sel = g_strsplit(env, " ", -1);
> > +        for (char **strv = cat_sel; *strv != NULL; strv++) {
> > +            GPatternSpec *pat = g_pattern_spec_new(*strv);
> > +            for (GSList *l = log_categories; l != NULL; l =
> > g_slist_next(l))
> > {
> > +                SpiceLogCategory *cat = l->data;
> > +                cat->enabled = g_pattern_match_string(pat, cat->name);
> > +            }
> > +            g_pattern_spec_free(pat);
> > +        }
> > +        g_strfreev(cat_sel);
> > +    }
> > +}
> > diff --git a/common/log.h b/common/log.h
> > index b86fd08..e202563 100644
> > --- a/common/log.h
> > +++ b/common/log.h
> > @@ -28,6 +28,63 @@
> >  
> >  G_BEGIN_DECLS
> >  
> > +typedef struct SpiceLogCategory {
> > +    const char *name;
> > +    const char *desc;
> > +    bool enabled;
> > +} SpiceLogCategory;
> > +
> > +/* This is only useful if the category is shared in several units. */
> > +/* The code could probably be better organized instead. */
> > +#define SPICE_LOG_CATEGORY_DECLARE(Name)                        \
> > +    extern SpiceLogCategory G_PASTE(spice_log_category_, Name);
> > +
> > +#define SPICE_LOG_CATEGORY(Name, Desc)                                  \
> > +    SpiceLogCategory G_PASTE(spice_log_category_, Name) = {             \
> > +        .name = G_STRINGIFY(Name),                                      \
> > +        .desc = Desc,                                                   \
> > +        .enabled = false,                                               \
> > +    };                                                                  \
> > +    SPICE_CONSTRUCTOR_FUNC(G_PASTE(spice_log_category_ctor_, Name)) {   \
> > +        spice_log_category_register(&G_PASTE(spice_log_category_, Name));
> > \
> > +    }                                                                   \
> > +    SPICE_DESTRUCTOR_FUNC(G_PASTE(spice_log_category_dtor_, Name)) {    \
> > +        spice_log_category_unregister(&G_PASTE(spice_log_category_,
> > Name));
> > \
> > +    }
> > +
> 
> Usually to do these stuff I use a simple "manual" list so
> I would add a "SpiceLogCategory *next" pointer to SpiceLogCategory and
> just use the constructor. This have some advantages:
> - don't need extra allocations. Other than reducing memory usage
>   and fragmentation you could have some issues with system uses multiple
>   allocators (well, sometimes happens on some weird systems like
>   Windows);
> - there are no possible allocation failure (well, should be rare at
>   startup but if you are paranoid... you are paranoid!);
> - you don't need destructor. The entire list will be freed as part of
>   memory unmapping.
> 
> I found weird the capital names for parameters.

Ok

> 
> I also would prefer ## instead of G_PASTE, this syntax was introduced
> as standard in C preprocessors quite some time ago. In the same patch
> you are using __VA_ARGS__ with is much more recent.
> 

G_PASTE is not about portability, it's mostly about readability but it also deals with some macro expansions issues, when it's nested iirc.


> > +#define SPICE_LOG_ENABLED(Name)                                 \
> > +    G_UNLIKELY(G_PASTE(spice_log_category_, Name).enabled)
> > +
> 
> OT: wondering if this G_PASTE(spice_log_category_, Name).enabled could
> be make a compile time constant in some way so to optimize out.
> 
> > +#if G_LOG_USE_STRUCTURED
> > +/* override future deprecation warning */
> > +#define g_log_structured(Domain, Level, ...) G_STMT_START {     \
> > +    G_GNUC_BEGIN_IGNORE_DEPRECATIONS                            \
> > +        g_log_structured(Domain, Level, ## __VA_ARGS__);        \
> > +    G_GNUC_END_IGNORE_DEPRECATIONS                              \
> > +} G_STMT_END
> > +
> > +#define spice_log(Name, Msg, ...) G_STMT_START {                        \
> > +    if (SPICE_LOG_ENABLED(Name)) {                                      \
> > +        g_log_structured(G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG,               \
> > +                         "CODE_FILE", __FILE__,                         \
> > +                         "CODE_LINE", G_STRINGIFY(__LINE__),            \
> > +                         "CODE_FUNC", G_STRFUNC,                        \
> > +                         "SPICE_LOG_CATEGORY", G_STRINGIFY(Name),       \
> > +                         "MESSAGE", G_STRINGIFY(Name)": " Msg, ##
> > __VA_ARGS__); \
> > +    }                                                                   \
> > +} G_STMT_END
> > +#else /* !G_LOG_USE_STRUCTURED */
> > +#define spice_log(Name, Msg, ...) G_STMT_START {                \
> > +    if (SPICE_LOG_ENABLED(Name)) {                              \
> > +        g_debug(G_STRINGIFY(Name)": " Msg, ## __VA_ARGS__);     \
> > +    }                                                           \
> > +} G_STMT_END
> > +#endif
> > +
> > +void spice_log_category_register(SpiceLogCategory *cat);
> > +void spice_log_category_unregister(SpiceLogCategory *cat);
> > +void spice_log_init(void);
> > +
> >  /* deprecated, please use glib directly */
> >  #define spice_return_if_fail(x) g_return_if_fail(x)
> >  #define spice_return_val_if_fail(x, val) g_return_val_if_fail(x, val)
> > @@ -36,7 +93,7 @@ G_BEGIN_DECLS
> >  #define spice_assert(x) g_assert(x)
> >  #define spice_static_assert(x) G_STATIC_ASSERT(x)
> >  
> > -/* deprecated */
> > +/* deprecated, use spice_log() instead */
> >  #ifndef SPICE_LOG_DOMAIN
> >  #define SPICE_LOG_DOMAIN __FILE__
> >  #endif
> > @@ -61,7 +118,20 @@ static inline void _spice_debug(const char *domain,
> > const
> > char *file,
> >      if (msg) {
> >          g_string_append_vprintf(s, msg, args);
> >      }
> > +#if G_LOG_USE_STRUCTURED
> > +    G_GNUC_BEGIN_IGNORE_DEPRECATIONS
> > +    const GLogField fields[] = {
> > +        { "GLIB_DOMAIN", G_LOG_DOMAIN, -1 },
> > +        { "MESSAGE", s->str, -1 },
> > +        { "CODE_FILE", file, -1 },
> > +        { "CODE_LINE", line, -1 },
> > +        { "CODE_FUNC", func, -1 },
> > +    };
> > +    g_log_structured_array(G_LOG_LEVEL_DEBUG, fields,
> > G_N_ELEMENTS(fields));
> > +    G_GNUC_END_IGNORE_DEPRECATIONS
> > +#else
> >      g_debug("%s", s->str);
> > +#endif
> >      va_end(args);
> >      g_string_free(s, true);
> >  }
> > diff --git a/tests/test-logging.c b/tests/test-logging.c
> > index 03f367a..cfe63e4 100644
> > --- a/tests/test-logging.c
> > +++ b/tests/test-logging.c
> > @@ -87,6 +87,7 @@ int main(int argc, char **argv)
> >      fatal_mask = (GLogLevelFlags)g_log_set_always_fatal((GLogLevelFlags)
> >      G_LOG_FATAL_MASK);
> >  
> >      g_test_init(&argc, &argv, NULL);
> > +    spice_log_init();
> >  
> >      /* Reset fatal mask set by g_test_init() as we don't want
> >       * warnings/criticals to be fatal by default since this is what some
> >       of
> >       the
> 
> Frediano
> 
_______________________________________________
Spice-devel mailing list
Spice-devel@xxxxxxxxxxxxxxxxxxxxx
https://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]