From 77779ead6d09604573b7170fa27fb9a5926cd02e Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Sat, 21 Feb 2009 22:45:56 +0100 Subject: rework logging to make it more modular --- src/daemon/main.c | 15 ++-- src/pulsecore/cli-command.c | 6 +- src/pulsecore/log.c | 197 +++++++++++++++++++++++++------------------- src/pulsecore/log.h | 44 +++++++--- src/tests/envelope-test.c | 2 +- src/tests/memblockq-test.c | 2 +- src/tests/mix-test.c | 2 +- src/tests/remix-test.c | 2 +- src/tests/resampler-test.c | 2 +- 9 files changed, 162 insertions(+), 110 deletions(-) diff --git a/src/daemon/main.c b/src/daemon/main.c index 0675f196..b630bd17 100644 --- a/src/daemon/main.c +++ b/src/daemon/main.c @@ -351,8 +351,9 @@ int main(int argc, char *argv[]) { int autospawn_fd = -1; pa_bool_t autospawn_locked = FALSE; - pa_log_set_maximal_level(PA_LOG_INFO); pa_log_set_ident("pulseaudio"); + pa_log_set_level(PA_LOG_INFO); + pa_log_set_flags(PA_LOG_COLORS|PA_LOG_PRINT_FILE|PA_LOG_PRINT_LEVEL, PA_LOG_RESET); #if defined(__linux__) && defined(__OPTIMIZE__) /* @@ -432,11 +433,13 @@ int main(int argc, char *argv[]) { goto finish; } - pa_log_set_maximal_level(conf->log_level); - pa_log_set_target(conf->auto_log_target ? PA_LOG_STDERR : conf->log_target, NULL); - pa_log_set_show_meta(conf->log_meta); + pa_log_set_level(conf->log_level); + pa_log_set_target(conf->auto_log_target ? PA_LOG_STDERR : conf->log_target); + if (conf->log_meta) + pa_log_set_flags(PA_LOG_PRINT_META, PA_LOG_SET); + if (conf->log_time) + pa_log_set_flags(PA_LOG_PRINT_TIME, PA_LOG_SET); pa_log_set_show_backtrace(conf->log_backtrace); - pa_log_set_show_time(conf->log_time); pa_log_debug("Started as real root: %s, suid root: %s", pa_yes_no(real_root), pa_yes_no(suid_root)); @@ -771,7 +774,7 @@ int main(int argc, char *argv[]) { #endif if (conf->auto_log_target) - pa_log_set_target(PA_LOG_SYSLOG, NULL); + pa_log_set_target(PA_LOG_SYSLOG); #ifdef HAVE_SETSID setsid(); diff --git a/src/pulsecore/cli-command.c b/src/pulsecore/cli-command.c index 7066e7e7..4ce87d6d 100644 --- a/src/pulsecore/cli-command.c +++ b/src/pulsecore/cli-command.c @@ -1350,7 +1350,7 @@ static int pa_cli_command_log_level(pa_core *c, pa_tokenizer *t, pa_strbuf *buf, return -1; } - pa_log_set_maximal_level(level); + pa_log_set_level(level); return 0; } @@ -1374,7 +1374,7 @@ static int pa_cli_command_log_meta(pa_core *c, pa_tokenizer *t, pa_strbuf *buf, return -1; } - pa_log_set_show_meta(b); + pa_log_set_flags(PA_LOG_PRINT_META, b ? PA_LOG_SET : PA_LOG_UNSET); return 0; } @@ -1398,7 +1398,7 @@ static int pa_cli_command_log_time(pa_core *c, pa_tokenizer *t, pa_strbuf *buf, return -1; } - pa_log_set_show_time(b); + pa_log_set_flags(PA_LOG_PRINT_TIME, b ? PA_LOG_SET : PA_LOG_UNSET); return 0; } diff --git a/src/pulsecore/log.c b/src/pulsecore/log.c index 89b75da3..9931586d 100644 --- a/src/pulsecore/log.c +++ b/src/pulsecore/log.c @@ -51,18 +51,21 @@ #include "log.h" -#define ENV_LOGLEVEL "PULSE_LOG" -#define ENV_LOGMETA "PULSE_LOG_META" -#define ENV_LOGTIME "PULSE_LOG_TIME" -#define ENV_LOGBACKTRACE "PULSE_LOG_BACKTRACE" - -static char *log_ident = NULL, *log_ident_local = NULL; -static pa_log_target_t log_target = PA_LOG_STDERR; -static pa_log_func_t user_log_func = NULL; -static pa_log_level_t maximal_level = PA_LOG_ERROR; -static unsigned show_backtrace = 0; -static pa_bool_t show_meta = FALSE; -static pa_bool_t show_time = FALSE; +#define ENV_LOG_SYSLOG "PULSE_LOG_SYSLOG" +#define ENV_LOG_LEVEL "PULSE_LOG" +#define ENV_LOG_COLORS "PULSE_LOG_COLORS" +#define ENV_LOG_PRINT_TIME "PULSE_LOG_TIME" +#define ENV_LOG_PRINT_FILE "PULSE_LOG_FILE" +#define ENV_LOG_PRINT_META "PULSE_LOG_META" +#define ENV_LOG_PRINT_LEVEL "PULSE_LOG_LEVEL" +#define ENV_LOG_BACKTRACE "PULSE_LOG_BACKTRACE" + +static char *ident = NULL; /* in local charset format */ +static pa_log_target_t target = PA_LOG_STDERR, target_override; +static pa_bool_t target_override_set = FALSE; +static pa_log_level_t maximum_level = PA_LOG_ERROR, maximum_level_override = PA_LOG_ERROR; +static unsigned show_backtrace = 0, show_backtrace_override = 0; +static pa_log_flags_t flags = 0, flags_override = 0; #ifdef HAVE_SYSLOG_H static const int level_to_syslog[] = { @@ -83,12 +86,10 @@ static const char level_to_char[] = { }; void pa_log_set_ident(const char *p) { - pa_xfree(log_ident); - pa_xfree(log_ident_local); + pa_xfree(ident); - log_ident = pa_xstrdup(p); - if (!(log_ident_local = pa_utf8_to_locale(log_ident))) - log_ident_local = pa_xstrdup(log_ident); + if (!(ident = pa_utf8_to_locale(p))) + ident = pa_ascii_filter(p); } /* To make valgrind shut up. */ @@ -97,29 +98,30 @@ static void ident_destructor(void) { if (!pa_in_valgrind()) return; - pa_xfree(log_ident); - pa_xfree(log_ident_local); + pa_xfree(ident); } -void pa_log_set_maximal_level(pa_log_level_t l) { +void pa_log_set_level(pa_log_level_t l) { pa_assert(l < PA_LOG_LEVEL_MAX); - maximal_level = l; + maximum_level = l; } -void pa_log_set_target(pa_log_target_t t, pa_log_func_t func) { - pa_assert(t == PA_LOG_USER || !func); +void pa_log_set_target(pa_log_target_t t) { + pa_assert(t < PA_LOG_TARGET_MAX); - log_target = t; - user_log_func = func; + target = t; } -void pa_log_set_show_meta(pa_bool_t b) { - show_meta = b; -} +void pa_log_set_flags(pa_log_flags_t _flags, pa_log_merge_t merge) { + pa_assert(!(_flags & ~(PA_LOG_COLORS|PA_LOG_PRINT_TIME|PA_LOG_PRINT_FILE|PA_LOG_PRINT_META|PA_LOG_PRINT_LEVEL))); -void pa_log_set_show_time(pa_bool_t b) { - show_time = b; + if (merge == PA_LOG_SET) + flags |= _flags; + else if (merge == PA_LOG_UNSET) + flags &= ~_flags; + else + flags = _flags; } void pa_log_set_show_backtrace(unsigned nlevels) { @@ -135,8 +137,7 @@ static char* get_backtrace(unsigned show_nframes) { unsigned j, n; size_t a; - if (show_nframes <= 0) - return NULL; + pa_assert(show_nframes > 0); n_frames = backtrace(trace, PA_ELEMENTSOF(trace)); @@ -182,6 +183,50 @@ static char* get_backtrace(unsigned show_nframes) { #endif +static void init_defaults(void) { + const char *e; + + if (!ident) { + char binary[256]; + if (pa_get_binary_name(binary, sizeof(binary))) + pa_log_set_ident(binary); + } + + if (getenv(ENV_LOG_SYSLOG)) { + target_override = PA_LOG_SYSLOG; + target_override_set = TRUE; + } + + if ((e = getenv(ENV_LOG_LEVEL))) { + maximum_level_override = (pa_log_level_t) atoi(e); + + if (maximum_level_override >= PA_LOG_LEVEL_MAX) + maximum_level_override = PA_LOG_LEVEL_MAX-1; + } + + if (getenv(ENV_LOG_COLORS)) + flags_override |= PA_LOG_COLORS; + + if (getenv(ENV_LOG_PRINT_TIME)) + flags_override |= PA_LOG_PRINT_TIME; + + if (getenv(ENV_LOG_PRINT_FILE)) + flags_override |= PA_LOG_PRINT_FILE; + + if (getenv(ENV_LOG_PRINT_META)) + flags_override |= PA_LOG_PRINT_META; + + if (getenv(ENV_LOG_PRINT_LEVEL)) + flags_override |= PA_LOG_PRINT_LEVEL; + + if ((e = getenv(ENV_LOG_BACKTRACE))) { + show_backtrace_override = (unsigned) atoi(e); + + if (show_backtrace_override <= 0) + show_backtrace_override = 0; + } +} + void pa_log_levelv_meta( pa_log_level_t level, const char*file, @@ -190,14 +235,13 @@ void pa_log_levelv_meta( const char *format, va_list ap) { - const char *e; char *t, *n; int saved_errno = errno; char *bt = NULL; - pa_log_level_t ml; -#ifdef HAVE_EXECINFO_H - unsigned show_bt; -#endif + pa_log_target_t _target; + pa_log_level_t _maximum_level; + unsigned _show_backtrace; + pa_log_flags_t _flags; /* We don't use dynamic memory allocation here to minimize the hit * in RT threads */ @@ -206,30 +250,30 @@ void pa_log_levelv_meta( pa_assert(level < PA_LOG_LEVEL_MAX); pa_assert(format); - ml = maximal_level; - - if (PA_UNLIKELY((e = getenv(ENV_LOGLEVEL)))) { - pa_log_level_t eml = (pa_log_level_t) atoi(e); + PA_ONCE_BEGIN { + init_defaults(); + } PA_ONCE_END; - if (eml > ml) - ml = eml; - } + _target = target_override_set ? target_override : target; + _maximum_level = PA_MAX(maximum_level, maximum_level_override); + _show_backtrace = PA_MAX(show_backtrace, show_backtrace_override); + _flags = flags | flags_override; - if (PA_LIKELY(level > ml)) { + if (PA_LIKELY(level > _maximum_level)) { errno = saved_errno; return; } pa_vsnprintf(text, sizeof(text), format, ap); - if ((show_meta || getenv(ENV_LOGMETA)) && file && line > 0 && func) + if ((_flags & PA_LOG_PRINT_META) && file && line > 0 && func) pa_snprintf(location, sizeof(location), "[%s:%i %s()] ", file, line, func); - else if (file) + else if (_flags & (PA_LOG_PRINT_META|PA_LOG_PRINT_FILE)) pa_snprintf(location, sizeof(location), "%s: ", pa_path_get_filename(file)); else location[0] = 0; - if (show_time || getenv(ENV_LOGTIME)) { + if (_flags & PA_LOG_PRINT_TIME) { static pa_usec_t start, last; pa_usec_t u, a, r; @@ -257,16 +301,8 @@ void pa_log_levelv_meta( timestamp[0] = 0; #ifdef HAVE_EXECINFO_H - show_bt = show_backtrace; - - if ((e = getenv(ENV_LOGBACKTRACE))) { - unsigned ebt = (unsigned) atoi(e); - - if (ebt > show_bt) - show_bt = ebt; - } - - bt = get_backtrace(show_bt); + if (_show_backtrace > 0) + bt = get_backtrace(_show_backtrace); #endif if (!pa_utf8_valid(text)) @@ -282,14 +318,15 @@ void pa_log_levelv_meta( if (t[strspn(t, "\t ")] == 0) continue; - switch (log_target) { + switch (_target) { + case PA_LOG_STDERR: { const char *prefix = "", *suffix = "", *grey = ""; char *local_t; #ifndef OS_IS_WIN32 /* Yes indeed. Useless, but fun! */ - if (isatty(STDERR_FILENO)) { + if ((_flags & PA_LOG_COLORS) && isatty(STDERR_FILENO)) { if (level <= PA_LOG_ERROR) prefix = "\x1B[1;31m"; else if (level <= PA_LOG_WARN) @@ -305,13 +342,15 @@ void pa_log_levelv_meta( /* We shouldn't be using dynamic allocation here to * minimize the hit in RT threads */ - local_t = pa_utf8_to_locale(t); - if (!local_t) + if ((local_t = pa_utf8_to_locale(t))) + t = local_t; + + if (_flags & PA_LOG_PRINT_LEVEL) fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp, level_to_char[level], location, prefix, t, grey, pa_strempty(bt), suffix); - else { - fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp, level_to_char[level], location, prefix, local_t, grey, pa_strempty(bt), suffix); - pa_xfree(local_t); - } + else + fprintf(stderr, "%s%s%s%s%s%s%s\n", timestamp, location, prefix, t, grey, pa_strempty(bt), suffix); + + pa_xfree(local_t); break; } @@ -320,29 +359,17 @@ void pa_log_levelv_meta( case PA_LOG_SYSLOG: { char *local_t; - openlog(log_ident_local ? log_ident_local : "???", LOG_PID, LOG_USER); - - local_t = pa_utf8_to_locale(t); - if (!local_t) - syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, t, pa_strempty(bt)); - else { - syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, local_t, pa_strempty(bt)); - pa_xfree(local_t); - } - - closelog(); - break; - } -#endif + openlog(ident, LOG_PID, LOG_USER); - case PA_LOG_USER: { - char x[1024]; + if ((local_t = pa_utf8_to_locale(t))) + t = local_t; - pa_snprintf(x, sizeof(x), "%s%s%s", timestamp, location, t); - user_log_func(level, x); + syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, t, pa_strempty(bt)); + pa_xfree(local_t); break; } +#endif case PA_LOG_NULL: default: @@ -350,8 +377,8 @@ void pa_log_levelv_meta( } } - errno = saved_errno; pa_xfree(bt); + errno = saved_errno; } void pa_log_level_meta( diff --git a/src/pulsecore/log.h b/src/pulsecore/log.h index 77adb791..6e7bfc35 100644 --- a/src/pulsecore/log.h +++ b/src/pulsecore/log.h @@ -35,8 +35,8 @@ typedef enum pa_log_target { PA_LOG_STDERR, /* default */ PA_LOG_SYSLOG, - PA_LOG_USER, /* to user specified function */ - PA_LOG_NULL /* to /dev/null */ + PA_LOG_NULL, /* to /dev/null */ + PA_LOG_TARGET_MAX } pa_log_target_t; typedef enum pa_log_level { @@ -48,18 +48,33 @@ typedef enum pa_log_level { PA_LOG_LEVEL_MAX } pa_log_level_t; +typedef enum pa_log_flags { + PA_LOG_COLORS = 0x01, /* Show colorful output */ + PA_LOG_PRINT_TIME = 0x02, /* Show time */ + PA_LOG_PRINT_FILE = 0x04, /* Show source file */ + PA_LOG_PRINT_META = 0x08, /* Show extended locaton information */ + PA_LOG_PRINT_LEVEL = 0x10, /* Show log level prefix */ +} pa_log_flags_t; + +typedef enum pa_log_merge { + PA_LOG_SET, + PA_LOG_UNSET, + PA_LOG_RESET +} pa_log_merge_t; + /* Set an identification for the current daemon. Used when logging to syslog. */ void pa_log_set_ident(const char *p); -typedef void (*pa_log_func_t)(pa_log_level_t t, const char*s); - -/* Set another log target. If t is PA_LOG_USER you may specify a function that is called every log string */ -void pa_log_set_target(pa_log_target_t t, pa_log_func_t func); +/* Set a log target. */ +void pa_log_set_target(pa_log_target_t t); /* Maximal log level */ -void pa_log_set_maximal_level(pa_log_level_t l); -void pa_log_set_show_meta(pa_bool_t b); -void pa_log_set_show_time(pa_bool_t b); +void pa_log_set_level(pa_log_level_t l); + +/* Set flags */ +void pa_log_set_flags(pa_log_flags_t flags, pa_log_merge_t merge); + +/* Enable backtrace */ void pa_log_set_show_backtrace(unsigned nlevels); void pa_log_level_meta( @@ -68,6 +83,7 @@ void pa_log_level_meta( int line, const char *func, const char *format, ...) PA_GCC_PRINTF_ATTR(5,6); + void pa_log_levelv_meta( pa_log_level_t level, const char*file, @@ -76,8 +92,14 @@ void pa_log_levelv_meta( const char *format, va_list ap); -void pa_log_level(pa_log_level_t level, const char *format, ...) PA_GCC_PRINTF_ATTR(2,3); -void pa_log_levelv(pa_log_level_t level, const char *format, va_list ap); +void pa_log_level( + pa_log_level_t level, + const char *format, ...) PA_GCC_PRINTF_ATTR(2,3); + +void pa_log_levelv( + pa_log_level_t level, + const char *format, + va_list ap); #if __STDC_VERSION__ >= 199901L diff --git a/src/tests/envelope-test.c b/src/tests/envelope-test.c index 4a72f5a3..11a80a14 100644 --- a/src/tests/envelope-test.c +++ b/src/tests/envelope-test.c @@ -203,7 +203,7 @@ int main(int argc, char *argv[]) { }; oil_init(); - pa_log_set_maximal_level(PA_LOG_DEBUG); + pa_log_set_level(PA_LOG_DEBUG); pa_assert_se(pool = pa_mempool_new(FALSE, 0)); pa_assert_se(envelope = pa_envelope_new(&ss)); diff --git a/src/tests/memblockq-test.c b/src/tests/memblockq-test.c index c53945b4..b01a4fd5 100644 --- a/src/tests/memblockq-test.c +++ b/src/tests/memblockq-test.c @@ -61,7 +61,7 @@ int main(int argc, char *argv[]) { pa_memchunk chunk1, chunk2, chunk3, chunk4; pa_memchunk silence; - pa_log_set_maximal_level(PA_LOG_DEBUG); + pa_log_set_level(PA_LOG_DEBUG); p = pa_mempool_new(FALSE, 0); diff --git a/src/tests/mix-test.c b/src/tests/mix-test.c index cc21ab03..db8ac6e3 100644 --- a/src/tests/mix-test.c +++ b/src/tests/mix-test.c @@ -199,7 +199,7 @@ int main(int argc, char *argv[]) { pa_cvolume v; oil_init(); - pa_log_set_maximal_level(PA_LOG_DEBUG); + pa_log_set_level(PA_LOG_DEBUG); pa_assert_se(pool = pa_mempool_new(FALSE, 0)); diff --git a/src/tests/remix-test.c b/src/tests/remix-test.c index 3538d7d4..3da4ee33 100644 --- a/src/tests/remix-test.c +++ b/src/tests/remix-test.c @@ -56,7 +56,7 @@ int main(int argc, char *argv[]) { pa_mempool *pool; oil_init(); - pa_log_set_maximal_level(PA_LOG_DEBUG); + pa_log_set_level(PA_LOG_DEBUG); pa_assert_se(pool = pa_mempool_new(FALSE, 0)); diff --git a/src/tests/resampler-test.c b/src/tests/resampler-test.c index 2d591867..da8d3756 100644 --- a/src/tests/resampler-test.c +++ b/src/tests/resampler-test.c @@ -199,7 +199,7 @@ int main(int argc, char *argv[]) { pa_cvolume v; oil_init(); - pa_log_set_maximal_level(PA_LOG_DEBUG); + pa_log_set_level(PA_LOG_DEBUG); pa_assert_se(pool = pa_mempool_new(FALSE, 0)); -- cgit