[Spice-commits] 3 commits - common/log.c m4/spice-deps.m4 tests/test-logging.c
Christophe Fergau
teuf at kemper.freedesktop.org
Tue Apr 5 14:48:22 UTC 2016
common/log.c | 31 ++++++++++++++++++-------------
m4/spice-deps.m4 | 2 +-
tests/test-logging.c | 50 +++++++++++++++++---------------------------------
3 files changed, 36 insertions(+), 47 deletions(-)
New commits:
commit 2a4bf49edd6e094174dd6e0a65051cf4b378b03c
Author: Christophe Fergeau <cfergeau at redhat.com>
Date: Mon Apr 4 18:02:42 2016 +0200
log: Make sure glib threading is initialized
While testing spice-server on EL6, I was getting random crashes in the
glib logging code because g_logv was called recursively even though this
was not visible in a backtrace.
It turns out on older glib versions (EL6 has 2.28), g_logv is not
thread-safe unless g_thread_init() is called first. If g_thread_init()
is not called, the GMutex/GPrivate calls g_logv makes are turned into
no-ops, which is going to cause the recursion issue I was seeing.
This commit adds a call to g_thread_init() for these older glib
versions.
(gdb) bt
0x7fff9f9fb110 "item.type: 114", unused_data=0x0) at gmessages.c:863
format=0x7ffff50e72ac "item.type: %d", args1=0x7fff9f9fb640) at gmessages.c:517
SPICE_LOG_LEVEL_DEBUG, strloc=0x7ffff50e72ba "dcc.c:1652", function=
0x7ffff50e7320 "release_item_before_push", format=0x7ffff50e72ac "item.type: %d", args=
0x7fff9f9fb640) at log.c:163
SPICE_LOG_LEVEL_DEBUG, strloc=0x7ffff50e72ba "dcc.c:1652", function=
0x7ffff50e7320 "release_item_before_push", format=0x7ffff50e72ac "item.type: %d") at log.c:195
at dcc.c:1652
at dcc.c:1719
at dcc-send.c:2450
at red-channel.c:578
at red-channel.c:1587
at event-loop.c:122
0x7ffff4fb2ef2 <watch_func>, user_data=0x7fff980244e0) at giounix.c:166
0x7ffff86ec770) at gmain.c:3092
diff --git a/common/log.c b/common/log.c
index d4a6d28..e39eefc 100644
--- a/common/log.c
+++ b/common/log.c
@@ -138,6 +138,14 @@ SPICE_CONSTRUCTOR_FUNC(spice_log_init)
g_log_set_handler(SPICE_LOG_DOMAIN,
G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
spice_logger, NULL);
+ /* Threading is always enabled from 2.31.0 onwards */
+ /* Our logging is potentially used from different threads.
+ * Older glibs require that g_thread_init() is called when
+ * doing that. */
+#if !GLIB_CHECK_VERSION(2, 31, 0)
+ if (!g_thread_supported())
+ g_thread_init(NULL);
+#endif
}
static void spice_logv(const char *log_domain,
diff --git a/m4/spice-deps.m4 b/m4/spice-deps.m4
index fb43cd2..170adf2 100644
--- a/m4/spice-deps.m4
+++ b/m4/spice-deps.m4
@@ -173,7 +173,7 @@ AC_DEFUN([SPICE_CHECK_PIXMAN], [
# use in the GLIB2_CFLAGS and GLIB2_LIBS variables.
#------------------
AC_DEFUN([SPICE_CHECK_GLIB2], [
- PKG_CHECK_MODULES(GLIB2, glib-2.0 >= 2.22 gio-2.0 >= 2.22)
+ PKG_CHECK_MODULES(GLIB2, glib-2.0 >= 2.22 gio-2.0 >= 2.22 gthread-2.0 >= 2.22)
])
# SPICE_CHECK_PYTHON_MODULES()
commit 8473d0ae71e5c7ae005b186048ba930208749238
Author: Christophe Fergeau <cfergeau at redhat.com>
Date: Mon Apr 4 17:54:33 2016 +0200
log: Use SPICE_CONSTRUCTOR_FUNC
This was done through a GOnce called every time spice_log() is called,
now it will always be called at spice-server startup.
This means the unit test needs to be updated as SPICE_DEBUG/ABORT_LEVEL
must now be set before the process starts up rather than before the
first spice_log call, and the deprecation warning these environment
variables trigger cannot be caught using g_test_expect_message() as
they are output before g_test_init() is called.
diff --git a/common/log.c b/common/log.c
index 5f08470..d4a6d28 100644
--- a/common/log.c
+++ b/common/log.c
@@ -130,18 +130,14 @@ static void spice_logger(const gchar *log_domain,
g_log_default_handler(log_domain, log_level, message, NULL);
}
-static inline void spice_log_init_once(void)
+SPICE_CONSTRUCTOR_FUNC(spice_log_init)
{
- static gsize logging_initialized = FALSE;
-
- if (g_once_init_enter(&logging_initialized)) {
- spice_log_set_debug_level();
- spice_log_set_abort_level();
- g_once_init_leave (&logging_initialized, TRUE);
- g_log_set_handler(SPICE_LOG_DOMAIN,
- G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
- spice_logger, NULL);
- }
+
+ spice_log_set_debug_level();
+ spice_log_set_abort_level();
+ g_log_set_handler(SPICE_LOG_DOMAIN,
+ G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
+ spice_logger, NULL);
}
static void spice_logv(const char *log_domain,
@@ -153,8 +149,6 @@ static void spice_logv(const char *log_domain,
{
GString *log_msg;
- spice_log_init_once();
-
g_return_if_fail(spice_log_level_to_glib(log_level) != 0);
log_msg = g_string_new(NULL);
diff --git a/tests/test-logging.c b/tests/test-logging.c
index cb929f9..b7ca616 100644
--- a/tests/test-logging.c
+++ b/tests/test-logging.c
@@ -48,18 +48,15 @@ LOG_OTHER_HELPER(critical, CRITICAL)
static void test_spice_abort_level(void)
{
if (g_test_subprocess()) {
- /* 2 = SPICE_LOG_LEVEL_WARNING */
- g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
- g_test_expect_message(NULL,
- G_LOG_LEVEL_WARNING,
- "*SPICE_ABORT_LEVEL*deprecated*");
- spice_debug("trigger deprecation warning");
- g_test_assert_expected_messages();
spice_warning("spice_warning");
return;
}
+ /* 2 = SPICE_LOG_LEVEL_WARNING */
+ g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
g_test_trap_subprocess(NULL, 0, 0);
+ g_unsetenv("SPICE_ABORT_LEVEL");
g_test_trap_assert_failed();
+ g_test_trap_assert_stderr("*SPICE_ABORT_LEVEL*deprecated*");
g_test_trap_assert_stderr("*spice_warning*");
}
@@ -67,18 +64,14 @@ static void test_spice_abort_level(void)
static void test_spice_abort_level_g_warning(void)
{
if (g_test_subprocess()) {
- /* 2 = SPICE_LOG_LEVEL_WARNING */
- g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
- g_test_expect_message(NULL,
- G_LOG_LEVEL_WARNING,
- "*SPICE_ABORT_LEVEL*deprecated*");
- spice_debug("trigger deprecation warning");
- g_test_assert_expected_messages();
g_warning("g_warning");
return;
}
+ g_setenv("SPICE_ABORT_LEVEL", "2", TRUE);
g_test_trap_subprocess(NULL, 0, 0);
+ g_unsetenv("SPICE_ABORT_LEVEL");
g_test_trap_assert_failed();
+ g_test_trap_assert_stderr("*SPICE_ABORT_LEVEL*deprecated*");
g_test_trap_assert_stderr("*g_warning*");
}
@@ -263,14 +256,6 @@ static void test_log_levels(void)
static void test_spice_debug_level(void)
{
if (g_test_subprocess()) {
- g_unsetenv("G_MESSAGES_DEBUG");
- g_setenv("SPICE_DEBUG_LEVEL", "5", TRUE);
- g_test_expect_message(NULL,
- G_LOG_LEVEL_WARNING,
- "*SPICE_DEBUG_LEVEL*deprecated*");
- spice_debug("trigger deprecation warning");
- g_test_assert_expected_messages();
-
/* g_test_expected_message only checks whether the appropriate messages got up to g_log()
* The following calls will be caught by the parent process to check what was (not) printed
* to stdout/stderr
@@ -283,8 +268,12 @@ static void test_spice_debug_level(void)
return;
}
+ g_unsetenv("G_MESSAGES_DEBUG");
+ g_setenv("SPICE_DEBUG_LEVEL", "5", TRUE);
g_test_trap_subprocess(NULL, 0, 0);
+ g_unsetenv("SPICE_DEBUG_LEVEL");
g_test_trap_assert_passed();
+ g_test_trap_assert_stderr("*SPICE_DEBUG_LEVEL*deprecated*");
g_test_trap_assert_stdout("*spice_info\n*g_debug\n*spice_debug\n");
}
@@ -294,17 +283,6 @@ static void test_spice_debug_level(void)
static void test_spice_debug_level_warning(void)
{
if (g_test_subprocess()) {
- g_setenv("SPICE_ABORT_LEVEL", "0", TRUE);
- g_setenv("SPICE_DEBUG_LEVEL", "1", TRUE);
- g_test_expect_message(NULL,
- G_LOG_LEVEL_WARNING,
- "*SPICE_DEBUG_LEVEL*deprecated*");
- g_test_expect_message(NULL,
- G_LOG_LEVEL_WARNING,
- "*SPICE_ABORT_LEVEL*deprecated*");
- spice_debug("trigger deprecation warning");
- g_test_assert_expected_messages();
-
spice_info("spice_info");
spice_debug("spice_debug");
spice_warning("spice_warning");
@@ -323,8 +301,14 @@ static void test_spice_debug_level_warning(void)
return;
}
+ g_setenv("SPICE_ABORT_LEVEL", "0", TRUE);
+ g_setenv("SPICE_DEBUG_LEVEL", "1", TRUE);
g_test_trap_subprocess(NULL, 0, 0);
+ g_unsetenv("SPICE_ABORT_LEVEL");
+ g_unsetenv("SPICE_DEBUG_LEVEL");
g_test_trap_assert_passed();
+ g_test_trap_assert_stderr("*SPICE_DEBUG_LEVEL*deprecated*");
+ g_test_trap_assert_stderr("*SPICE_ABORT_LEVEL*deprecated*");
g_test_trap_assert_stderr("*spice_critical\n*g_critical\n*other_message\n*other_warning\n*other_critical\n");
}
commit 6a65f470d1fc12f2d2cfb81b940faca9ff91d56c
Author: Christophe Fergeau <cfergeau at redhat.com>
Date: Tue Apr 5 12:46:05 2016 +0200
log: Clamp SPICE_DEBUG_LEVEL if it's too high
This matches how SPICE_DEBUG_LEVEL behaved before switching to glib
logging.
diff --git a/common/log.c b/common/log.c
index 8d47cb6..5f08470 100644
--- a/common/log.c
+++ b/common/log.c
@@ -67,6 +67,9 @@ static void spice_log_set_debug_level(void)
/* FIXME: To be removed after enough deprecation time */
g_warning("Setting SPICE_DEBUG_LEVEL is deprecated, use G_MESSAGES_DEBUG instead");
debug_level = atoi(debug_str);
+ if (debug_level > SPICE_LOG_LEVEL_DEBUG) {
+ debug_level = SPICE_LOG_LEVEL_DEBUG;
+ }
glib_debug_level = spice_log_level_to_glib(debug_level);
/* If the debug level is too high, make sure we don't try to enable
More information about the Spice-commits
mailing list