From c3b758f6fe8b7ae5e3e0204236f6aba48d714bc1 Mon Sep 17 00:00:00 2001 From: Ben Pfaff Date: Thu, 5 Dec 2013 16:59:13 -0800 Subject: [PATCH] vlog: Avoid deadlock in vlog_init__() corner case. Anything inside vlog_init__() that tried to log a message was going to deadlock, since it would hit pthread_once() recursively and wait for the previous call to complete. Unfortunately, there was a VLOG_ERR call inside vlog_init__(), only called in the corner case where the system's clock was wrong. This fixes the problem by rearranging code so that the logging isn't inside the "once-only" region. Found by inspection. Signed-off-by: Ben Pfaff --- lib/vlog.c | 76 +++++++++++++++++++++++++++++------------------------- 1 file changed, 41 insertions(+), 35 deletions(-) diff --git a/lib/vlog.c b/lib/vlog.c index 540e72ac2..42e4869bb 100644 --- a/lib/vlog.c +++ b/lib/vlog.c @@ -592,46 +592,52 @@ vlog_disable_rate_limit(struct unixctl_conn *conn, int argc, set_rate_limits(conn, argc, argv, false); } -static void -vlog_init__(void) -{ - static char *program_name_copy; - long long int now; - - /* openlog() is allowed to keep the pointer passed in, without making a - * copy. The daemonize code sometimes frees and replaces 'program_name', - * so make a private copy just for openlog(). (We keep a pointer to the - * private copy to suppress memory leak warnings in case openlog() does - * make its own copy.) */ - program_name_copy = program_name ? xstrdup(program_name) : NULL; - openlog(program_name_copy, LOG_NDELAY, LOG_DAEMON); - - now = time_wall_msec(); - if (now < 0) { - char *s = xastrftime_msec("%a, %d %b %Y %H:%M:%S", now, true); - VLOG_ERR("current time is negative: %s (%lld)", s, now); - free(s); - } - - unixctl_command_register( - "vlog/set", "{spec | PATTERN:facility:pattern}", - 1, INT_MAX, vlog_unixctl_set, NULL); - unixctl_command_register("vlog/list", "", 0, 0, vlog_unixctl_list, NULL); - unixctl_command_register("vlog/enable-rate-limit", "[module]...", - 0, INT_MAX, vlog_enable_rate_limit, NULL); - unixctl_command_register("vlog/disable-rate-limit", "[module]...", - 0, INT_MAX, vlog_disable_rate_limit, NULL); - unixctl_command_register("vlog/reopen", "", 0, 0, - vlog_unixctl_reopen, NULL); -} - /* Initializes the logging subsystem and registers its unixctl server * commands. */ void vlog_init(void) { - static pthread_once_t once = PTHREAD_ONCE_INIT; - pthread_once(&once, vlog_init__); + static struct ovsthread_once once = OVSTHREAD_ONCE_INITIALIZER; + + if (ovsthread_once_start(&once)) { + static char *program_name_copy; + long long int now; + + /* Do initialization work that needs to be done before any logging + * occurs. We want to keep this really minimal because any attempt to + * log anything before calling ovsthread_once_done() will deadlock. */ + + /* openlog() is allowed to keep the pointer passed in, without making a + * copy. The daemonize code sometimes frees and replaces + * 'program_name', so make a private copy just for openlog(). (We keep + * a pointer to the private copy to suppress memory leak warnings in + * case openlog() does make its own copy.) */ + program_name_copy = program_name ? xstrdup(program_name) : NULL; + openlog(program_name_copy, LOG_NDELAY, LOG_DAEMON); + ovsthread_once_done(&once); + + /* Now do anything that we want to happen only once but doesn't have to + * finish before we start logging. */ + + now = time_wall_msec(); + if (now < 0) { + char *s = xastrftime_msec("%a, %d %b %Y %H:%M:%S", now, true); + VLOG_ERR("current time is negative: %s (%lld)", s, now); + free(s); + } + + unixctl_command_register( + "vlog/set", "{spec | PATTERN:facility:pattern}", + 1, INT_MAX, vlog_unixctl_set, NULL); + unixctl_command_register("vlog/list", "", 0, 0, vlog_unixctl_list, + NULL); + unixctl_command_register("vlog/enable-rate-limit", "[module]...", + 0, INT_MAX, vlog_enable_rate_limit, NULL); + unixctl_command_register("vlog/disable-rate-limit", "[module]...", + 0, INT_MAX, vlog_disable_rate_limit, NULL); + unixctl_command_register("vlog/reopen", "", 0, 0, + vlog_unixctl_reopen, NULL); + } } /* Enables VLF_FILE log output to be written asynchronously to disk. -- 2.43.0