From be0ea769dd927cc683eda7d7ab0abeab630b2b99 Mon Sep 17 00:00:00 2001 From: Ben Pfaff Date: Thu, 23 Oct 2008 11:08:23 -0700 Subject: [PATCH] Make the format of vlog messages user-configurable. --- controller/controller.8.in | 5 + include/vlog.h | 19 +-- lib/vlog.c | 257 ++++++++++++++++++++++++++++-------- secchan/secchan.8.in | 5 + switch/switch.8.in | 5 + utilities/dpctl.8 | 5 + utilities/ofp-discover.8.in | 5 + utilities/vlogconf.8 | 86 ++++++++++++ 8 files changed, 322 insertions(+), 65 deletions(-) diff --git a/controller/controller.8.in b/controller/controller.8.in index 26c7c4cb..044125ba 100644 --- a/controller/controller.8.in +++ b/controller/controller.8.in @@ -169,6 +169,11 @@ omitted, \fIlevel\fR defaults to \fBdbg\fR. Sets the maximum logging verbosity level, equivalent to \fB--verbose=ANY:ANY:dbg\fR. +.TP +\fB-vPATTERN:\fIfacility\fB:\fIpattern\fR, \fB--verbose=PATTERN:\fIfacility\fB:\fIpattern\fR +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Refer to +\fBvlogconf\fR(8) for a description of the valid syntax for \fIpattern\fR. + .TP .BR \-V ", " \-\^\-version Prints version information to the console. diff --git a/include/vlog.h b/include/vlog.h index c6980a2f..f96ce1a2 100644 --- a/include/vlog.h +++ b/include/vlog.h @@ -42,12 +42,12 @@ /* Logging importance levels. */ #define VLOG_LEVELS \ - VLOG_LEVEL(EMER) \ - VLOG_LEVEL(ERR) \ - VLOG_LEVEL(WARN) \ - VLOG_LEVEL(DBG) + VLOG_LEVEL(EMER, LOG_ALERT) \ + VLOG_LEVEL(ERR, LOG_ERR) \ + VLOG_LEVEL(WARN, LOG_WARNING) \ + VLOG_LEVEL(DBG, LOG_DEBUG) enum vlog_level { -#define VLOG_LEVEL(NAME) VLL_##NAME, +#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) VLL_##NAME, VLOG_LEVELS #undef VLOG_LEVEL VLL_N_LEVELS @@ -57,11 +57,11 @@ const char *vlog_get_level_name(enum vlog_level); enum vlog_level vlog_get_level_val(const char *name); /* Facilities that we can log to. */ -#define VLOG_FACILITIES \ - VLOG_FACILITY(SYSLOG) \ - VLOG_FACILITY(CONSOLE) +#define VLOG_FACILITIES \ + VLOG_FACILITY(SYSLOG, "%05N|%c|%p|%m") \ + VLOG_FACILITY(CONSOLE, "%d{%b %d %H:%M:%S}|%05N|%c|%p|%m") enum vlog_facility { -#define VLOG_FACILITY(NAME) VLF_##NAME, +#define VLOG_FACILITY(NAME, PATTERN) VLF_##NAME, VLOG_FACILITIES #undef VLOG_FACILITY VLF_N_FACILITIES, @@ -115,6 +115,7 @@ struct vlog_rate_limit { /* Configuring how each module logs messages. */ enum vlog_level vlog_get_level(enum vlog_module, enum vlog_facility); void vlog_set_levels(enum vlog_module, enum vlog_facility, enum vlog_level); +void vlog_set_pattern(enum vlog_facility, const char *pattern); char *vlog_set_levels_from_string(const char *); char *vlog_get_levels(void); bool vlog_is_enabled(enum vlog_module, enum vlog_level); diff --git a/lib/vlog.c b/lib/vlog.c index a136e563..057d6d58 100644 --- a/lib/vlog.c +++ b/lib/vlog.c @@ -34,14 +34,15 @@ #include #include "vlog.h" #include +#include #include #include #include #include -#include -#include +#include #include #include +#include #include "dynamic-string.h" #include "sat-math.h" #include "timeval.h" @@ -51,26 +52,43 @@ /* Name for each logging level. */ static const char *level_names[VLL_N_LEVELS] = { -#define VLOG_LEVEL(NAME) #NAME, +#define VLOG_LEVEL(NAME, SYSLOG_LEVEL) #NAME, VLOG_LEVELS #undef VLOG_LEVEL }; -/* Name for each logging facility. */ -static const char *facility_names[VLF_N_FACILITIES] = { -#define VLOG_FACILITY(NAME) #NAME, - VLOG_FACILITIES -#undef VLOG_FACILITY +/* Syslog value for each logging level. */ +static 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, #include "vlog-modules.def" +#undef VLOG_MODULE }; +/* Information about each facility. */ +struct facility { + const char *name; /* Name. */ + char *pattern; /* Current pattern. */ + bool default_pattern; /* Whether current pattern is the default. */ +}; +static struct facility facilities[VLF_N_FACILITIES] = { +#define VLOG_FACILITY(NAME, PATTERN) {#NAME, PATTERN, true}, + VLOG_FACILITIES +#undef VLOG_FACILITY +}; + +/* Current log levels. */ static int levels[VLM_N_MODULES][VLF_N_FACILITIES]; +/* Time at which vlog was initialized, in milliseconds. */ +static long long int boot_time; + /* Searches the 'n_names' in 'names'. Returns the index of a match for * 'target', or 'n_names' if no name matches. */ static size_t @@ -108,7 +126,7 @@ const char * vlog_get_facility_name(enum vlog_facility facility) { assert(facility < VLF_N_FACILITIES); - return facility_names[facility]; + return facilities[facility].name; } /* Returns the logging facility named 'name', or VLF_N_FACILITIES if 'name' is @@ -116,7 +134,14 @@ vlog_get_facility_name(enum vlog_facility facility) enum vlog_facility vlog_get_facility_val(const char *name) { - return search_name_array(name, facility_names, ARRAY_SIZE(facility_names)); + size_t i; + + for (i = 0; i < VLF_N_FACILITIES; i++) { + if (!strcasecmp(facilities[i].name, name)) { + break; + } + } + return i; } /* Returns the name for logging module 'module'. */ @@ -174,6 +199,32 @@ vlog_set_levels(enum vlog_module module, enum vlog_facility facility, } } +static void +do_set_pattern(enum vlog_facility facility, const char *pattern) +{ + struct facility *f = &facilities[facility]; + if (!f->default_pattern) { + free(f->pattern); + } else { + f->default_pattern = false; + } + f->pattern = xstrdup(pattern); +} + +/* Sets the pattern for the given 'facility' to 'pattern'. */ +void +vlog_set_pattern(enum vlog_facility facility, const char *pattern) +{ + assert(facility < VLF_N_FACILITIES || facility == VLF_ANY_FACILITY); + if (facility == VLF_ANY_FACILITY) { + for (facility = 0; facility < VLF_N_FACILITIES; facility++) { + do_set_pattern(facility, pattern); + } + } else { + do_set_pattern(facility, pattern); + } +} + /* Set debugging levels: * * mod[:facility[:level]] mod2[:facility[:level]] ... @@ -186,27 +237,14 @@ vlog_set_levels_from_string(const char *s_) { char *save_ptr; char *s = xstrdup(s_); - char *module, *level, *facility; + 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_level e_level; enum vlog_facility e_facility; facility = strtok_r(NULL, ":", &save_ptr); - level = strtok_r(NULL, ":", &save_ptr); - - 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; - } - } if (!facility || !strcmp(facility, "ANY")) { e_facility = VLF_ANY_FACILITY; @@ -219,14 +257,34 @@ vlog_set_levels_from_string(const char *s_) } } - 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; - } + 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; + } + } - vlog_set_levels(e_module, e_facility, e_level); + 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); + } } free(s); return NULL; @@ -256,6 +314,7 @@ vlog_init(void) openlog(program_name, LOG_NDELAY, LOG_DAEMON); vlog_set_levels(VLM_ANY_MODULE, VLF_ANY_FACILITY, VLL_WARN); + boot_time = time_msec(); now = time_now(); if (now < 0) { struct tm tm; @@ -304,6 +363,107 @@ vlog_is_enabled(enum vlog_module module, enum vlog_level level) || levels[module][VLF_SYSLOG] >= level); } +static const char * +fetch_braces(const char *p, const char *def, char *out, size_t out_size) +{ + if (*p == '{') { + size_t n = strcspn(p + 1, "}"); + size_t n_copy = MIN(n, out_size - 1); + memcpy(out, p + 1, n_copy); + out[n_copy] = '\0'; + p += n + 2; + } else { + strlcpy(out, def, out_size); + } + return p; +} + +static void +format_log_message(enum vlog_module module, enum vlog_level level, + enum vlog_facility facility, unsigned int msg_num, + 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'; ) { + enum { LEFT, RIGHT } justify = RIGHT; + int pad = '0'; + size_t length, field, used; + + if (*p != '%') { + ds_put_char(s, *p++); + continue; + } + + p++; + if (*p == '-') { + justify = LEFT; + p++; + } + if (*p == '0') { + pad = '0'; + p++; + } + field = 0; + while (isdigit(*p)) { + field = (field * 10) + (*p - '0'); + p++; + } + + length = s->length; + switch (*p++) { + case 'A': + ds_put_cstr(s, program_name); + 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, NULL); + break; + case 'm': + va_copy(args, args_); + ds_put_format_valist(s, message, args); + va_end(args); + break; + case 'N': + ds_put_format(s, "%u", msg_num); + break; + case 'n': + ds_put_char(s, '\n'); + break; + case 'p': + ds_put_cstr(s, vlog_get_level_name(level)); + break; + case 'P': + ds_put_format(s, "%ld", (long int) getpid()); + break; + case 'r': + ds_put_format(s, "%lld", time_msec() - boot_time); + break; + default: + ds_put_char(s, p[-1]); + break; + } + used = s->length - length; + if (used < field) { + size_t n_pad = field - used; + if (justify == RIGHT) { + ds_put_uninit(s, n_pad); + memmove(&s->string[length + n_pad], &s->string[length], used); + memset(&s->string[length], pad, n_pad); + } else { + ds_put_char_multiple(s, pad, n_pad); + } + } + } +} + /* Writes 'message' to the log at the given 'level' and as coming from the * given 'module'. * @@ -316,43 +476,28 @@ vlog_valist(enum vlog_module module, enum vlog_level level, bool log_syslog = levels[module][VLF_SYSLOG] >= level; if (log_console || log_syslog) { int save_errno = errno; - static int msg_num; - const char *module_name = vlog_get_module_name(module); - const char *level_name = vlog_get_level_name(level); - time_t now; - struct tm tm; - size_t time_len; + static unsigned int msg_num; struct ds s; - now = time_now(); - localtime_r(&now, &tm); - - /* Compose log message. */ ds_init(&s); ds_reserve(&s, 1024); - ds_put_strftime(&s, "%b %d %H:%M:%S|", &tm); - time_len = s.length; - ds_put_format(&s, "%05d|%s|%s:", ++msg_num, module_name, level_name); - ds_put_format_valist(&s, message, args); - ds_chomp(&s, '\n'); + msg_num++; if (log_console) { - fprintf(stderr, "%s\n", s.string); + format_log_message(module, level, VLF_CONSOLE, msg_num, + message, args, &s); + ds_put_char(&s, '\n'); + fputs(ds_cstr(&s), stderr); } if (log_syslog) { - int syslog_level = LOG_ALERT; + int syslog_level = syslog_levels[level]; char *save_ptr = NULL; char *line; - switch (level) { - case VLL_EMER: syslog_level = LOG_ALERT; break; - case VLL_ERR: syslog_level = LOG_ERR; break; - case VLL_WARN: syslog_level = LOG_WARNING; break; - case VLL_DBG: syslog_level = LOG_DEBUG; break; - case VLL_N_LEVELS: NOT_REACHED(); - } - for (line = strtok_r(&s.string[time_len], "\n", &save_ptr); line; + format_log_message(module, level, VLF_SYSLOG, msg_num, + 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); } diff --git a/secchan/secchan.8.in b/secchan/secchan.8.in index beb57b04..5e887915 100644 --- a/secchan/secchan.8.in +++ b/secchan/secchan.8.in @@ -441,6 +441,11 @@ omitted, \fIlevel\fR defaults to \fBdbg\fR. Sets the maximum logging verbosity level, equivalent to \fB--verbose=ANY:ANY:dbg\fR. +.TP +\fB-vPATTERN:\fIfacility\fB:\fIpattern\fR, \fB--verbose=PATTERN:\fIfacility\fB:\fIpattern\fR +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Refer to +\fBvlogconf\fR(8) for a description of the valid syntax for \fIpattern\fR. + .TP .BR \-V ", " \-\^\-version Prints version information to the console. diff --git a/switch/switch.8.in b/switch/switch.8.in index aa1bbc42..6d1a33b4 100644 --- a/switch/switch.8.in +++ b/switch/switch.8.in @@ -129,6 +129,11 @@ omitted, \fIlevel\fR defaults to \fBdbg\fR. Sets the maximum logging verbosity level, equivalent to \fB--verbose=ANY:ANY:dbg\fR. +.TP +\fB-vPATTERN:\fIfacility\fB:\fIpattern\fR, \fB--verbose=PATTERN:\fIfacility\fB:\fIpattern\fR +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Refer to +\fBvlogconf\fR(8) for a description of the valid syntax for \fIpattern\fR. + .TP .BR \-V ", " \-\^\-version Prints version information to the console. diff --git a/utilities/dpctl.8 b/utilities/dpctl.8 index a1fcd077..c7805932 100644 --- a/utilities/dpctl.8 +++ b/utilities/dpctl.8 @@ -448,6 +448,11 @@ omitted, \fIlevel\fR defaults to \fBdbg\fR. Sets the maximum logging verbosity level, equivalent to \fB--verbose=ANY:ANY:dbg\fR. +.TP +\fB-vPATTERN:\fIfacility\fB:\fIpattern\fR, \fB--verbose=PATTERN:\fIfacility\fB:\fIpattern\fR +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Refer to +\fBvlogconf\fR(8) for a description of the valid syntax for \fIpattern\fR. + .TP .BR \-V ", " \-\^\-version Prints version information to the console. diff --git a/utilities/ofp-discover.8.in b/utilities/ofp-discover.8.in index 694b3b93..772bccbd 100644 --- a/utilities/ofp-discover.8.in +++ b/utilities/ofp-discover.8.in @@ -116,6 +116,11 @@ omitted, \fIlevel\fR defaults to \fBdbg\fR. Sets the maximum logging verbosity level, equivalent to \fB--verbose=ANY:ANY:dbg\fR. +.TP +\fB-vPATTERN:\fIfacility\fB:\fIpattern\fR, \fB--verbose=PATTERN:\fIfacility\fB:\fIpattern\fR +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Refer to +\fBvlogconf\fR(8) for a description of the valid syntax for \fIpattern\fR. + .TP .BR \-V ", " \-\^\-version Prints version information to the console. diff --git a/utilities/vlogconf.8 b/utilities/vlogconf.8 index 74e81616..7298d29d 100644 --- a/utilities/vlogconf.8 +++ b/utilities/vlogconf.8 @@ -57,6 +57,92 @@ logging levels for both facilities. If it is omitted, minimum severity of a message for it to be logged. If it is omitted, \fIlevel\fR defaults to \fBdbg\fR. +.TP +\fB-s PATTERN:\fIfacility\fB:\fIpattern\fR, \fB--set=PATTERN:\fIfacility\fB:\fIpattern\fR + +Sets the log pattern for \fIfacility\fR to \fIpattern\fR. Each time a +message is logged to \fIfacility\fR, \fIpattern\fR determines the +message's formatting. Most characters in \fIpattern\fR are copied +literally to the log, but special escapes beginning with \fB%\fR are +expanded as follows: + +.RS +.TP +\fB%A\fR +The name of the application logging the message, e.g. \fBsecchan\fR. + +.TP +\fB%c\fR +The name of the module (as shown by \fBvlogconf --list\fR) logging +the message. + +.TP +\fB%d\fR +The current date and time in ISO 8601 format (YYYY-MM-DD HH:MM:SS). + +.TP +\fB%d{\fIformat\fB}\fR +The current date and time in the specified \fIformat\fR, which takes +the same format as the \fItemplate\fR argument to \fBstrftime\fR(3). + +.TP +\fB%m\fR +The message being logged. + +.TP +\fB%N\fR +A serial number for this message within this run of the program, as a +decimal number. The first message a program logs has serial number 1, +the second one has serial number 2, and so on. + +.TP +\fB%n\fR +A new-line. + +.TP +\fB%p\fR +The level at which the message is logged, e.g. \fBDBG\fR. + +.TP +\fB%P\fR +The program's process ID (pid), as a decimal number. + +.TP +\fB%r\fR +The number of milliseconds elapsed from the start of the application +to the time the message was logged. + +.TP +\fB%%\fR +A literal \fB%\fR. +.RE + +.IP +A few options may appear between the \fB%\fR and the format specifier +character, in this order: + +.RS +.TP +\fB-\fR +Left justify the escape's expansion within its field width. Right +justification is the default. + +.TP +\fB0\fR +Pad the field to the field width with \fB0\fRs. Padding with spaces +is the default. + +.TP +\fIwidth\fR +A number specifies the minimum field width. If the escape expands to +fewer characters than \fIwidth\fR then it is padded to fill the field +width. (A field wider than \fIwidth\fR is not truncated to fit.) +.RE + +.IP +The default pattern for console output is \fB%d{%b %d +%H:%M:%S}|%05N|%c|%p|%m\fR; for syslog output, \fB%05N|%c|%p|%m\fR. + .SH OPTIONS .TP \fB\-h\fR, \fB\-\^\-help\fR -- 2.30.2