#include "ofpbuf.h"
#include "ovs-thread.h"
#include "sat-math.h"
+#include "socket-util.h"
#include "svec.h"
#include "timeval.h"
#include "unixctl.h"
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
/* Name for each logging level. */
static const char *const level_names[VLL_N_LEVELS] = {
-#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) #NAME,
+#define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) #NAME,
VLOG_LEVELS
#undef VLOG_LEVEL
};
/* Syslog value for each logging level. */
static const int syslog_levels[VLL_N_LEVELS] = {
-#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) SYSLOG_LEVEL,
+#define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) SYSLOG_LEVEL,
VLOG_LEVELS
#undef VLOG_LEVEL
};
+/* RFC 5424 defines specific values for each syslog level. Normally LOG_* use
+ * the same values. Verify that in fact they're the same. If we get assertion
+ * failures here then we need to define a separate rfc5424_levels[] array. */
+#define VLOG_LEVEL(NAME, SYSLOG_LEVEL, RFC5424) \
+ BUILD_ASSERT_DECL(SYSLOG_LEVEL == RFC5424);
+VLOG_LEVELS
+#undef VLOG_LEVELS
+
+/* Similarly, RFC 5424 defines the local0 facility with the value ordinarily
+ * used for LOG_LOCAL0. */
+BUILD_ASSERT_DECL(LOG_LOCAL0 == (16 << 3));
+
/* 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
+struct list vlog_modules = LIST_INITIALIZER(&vlog_modules);
/* Protects the 'pattern' in all "struct facility"s, so that a race between
* changing and reading the pattern does not cause an access to freed
*
* All of the following is protected by 'log_file_mutex', which nests inside
* pattern_rwlock. */
-static struct ovs_mutex log_file_mutex = OVS_ADAPTIVE_MUTEX_INITIALIZER;
+static struct ovs_mutex log_file_mutex = OVS_MUTEX_INITIALIZER;
static char *log_file_name OVS_GUARDED_BY(log_file_mutex);
static int log_fd OVS_GUARDED_BY(log_file_mutex) = -1;
static struct async_append *log_writer OVS_GUARDED_BY(log_file_mutex);
static bool log_async OVS_GUARDED_BY(log_file_mutex);
+/* Syslog export configuration. */
+static int syslog_fd OVS_GUARDED_BY(pattern_rwlock) = -1;
+
static void format_log_message(const struct vlog_module *, enum vlog_level,
- enum vlog_facility,
+ const char *pattern,
const char *message, va_list, struct ds *)
- PRINTF_FORMAT(4, 0) OVS_REQ_RDLOCK(&pattern_rwlock);
+ PRINTF_FORMAT(4, 0);
/* Searches the 'n_names' in 'names'. Returns the index of a match for
* 'target', or 'n_names' if no name matches. */
struct vlog_module *
vlog_module_from_name(const char *name)
{
- struct vlog_module **mp;
+ struct vlog_module *mp;
- for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
- if (!strcasecmp(name, (*mp)->name)) {
- return *mp;
+ LIST_FOR_EACH (mp, list, &vlog_modules) {
+ if (!strcasecmp(name, mp->name)) {
+ return mp;
}
}
+
return NULL;
}
ovs_mutex_lock(&log_file_mutex);
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);
+ struct vlog_module *mp;
+ LIST_FOR_EACH (mp, list, &vlog_modules) {
+ mp->levels[facility] = level;
+ update_min_level(mp);
}
} else {
module->levels[facility] = level;
vlog_set_log_file(const char *file_name)
{
char *new_log_file_name;
- struct vlog_module **mp;
+ struct vlog_module *mp;
struct stat old_stat;
struct stat new_stat;
int new_log_fd;
log_writer = async_append_create(new_log_fd);
}
- for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
- update_min_level(*mp);
+ LIST_FOR_EACH (mp, list, &vlog_modules) {
+ update_min_level(mp);
}
ovs_mutex_unlock(&log_file_mutex);
}
}
+/* Set the vlog udp syslog target. */
+void
+vlog_set_syslog_target(const char *target)
+{
+ int new_fd;
+
+ inet_open_active(SOCK_DGRAM, target, 0, NULL, &new_fd, 0);
+
+ ovs_rwlock_wrlock(&pattern_rwlock);
+ if (syslog_fd >= 0) {
+ close(syslog_fd);
+ }
+ syslog_fd = new_fd;
+ ovs_rwlock_unlock(&pattern_rwlock);
+}
+
static void
vlog_unixctl_set(struct unixctl_conn *conn, int argc, const char *argv[],
void *aux OVS_UNUSED)
static void
set_all_rate_limits(bool enable)
{
- struct vlog_module **mp;
+ struct vlog_module *mp;
- for (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
- (*mp)->honor_rate_limits = enable;
+ LIST_FOR_EACH (mp, list, &vlog_modules) {
+ mp->honor_rate_limits = enable;
}
}
set_rate_limits(conn, argc, argv, false);
}
-static void
-vlog_init__(void)
-{
- static char *program_name_copy;
- time_t 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();
- if (now < 0) {
- 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", "{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.
vlog_get_levels(void)
{
struct ds s = DS_EMPTY_INITIALIZER;
- struct vlog_module **mp;
+ 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 (mp = vlog_modules; mp < &vlog_modules[n_vlog_modules]; mp++) {
+ LIST_FOR_EACH (mp, list, &vlog_modules) {
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) {
+ 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');
static void
format_log_message(const struct vlog_module *module, enum vlog_level level,
- enum vlog_facility facility,
- const char *message, va_list args_, struct ds *s)
+ const char *pattern, const char *message,
+ va_list args_, struct ds *s)
{
char tmp[128];
va_list args;
const char *p;
ds_clear(s);
- for (p = facilities[facility].pattern; *p != '\0'; ) {
+ for (p = pattern; *p != '\0'; ) {
const char *subprogram_name;
enum { LEFT, RIGHT } justify = RIGHT;
int pad = '0';
case 'A':
ds_put_cstr(s, program_name);
break;
+ case 'B':
+ ds_put_format(s, "%d", LOG_LOCAL0 + syslog_levels[level]);
+ break;
case 'c':
p = fetch_braces(p, "", tmp, sizeof tmp);
ds_put_cstr(s, vlog_get_module_name(module));
break;
case 'd':
- p = fetch_braces(p, "%Y-%m-%d %H:%M:%S", tmp, sizeof tmp);
- ds_put_strftime(s, tmp, time_wall(), false);
+ p = fetch_braces(p, "%Y-%m-%d %H:%M:%S.###", tmp, sizeof tmp);
+ ds_put_strftime_msec(s, tmp, time_wall_msec(), 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);
+ p = fetch_braces(p, "%Y-%m-%d %H:%M:%S.###", tmp, sizeof tmp);
+ ds_put_strftime_msec(s, tmp, time_wall_msec(), true);
+ break;
+ case 'E':
+ gethostname(tmp, sizeof tmp);
+ tmp[sizeof tmp - 1] = '\0';
+ ds_put_cstr(s, tmp);
break;
case 'm':
/* Format user-supplied log message and trim trailing new-lines. */
}
}
+/* Exports the given 'syslog_message' to the configured udp syslog sink. */
+static void
+send_to_syslog_fd(const char *s, size_t length)
+ OVS_REQ_RDLOCK(pattern_rwlock)
+{
+ static size_t max_length = SIZE_MAX;
+ size_t send_len = MIN(length, max_length);
+
+ while (write(syslog_fd, s, send_len) < 0 && errno == EMSGSIZE) {
+ send_len -= send_len / 20;
+ max_length = send_len;
+ }
+}
+
/* Writes 'message' to the log at the given 'level' and as coming from the
* given 'module'.
*
ovs_rwlock_rdlock(&pattern_rwlock);
if (log_to_console) {
- format_log_message(module, level, VLF_CONSOLE, message, args, &s);
+ format_log_message(module, level, facilities[VLF_CONSOLE].pattern,
+ message, args, &s);
ds_put_char(&s, '\n');
fputs(ds_cstr(&s), stderr);
}
char *save_ptr = NULL;
char *line;
- format_log_message(module, level, VLF_SYSLOG, message, args, &s);
+ format_log_message(module, level, facilities[VLF_SYSLOG].pattern,
+ message, args, &s);
for (line = strtok_r(s.string, "\n", &save_ptr); line;
line = strtok_r(NULL, "\n", &save_ptr)) {
syslog(syslog_level, "%s", line);
}
+
+ if (syslog_fd >= 0) {
+ format_log_message(module, level,
+ "<%B>1 %D{%Y-%m-%dT%H:%M:%S.###Z} "
+ "%E %A %P %c - \xef\xbb\xbf%m",
+ message, args, &s);
+ send_to_syslog_fd(ds_cstr(&s), s.length);
+ }
}
if (log_to_file) {
- format_log_message(module, level, VLF_FILE, message, args, &s);
+ format_log_message(module, level, facilities[VLF_FILE].pattern,
+ message, args, &s);
ds_put_char(&s, '\n');
ovs_mutex_lock(&log_file_mutex);
void
vlog_usage(void)
{
- printf("\nLogging options:\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",
+ printf("\n\
+Logging options:\n\
+ -vSPEC, --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\
+ --syslog-target=HOST:PORT also send syslog msgs to HOST:PORT via UDP\n",
ovs_logdir(), program_name);
}