Replace all uses of strerror() by ovs_strerror(), for thread safety.
[sliver-openvswitch.git] / lib / vlog.c
index e086e79..f87f48f 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008, 2009, 2010 Nicira Networks.
+ * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013 Nicira, Inc.
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
 #include <assert.h>
 #include <ctype.h>
 #include <errno.h>
+#include <fcntl.h>
 #include <stdarg.h>
 #include <stdlib.h>
 #include <string.h>
+#include <sys/stat.h>
 #include <sys/types.h>
 #include <syslog.h>
 #include <time.h>
 #include <unistd.h>
+#include "coverage.h"
 #include "dirs.h"
 #include "dynamic-string.h"
+#include "ofpbuf.h"
 #include "sat-math.h"
+#include "svec.h"
 #include "timeval.h"
 #include "unixctl.h"
 #include "util.h"
+#include "worker.h"
 
-#define THIS_MODULE VLM_vlog
+VLOG_DEFINE_THIS_MODULE(vlog);
+
+COVERAGE_DEFINE(vlog_recursive);
+
+/* ovs_assert() logs the assertion message, so using ovs_assert() in this
+ * source file could cause recursion. */
+#undef ovs_assert
+#define ovs_assert use_assert_instead_of_ovs_assert_in_this_module
 
 /* Name for each logging level. */
-static const char *level_names[VLL_N_LEVELS] = {
+static const char *const level_names[VLL_N_LEVELS] = {
 #define VLOG_LEVEL(NAME, SYSLOG_LEVEL) #NAME,
     VLOG_LEVELS
 #undef VLOG_LEVEL
 };
 
 /* Syslog value for each logging level. */
-static int syslog_levels[VLL_N_LEVELS] = {
+static const int syslog_levels[VLL_N_LEVELS] = {
 #define VLOG_LEVEL(NAME, SYSLOG_LEVEL) SYSLOG_LEVEL,
     VLOG_LEVELS
 #undef VLOG_LEVEL
 };
 
-/* Name for each logging module */
-static const char *module_names[VLM_N_MODULES] = { 
-#define VLOG_MODULE(NAME) #NAME,
+/* The log modules. */
+#if USE_LINKER_SECTIONS
+extern struct vlog_module *__start_vlog_modules[];
+extern struct vlog_module *__stop_vlog_modules[];
+#define vlog_modules __start_vlog_modules
+#define n_vlog_modules (__stop_vlog_modules - __start_vlog_modules)
+#else
+#define VLOG_MODULE VLOG_DEFINE_MODULE__
+#include "vlog-modules.def"
+#undef VLOG_MODULE
+
+struct vlog_module *vlog_modules[] = {
+#define VLOG_MODULE(NAME) &VLM_##NAME,
 #include "vlog-modules.def"
 #undef VLOG_MODULE
 };
+#define n_vlog_modules ARRAY_SIZE(vlog_modules)
+#endif
 
 /* Information about each facility. */
 struct facility {
@@ -68,29 +93,24 @@ static struct facility facilities[VLF_N_FACILITIES] = {
 #undef VLOG_FACILITY
 };
 
-/* Current log levels. */
-static int levels[VLM_N_MODULES][VLF_N_FACILITIES];
-
-/* For fast checking whether we're logging anything for a given module and
- * level.*/
-enum vlog_level min_vlog_levels[VLM_N_MODULES];
-
-/* Time at which vlog was initialized, in milliseconds. */
-static long long int boot_time;
-
 /* VLF_FILE configuration. */
 static char *log_file_name;
-static FILE *log_file;
+static int log_fd = -1;
 
-static void format_log_message(enum vlog_module, enum vlog_level,
+/* vlog initialized? */
+static bool vlog_inited;
+
+static void format_log_message(const struct vlog_module *, enum vlog_level,
                                enum vlog_facility, unsigned int msg_num,
                                const char *message, va_list, struct ds *)
     PRINTF_FORMAT(5, 0);
+static void vlog_write_file(struct ds *);
+static void vlog_update_async_log_fd(void);
 
 /* Searches the 'n_names' in 'names'.  Returns the index of a match for
  * 'target', or 'n_names' if no name matches. */
 static size_t
-search_name_array(const char *target, const char **names, size_t n_names) 
+search_name_array(const char *target, const char *const *names, size_t n_names)
 {
     size_t i;
 
@@ -114,14 +134,14 @@ vlog_get_level_name(enum vlog_level level)
 /* Returns the logging level with the given 'name', or VLL_N_LEVELS if 'name'
  * is not the name of a logging level. */
 enum vlog_level
-vlog_get_level_val(const char *name) 
+vlog_get_level_val(const char *name)
 {
     return search_name_array(name, level_names, ARRAY_SIZE(level_names));
 }
 
 /* Returns the name for logging facility 'facility'. */
 const char *
-vlog_get_facility_name(enum vlog_facility facility) 
+vlog_get_facility_name(enum vlog_facility facility)
 {
     assert(facility < VLF_N_FACILITIES);
     return facilities[facility].name;
@@ -130,7 +150,7 @@ vlog_get_facility_name(enum vlog_facility facility)
 /* Returns the logging facility named 'name', or VLF_N_FACILITIES if 'name' is
  * not the name of a logging facility. */
 enum vlog_facility
-vlog_get_facility_val(const char *name) 
+vlog_get_facility_val(const char *name)
 {
     size_t i;
 
@@ -143,65 +163,77 @@ vlog_get_facility_val(const char *name)
 }
 
 /* Returns the name for logging module 'module'. */
-const char *vlog_get_module_name(enum vlog_module module) 
+const char *
+vlog_get_module_name(const struct vlog_module *module)
 {
-    assert(module < VLM_N_MODULES);
-    return module_names[module];
+    return module->name;
 }
 
-/* Returns the logging module named 'name', or VLM_N_MODULES if 'name' is not
- * the name of a logging module. */
-enum vlog_module
-vlog_get_module_val(const char *name) 
+/* Returns the logging module named 'name', or NULL if 'name' is not the name
+ * of a logging module. */
+struct vlog_module *
+vlog_module_from_name(const char *name)
 {
-    return search_name_array(name, module_names, ARRAY_SIZE(module_names));
+    struct vlog_module **mp;
+
+    for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+        if (!strcasecmp(name, (*mp)->name)) {
+            return *mp;
+        }
+    }
+    return NULL;
 }
 
 /* Returns the current logging level for the given 'module' and 'facility'. */
 enum vlog_level
-vlog_get_level(enum vlog_module module, enum vlog_facility facility) 
+vlog_get_level(const struct vlog_module *module, enum vlog_facility facility)
 {
-    assert(module < VLM_N_MODULES);
     assert(facility < VLF_N_FACILITIES);
-    return levels[module][facility];
+    return module->levels[facility];
 }
 
 static void
-update_min_level(enum vlog_module module)
+update_min_level(struct vlog_module *module)
 {
-    enum vlog_level min_level = VLL_EMER;
     enum vlog_facility facility;
 
+    module->min_level = VLL_OFF;
     for (facility = 0; facility < VLF_N_FACILITIES; facility++) {
-        if (log_file || facility != VLF_FILE) {
-            min_level = MAX(min_level, levels[module][facility]); 
+        if (log_fd >= 0 || facility != VLF_FILE) {
+            enum vlog_level level = module->levels[facility];
+            if (level > module->min_level) {
+                module->min_level = level;
+            }
         }
     }
-    min_vlog_levels[module] = min_level;
 }
 
 static void
-set_facility_level(enum vlog_facility facility, enum vlog_module module,
+set_facility_level(enum vlog_facility facility, struct vlog_module *module,
                    enum vlog_level level)
 {
     assert(facility >= 0 && facility < VLF_N_FACILITIES);
     assert(level < VLL_N_LEVELS);
 
-    if (module == VLM_ANY_MODULE) {
-        for (module = 0; module < VLM_N_MODULES; module++) {
-            levels[module][facility] = level;
-            update_min_level(module);
+    if (!module) {
+        struct vlog_module **mp;
+
+        for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+            (*mp)->levels[facility] = level;
+            update_min_level(*mp);
         }
     } else {
-        levels[module][facility] = level;
+        module->levels[facility] = level;
         update_min_level(module);
     }
 }
 
-/* Sets the logging level for the given 'module' and 'facility' to 'level'. */
+/* Sets the logging level for the given 'module' and 'facility' to 'level'.  A
+ * null 'module' or a 'facility' of VLF_ANY_FACILITY is treated as a wildcard
+ * across all modules or facilities, respectively. */
 void
-vlog_set_levels(enum vlog_module module, enum vlog_facility facility,
-                enum vlog_level level) 
+vlog_set_levels(struct vlog_module *module, enum vlog_facility facility,
+                enum vlog_level level)
 {
     assert(facility < VLF_N_FACILITIES || facility == VLF_ANY_FACILITY);
     if (facility == VLF_ANY_FACILITY) {
@@ -214,7 +246,7 @@ vlog_set_levels(enum vlog_module module, enum vlog_facility facility,
 }
 
 static void
-do_set_pattern(enum vlog_facility facility, const char *pattern) 
+do_set_pattern(enum vlog_facility facility, const char *pattern)
 {
     struct facility *f = &facilities[facility];
     if (!f->default_pattern) {
@@ -256,14 +288,14 @@ int
 vlog_set_log_file(const char *file_name)
 {
     char *old_log_file_name;
-    enum vlog_module module;
+    struct vlog_module **mp;
     int error;
 
     /* Close old log file. */
-    if (log_file) {
+    if (log_fd >= 0) {
         VLOG_INFO("closing log file");
-        fclose(log_file);
-        log_file = NULL;
+        close(log_fd);
+        log_fd = -1;
     }
 
     /* Update log file name and free old name.  The ordering is important
@@ -271,21 +303,24 @@ vlog_set_log_file(const char *file_name)
     old_log_file_name = log_file_name;
     log_file_name = (file_name
                      ? xstrdup(file_name)
-                     : xasprintf("%s/%s.log", ovs_logdir, program_name));
+                     : xasprintf("%s/%s.log", ovs_logdir(), program_name));
     free(old_log_file_name);
     file_name = NULL;           /* Might have been freed. */
 
     /* Open new log file and update min_levels[] to reflect whether we actually
      * have a log_file. */
-    log_file = fopen(log_file_name, "a");
-    for (module = 0; module < VLM_N_MODULES; module++) {
-        update_min_level(module);
+    log_fd = open(log_file_name, O_WRONLY | O_CREAT | O_APPEND, 0666);
+    if (log_fd >= 0) {
+        vlog_update_async_log_fd();
+    }
+    for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+        update_min_level(*mp);
     }
 
     /* Log success or failure. */
-    if (!log_file) {
+    if (log_fd < 0) {
         VLOG_WARN("failed to open %s for logging: %s",
-                  log_file_name, strerror(errno));
+                  log_file_name, ovs_strerror(errno));
         error = errno;
     } else {
         VLOG_INFO("opened log file %s", log_file_name);
@@ -301,72 +336,109 @@ vlog_set_log_file(const char *file_name)
 int
 vlog_reopen_log_file(void)
 {
-    return log_file_name ? vlog_set_log_file(log_file_name) : 0;
+    struct stat old, new;
+
+    /* Skip re-opening if there's nothing to reopen. */
+    if (!log_file_name) {
+        return 0;
+    }
+
+    /* Skip re-opening if it would be a no-op because the old and new files are
+     * the same.  (This avoids writing "closing log file" followed immediately
+     * by "opened log file".) */
+    if (log_fd >= 0
+        && !fstat(log_fd, &old)
+        && !stat(log_file_name, &new)
+        && old.st_dev == new.st_dev
+        && old.st_ino == new.st_ino) {
+        return 0;
+    }
+
+    return vlog_set_log_file(log_file_name);
 }
 
-/* Set debugging levels:
- *
- *  mod[:facility[:level]] mod2[:facility[:level]] ...
- *
- * Return null if successful, otherwise an error message that the caller must
- * free().
- */
+/* Set debugging levels.  Returns null if successful, otherwise an error
+ * message that the caller must free(). */
 char *
 vlog_set_levels_from_string(const char *s_)
 {
-    char *save_ptr = NULL;
     char *s = xstrdup(s_);
-    char *module, *facility;
-
-    for (module = strtok_r(s, ": \t", &save_ptr); module != NULL;
-         module = strtok_r(NULL, ": \t", &save_ptr)) {
-        enum vlog_module e_module;
-        enum vlog_facility e_facility;
+    char *save_ptr = NULL;
+    char *msg = NULL;
+    char *word;
 
-        facility = strtok_r(NULL, ":", &save_ptr);
+    word = strtok_r(s, " ,:\t", &save_ptr);
+    if (word && !strcasecmp(word, "PATTERN")) {
+        enum vlog_facility facility;
 
-        if (!facility || !strcmp(facility, "ANY")) {
-            e_facility = VLF_ANY_FACILITY;
-        } else {
-            e_facility = vlog_get_facility_val(facility);
-            if (e_facility >= VLF_N_FACILITIES) {
-                char *msg = xasprintf("unknown facility \"%s\"", facility);
-                free(s);
-                return msg;
-            }
+        word = strtok_r(NULL, " ,:\t", &save_ptr);
+        if (!word) {
+            msg = xstrdup("missing facility");
+            goto exit;
         }
 
-        if (!strcmp(module, "PATTERN")) {
-            vlog_set_pattern(e_facility, save_ptr);
-            break;
-        } else {
-            char *level;
-            enum vlog_level e_level;
-
-            if (!strcmp(module, "ANY")) {
-                e_module = VLM_ANY_MODULE;
-            } else {
-                e_module = vlog_get_module_val(module);
-                if (e_module >= VLM_N_MODULES) {
-                    char *msg = xasprintf("unknown module \"%s\"", module);
-                    free(s);
-                    return msg;
+        facility = (!strcasecmp(word, "ANY")
+                    ? VLF_ANY_FACILITY
+                    : vlog_get_facility_val(word));
+        if (facility == VLF_N_FACILITIES) {
+            msg = xasprintf("unknown facility \"%s\"", word);
+            goto exit;
+        }
+        vlog_set_pattern(facility, save_ptr);
+    } else {
+        struct vlog_module *module = NULL;
+        enum vlog_level level = VLL_N_LEVELS;
+        enum vlog_facility facility = VLF_N_FACILITIES;
+
+        for (; word != NULL; word = strtok_r(NULL, " ,:\t", &save_ptr)) {
+            if (!strcasecmp(word, "ANY")) {
+                continue;
+            } else if (vlog_get_facility_val(word) != VLF_N_FACILITIES) {
+                if (facility != VLF_N_FACILITIES) {
+                    msg = xstrdup("cannot specify multiple facilities");
+                    goto exit;
                 }
+                facility = vlog_get_facility_val(word);
+            } else if (vlog_get_level_val(word) != VLL_N_LEVELS) {
+                if (level != VLL_N_LEVELS) {
+                    msg = xstrdup("cannot specify multiple levels");
+                    goto exit;
+                }
+                level = vlog_get_level_val(word);
+            } else if (vlog_module_from_name(word)) {
+                if (module) {
+                    msg = xstrdup("cannot specify multiple modules");
+                    goto exit;
+                }
+                module = vlog_module_from_name(word);
+            } else {
+                msg = xasprintf("no facility, level, or module \"%s\"", word);
+                goto exit;
             }
+        }
 
-            level = strtok_r(NULL, ":", &save_ptr);
-            e_level = level ? vlog_get_level_val(level) : VLL_DBG;
-            if (e_level >= VLL_N_LEVELS) {
-                char *msg = xasprintf("unknown level \"%s\"", level);
-                free(s);
-                return msg;
-            }
-
-            vlog_set_levels(e_module, e_facility, e_level);
+        if (facility == VLF_N_FACILITIES) {
+            facility = VLF_ANY_FACILITY;
         }
+        if (level == VLL_N_LEVELS) {
+            level = VLL_DBG;
+        }
+        vlog_set_levels(module, facility, level);
     }
+
+exit:
     free(s);
-    return NULL;
+    return msg;
+}
+
+/* Set debugging levels.  Abort with an error message if 's' is invalid. */
+void
+vlog_set_levels_from_string_assert(const char *s)
+{
+    char *error = vlog_set_levels_from_string(s);
+    if (error) {
+        ovs_fatal(0, "%s", error);
+    }
 }
 
 /* If 'arg' is null, configure maximum verbosity.  Otherwise, sets
@@ -380,74 +452,149 @@ vlog_set_verbosity(const char *arg)
             ovs_fatal(0, "processing \"%s\": %s", arg, msg);
         }
     } else {
-        vlog_set_levels(VLM_ANY_MODULE, VLF_ANY_FACILITY, VLL_DBG);
+        vlog_set_levels(NULL, VLF_ANY_FACILITY, VLL_DBG);
     }
 }
 
 static void
-vlog_unixctl_set(struct unixctl_conn *conn,
-                 const char *args, void *aux OVS_UNUSED)
+vlog_unixctl_set(struct unixctl_conn *conn, int argc, const char *argv[],
+                 void *aux OVS_UNUSED)
 {
-    char *msg = vlog_set_levels_from_string(args);
-    unixctl_command_reply(conn, msg ? 501 : 202, msg);
-    free(msg);
+    int i;
+
+    for (i = 1; i < argc; i++) {
+        char *msg = vlog_set_levels_from_string(argv[i]);
+        if (msg) {
+            unixctl_command_reply_error(conn, msg);
+            free(msg);
+            return;
+        }
+    }
+    unixctl_command_reply(conn, NULL);
 }
 
 static void
-vlog_unixctl_list(struct unixctl_conn *conn,
-                  const char *args OVS_UNUSED, void *aux OVS_UNUSED)
+vlog_unixctl_list(struct unixctl_conn *conn, int argc OVS_UNUSED,
+                  const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
 {
     char *msg = vlog_get_levels();
-    unixctl_command_reply(conn, 200, msg);
+    unixctl_command_reply(conn, msg);
     free(msg);
 }
 
 static void
-vlog_unixctl_reopen(struct unixctl_conn *conn,
-                    const char *args OVS_UNUSED, void *aux OVS_UNUSED)
+vlog_unixctl_reopen(struct unixctl_conn *conn, int argc OVS_UNUSED,
+                    const char *argv[] OVS_UNUSED, void *aux OVS_UNUSED)
 {
     if (log_file_name) {
         int error = vlog_reopen_log_file();
         if (error) {
-            unixctl_command_reply(conn, 503, strerror(errno));
+            unixctl_command_reply_error(conn, ovs_strerror(errno));
         } else {
-            unixctl_command_reply(conn, 202, NULL);
+            unixctl_command_reply(conn, NULL);
+        }
+    } else {
+        unixctl_command_reply_error(conn, "Logging to file not configured");
+    }
+}
+
+static void
+set_all_rate_limits(bool enable)
+{
+    struct vlog_module **mp;
+
+    for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+        (*mp)->honor_rate_limits = enable;
+    }
+}
+
+static void
+set_rate_limits(struct unixctl_conn *conn, int argc,
+                const char *argv[], bool enable)
+{
+    if (argc > 1) {
+        int i;
+
+        for (i = 1; i < argc; i++) {
+            if (!strcasecmp(argv[i], "ANY")) {
+                set_all_rate_limits(enable);
+            } else {
+                struct vlog_module *module = vlog_module_from_name(argv[i]);
+                if (!module) {
+                    unixctl_command_reply_error(conn, "unknown module");
+                    return;
+                }
+                module->honor_rate_limits = enable;
+            }
         }
     } else {
-        unixctl_command_reply(conn, 403, "Logging to file not configured");
+        set_all_rate_limits(enable);
     }
+    unixctl_command_reply(conn, NULL);
+}
+
+static void
+vlog_enable_rate_limit(struct unixctl_conn *conn, int argc,
+                       const char *argv[], void *aux OVS_UNUSED)
+{
+    set_rate_limits(conn, argc, argv, true);
 }
 
-/* Initializes the logging subsystem. */
+static void
+vlog_disable_rate_limit(struct unixctl_conn *conn, int argc,
+                       const char *argv[], void *aux OVS_UNUSED)
+{
+    set_rate_limits(conn, argc, argv, false);
+}
+
+/* Initializes the logging subsystem and registers its unixctl server
+ * commands. */
 void
-vlog_init(void) 
+vlog_init(void)
 {
+    static char *program_name_copy;
     time_t now;
 
-    openlog(program_name, LOG_NDELAY, LOG_DAEMON);
-    vlog_set_levels(VLM_ANY_MODULE, VLF_ANY_FACILITY, VLL_INFO);
+    if (vlog_inited) {
+        return;
+    }
+    vlog_inited = true;
+
+    /* 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);
 
-    boot_time = time_msec();
     now = time_wall();
     if (now < 0) {
-        struct tm tm;
-        char s[128];
-
-        localtime_r(&now, &tm);
-        strftime(s, sizeof s, "%a, %d %b %Y %H:%M:%S %z", &tm);
+        char *s = xastrftime("%a, %d %b %Y %H:%M:%S", now, true);
         VLOG_ERR("current time is negative: %s (%ld)", s, (long int) now);
+        free(s);
     }
 
-    unixctl_command_register("vlog/set", vlog_unixctl_set, NULL);
-    unixctl_command_register("vlog/list", vlog_unixctl_list, NULL);
-    unixctl_command_register("vlog/reopen", vlog_unixctl_reopen, NULL);
+    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);
 }
 
 /* Closes the logging subsystem. */
 void
-vlog_exit(void) 
+vlog_exit(void)
 {
-    closelog(); 
+    if (vlog_inited) {
+        closelog();
+        vlog_inited = false;
+    }
 }
 
 /* Print the current logging level for each module. */
@@ -455,18 +602,36 @@ char *
 vlog_get_levels(void)
 {
     struct ds s = DS_EMPTY_INITIALIZER;
-    enum vlog_module module;
+    struct vlog_module **mp;
+    struct svec lines = SVEC_EMPTY_INITIALIZER;
+    char *line;
+    size_t i;
 
     ds_put_format(&s, "                 console    syslog    file\n");
     ds_put_format(&s, "                 -------    ------    ------\n");
 
-    for (module = 0; module < VLM_N_MODULES; module++) {
-        ds_put_format(&s, "%-16s  %4s       %4s       %4s\n",
-           vlog_get_module_name(module),
-           vlog_get_level_name(vlog_get_level(module, VLF_CONSOLE)),
-           vlog_get_level_name(vlog_get_level(module, VLF_SYSLOG)),
-           vlog_get_level_name(vlog_get_level(module, VLF_FILE)));
+    for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+        struct ds line;
+
+        ds_init(&line);
+        ds_put_format(&line, "%-16s  %4s       %4s       %4s",
+                      vlog_get_module_name(*mp),
+                      vlog_get_level_name(vlog_get_level(*mp, VLF_CONSOLE)),
+                      vlog_get_level_name(vlog_get_level(*mp, VLF_SYSLOG)),
+                      vlog_get_level_name(vlog_get_level(*mp, VLF_FILE)));
+        if (!(*mp)->honor_rate_limits) {
+            ds_put_cstr(&line, "    (rate limiting disabled)");
+        }
+        ds_put_char(&line, '\n');
+
+        svec_add_nocopy(&lines, ds_steal_cstr(&line));
+    }
+
+    svec_sort(&lines);
+    SVEC_FOR_EACH (i, line, &lines) {
+        ds_put_cstr(&s, line);
     }
+    svec_destroy(&lines);
 
     return ds_cstr(&s);
 }
@@ -475,9 +640,9 @@ vlog_get_levels(void)
  * would cause some log output, false if that module and level are completely
  * disabled. */
 bool
-vlog_is_enabled(enum vlog_module module, enum vlog_level level)
+vlog_is_enabled(const struct vlog_module *module, enum vlog_level level)
 {
-    return min_vlog_levels[module] >= level;
+    return module->min_level >= level;
 }
 
 static const char *
@@ -496,7 +661,7 @@ fetch_braces(const char *p, const char *def, char *out, size_t out_size)
 }
 
 static void
-format_log_message(enum vlog_module module, enum vlog_level level,
+format_log_message(const struct vlog_module *module, enum vlog_level level,
                    enum vlog_facility facility, unsigned int msg_num,
                    const char *message, va_list args_, struct ds *s)
 {
@@ -541,7 +706,11 @@ format_log_message(enum vlog_module module, enum vlog_level level,
             break;
         case 'd':
             p = fetch_braces(p, "%Y-%m-%d %H:%M:%S", tmp, sizeof tmp);
-            ds_put_strftime(s, tmp, NULL);
+            ds_put_strftime(s, tmp, time_wall(), false);
+            break;
+        case 'D':
+            p = fetch_braces(p, "%Y-%m-%d %H:%M:%S", tmp, sizeof tmp);
+            ds_put_strftime(s, tmp, time_wall(), true);
             break;
         case 'm':
             /* Format user-supplied log message and trim trailing new-lines. */
@@ -566,7 +735,15 @@ format_log_message(enum vlog_module module, enum vlog_level level,
             ds_put_format(s, "%ld", (long int) getpid());
             break;
         case 'r':
-            ds_put_format(s, "%lld", time_msec() - boot_time);
+            ds_put_format(s, "%lld", time_msec() - time_boot_msec());
+            break;
+        case 't':
+            ds_put_cstr(s, subprogram_name[0] ? subprogram_name : "main");
+            break;
+        case 'T':
+            if (subprogram_name[0]) {
+                ds_put_format(s, "(%s)", subprogram_name);
+            }
             break;
         default:
             ds_put_char(s, p[-1]);
@@ -591,17 +768,19 @@ format_log_message(enum vlog_module module, enum vlog_level level,
  *
  * Guaranteed to preserve errno. */
 void
-vlog_valist(enum vlog_module module, enum vlog_level level,
+vlog_valist(const struct vlog_module *module, enum vlog_level level,
             const char *message, va_list args)
 {
-    bool log_to_console = levels[module][VLF_CONSOLE] >= level;
-    bool log_to_syslog = levels[module][VLF_SYSLOG] >= level;
-    bool log_to_file = levels[module][VLF_FILE] >= level && log_file;
+    bool log_to_console = module->levels[VLF_CONSOLE] >= level;
+    bool log_to_syslog = module->levels[VLF_SYSLOG] >= level;
+    bool log_to_file = module->levels[VLF_FILE] >= level && log_fd >= 0;
     if (log_to_console || log_to_syslog || log_to_file) {
         int save_errno = errno;
         static unsigned int msg_num;
         struct ds s;
 
+        vlog_init();
+
         ds_init(&s);
         ds_reserve(&s, 1024);
         msg_num++;
@@ -630,8 +809,7 @@ vlog_valist(enum vlog_module module, enum vlog_level level,
             format_log_message(module, level, VLF_FILE, msg_num,
                                message, args, &s);
             ds_put_char(&s, '\n');
-            fputs(ds_cstr(&s), log_file);
-            fflush(log_file);
+            vlog_write_file(&s);
         }
 
         ds_destroy(&s);
@@ -640,7 +818,8 @@ vlog_valist(enum vlog_module module, enum vlog_level level,
 }
 
 void
-vlog(enum vlog_module module, enum vlog_level level, const char *message, ...)
+vlog(const struct vlog_module *module, enum vlog_level level,
+     const char *message, ...)
 {
     va_list args;
 
@@ -649,48 +828,115 @@ vlog(enum vlog_module module, enum vlog_level level, const char *message, ...)
     va_end(args);
 }
 
+/* Logs 'message' to 'module' at maximum verbosity, then exits with a failure
+ * exit code.  Always writes the message to stderr, even if the console
+ * facility is disabled.
+ *
+ * Choose this function instead of vlog_abort_valist() if the daemon monitoring
+ * facility shouldn't automatically restart the current daemon.  */
+void
+vlog_fatal_valist(const struct vlog_module *module_,
+                  const char *message, va_list args)
+{
+    struct vlog_module *module = CONST_CAST(struct vlog_module *, module_);
+
+    /* Don't log this message to the console to avoid redundancy with the
+     * message written by the later ovs_fatal_valist(). */
+    module->levels[VLF_CONSOLE] = VLL_OFF;
+
+    vlog_valist(module, VLL_EMER, message, args);
+    ovs_fatal_valist(0, message, args);
+}
+
+/* Logs 'message' to 'module' at maximum verbosity, then exits with a failure
+ * exit code.  Always writes the message to stderr, even if the console
+ * facility is disabled.
+ *
+ * Choose this function instead of vlog_abort() if the daemon monitoring
+ * facility shouldn't automatically restart the current daemon.  */
+void
+vlog_fatal(const struct vlog_module *module, const char *message, ...)
+{
+    va_list args;
+
+    va_start(args, message);
+    vlog_fatal_valist(module, message, args);
+    va_end(args);
+}
+
+/* Logs 'message' to 'module' at maximum verbosity, then calls abort().  Always
+ * writes the message to stderr, even if the console facility is disabled.
+ *
+ * Choose this function instead of vlog_fatal_valist() if the daemon monitoring
+ * facility should automatically restart the current daemon.  */
+void
+vlog_abort_valist(const struct vlog_module *module_,
+                  const char *message, va_list args)
+{
+    struct vlog_module *module = (struct vlog_module *) module_;
+
+    /* Don't log this message to the console to avoid redundancy with the
+     * message written by the later ovs_abort_valist(). */
+    module->levels[VLF_CONSOLE] = VLL_OFF;
+
+    vlog_valist(module, VLL_EMER, message, args);
+    ovs_abort_valist(0, message, args);
+}
+
+/* Logs 'message' to 'module' at maximum verbosity, then calls abort().  Always
+ * writes the message to stderr, even if the console facility is disabled.
+ *
+ * Choose this function instead of vlog_fatal() if the daemon monitoring
+ * facility should automatically restart the current daemon.  */
+void
+vlog_abort(const struct vlog_module *module, const char *message, ...)
+{
+    va_list args;
+
+    va_start(args, message);
+    vlog_abort_valist(module, message, args);
+    va_end(args);
+}
+
 bool
-vlog_should_drop(enum vlog_module module, enum vlog_level level,
+vlog_should_drop(const struct vlog_module *module, enum vlog_level level,
                  struct vlog_rate_limit *rl)
 {
+    if (!module->honor_rate_limits) {
+        return false;
+    }
+
     if (!vlog_is_enabled(module, level)) {
         return true;
     }
 
-    if (rl->tokens < VLOG_MSG_TOKENS) {
+    if (!token_bucket_withdraw(&rl->token_bucket, VLOG_MSG_TOKENS)) {
         time_t now = time_now();
-        if (rl->last_fill > now) {
-            /* Last filled in the future?  Time must have gone backward, or
-             * 'rl' has not been used before. */
-            rl->tokens = rl->burst;
-        } else if (rl->last_fill < now) {
-            unsigned int add = sat_mul(rl->rate, now - rl->last_fill);
-            unsigned int tokens = sat_add(rl->tokens, add);
-            rl->tokens = MIN(tokens, rl->burst);
-            rl->last_fill = now;
-        }
-        if (rl->tokens < VLOG_MSG_TOKENS) {
-            if (!rl->n_dropped) {
-                rl->first_dropped = now;
-            }
-            rl->n_dropped++;
-            return true;
+        if (!rl->n_dropped) {
+            rl->first_dropped = now;
         }
+        rl->last_dropped = now;
+        rl->n_dropped++;
+        return true;
     }
-    rl->tokens -= VLOG_MSG_TOKENS;
 
     if (rl->n_dropped) {
+        time_t now = time_now();
+        unsigned int first_dropped_elapsed = now - rl->first_dropped;
+        unsigned int last_dropped_elapsed = now - rl->last_dropped;
+
         vlog(module, level,
-             "Dropped %u log messages in last %u seconds "
-             "due to excessive rate",
-             rl->n_dropped, (unsigned int) (time_now() - rl->first_dropped));
+             "Dropped %u log messages in last %u seconds (most recently, "
+             "%u seconds ago) due to excessive rate",
+             rl->n_dropped, first_dropped_elapsed, last_dropped_elapsed);
+
         rl->n_dropped = 0;
     }
     return false;
 }
 
 void
-vlog_rate_limit(enum vlog_module module, enum vlog_level level,
+vlog_rate_limit(const struct vlog_module *module, enum vlog_level level,
                 struct vlog_rate_limit *rl, const char *message, ...)
 {
     if (!vlog_should_drop(module, level, rl)) {
@@ -703,12 +949,68 @@ vlog_rate_limit(enum vlog_module module, enum vlog_level level,
 }
 
 void
-vlog_usage(void) 
+vlog_usage(void)
 {
     printf("\nLogging options:\n"
-           "  -v, --verbose=MODULE[:FACILITY[:LEVEL]]  set logging levels\n"
+           "  -v, --verbose=[SPEC]    set logging levels\n"
            "  -v, --verbose           set maximum verbosity level\n"
            "  --log-file[=FILE]       enable logging to specified FILE\n"
            "                          (default: %s/%s.log)\n",
-           ovs_logdir, program_name);
+           ovs_logdir(), program_name);
+}
+\f
+static bool vlog_async_inited = false;
+
+static worker_request_func vlog_async_write_request_cb;
+
+static void
+vlog_write_file(struct ds *s)
+{
+    if (worker_is_running()) {
+        static bool in_worker_request = false;
+        if (!in_worker_request) {
+            in_worker_request = true;
+
+            worker_request(s->string, s->length,
+                           &log_fd, vlog_async_inited ? 0 : 1,
+                           vlog_async_write_request_cb, NULL, NULL);
+            vlog_async_inited = true;
+
+            in_worker_request = false;
+            return;
+        } else {
+            /* We've been entered recursively.  This can happen if
+             * worker_request(), or a function that it calls, tries to log
+             * something.  We can't call worker_request() recursively, so fall
+             * back to writing the log file directly. */
+            COVERAGE_INC(vlog_recursive);
+        }
+    }
+    ignore(write(log_fd, s->string, s->length));
+}
+
+static void
+vlog_update_async_log_fd(void)
+{
+    if (worker_is_running()) {
+        worker_request(NULL, 0, &log_fd, 1, vlog_async_write_request_cb,
+                       NULL, NULL);
+        vlog_async_inited = true;
+    }
+}
+
+static void
+vlog_async_write_request_cb(struct ofpbuf *request,
+                            const int *fd, size_t n_fds)
+{
+    if (n_fds > 0) {
+        if (log_fd >= 0) {
+            close(log_fd);
+        }
+        log_fd = *fd;
+    }
+
+    if (request->size > 0) {
+        ignore(write(log_fd, request->data, request->size));
+    }
 }