> > 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. > + 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. 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. > +#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