[Spice-devel] [PATCH spice-common 3/4] RFC: Add spice log categories
marcandre.lureau at redhat.com
marcandre.lureau at redhat.com
Mon Jun 12 08:19:53 UTC 2017
From: Marc-André Lureau <marcandre.lureau at redhat.com>
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 at redhat.com>
---
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) {
+ 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)); \
+ }
+
+#define SPICE_LOG_ENABLED(Name) \
+ G_UNLIKELY(G_PASTE(spice_log_category_, Name).enabled)
+
+#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
--
2.13.0.91.g00982b8dd
More information about the Spice-devel
mailing list