2 This file is part of PulseAudio.
4 Copyright 2004-2006 Lennart Poettering
5 Copyright 2006 Pierre Ossman <ossman@cendio.se> for Cendio AB
7 PulseAudio is free software; you can redistribute it and/or modify
8 it under the terms of the GNU Lesser General Public License as
9 published by the Free Software Foundation; either version 2.1 of the
10 License, or (at your option) any later version.
12 PulseAudio is distributed in the hope that it will be useful, but
13 WITHOUT ANY WARRANTY; without even the implied warranty of
14 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
15 General Public License for more details.
17 You should have received a copy of the GNU Lesser General Public
18 License along with PulseAudio; if not, see <http://www.gnu.org/licenses/>.
33 #ifdef HAVE_EXECINFO_H
41 #ifdef HAVE_SYSTEMD_JOURNAL
43 /* sd_journal_send() implicitly add fields for the source file,
44 * function name and code line from where it's invoked. As the
45 * correct code location fields CODE_FILE, CODE_LINE and
46 * CODE_FUNC are already handled by this module, we do not want
47 * the automatic values supplied by the systemd journal API.
49 * Without suppressing these, both the actual log event source
50 * and the call to sd_journal_send() will be logged. */
51 #define SD_JOURNAL_SUPPRESS_LOCATION
53 #include <systemd/sd-journal.h>
56 #include <pulse/gccmacro.h>
57 #include <pulse/rtclock.h>
58 #include <pulse/utf8.h>
59 #include <pulse/xmalloc.h>
60 #include <pulse/util.h>
61 #include <pulse/timeval.h>
63 #include <pulsecore/macro.h>
64 #include <pulsecore/core-util.h>
65 #include <pulsecore/core-error.h>
66 #include <pulsecore/once.h>
67 #include <pulsecore/ratelimit.h>
68 #include <pulsecore/thread.h>
69 #include <pulsecore/i18n.h>
75 #define DLOG_TAG "PULSEAUDIO"
77 #define COLOR_BLACK 30
79 #define COLOR_GREEN 32
81 #define COLOR_MAGENTA 35
83 #define COLOR_WHITE 97
84 #define COLOR_B_GRAY 100
85 #define COLOR_B_RED 101
86 #define COLOR_B_GREEN 102
87 #define COLOR_B_YELLOW 103
88 #define COLOR_B_BLUE 104
89 #define COLOR_B_MAGENTA 105
90 #define COLOR_B_CYAN 106
91 #define COLOR_REVERSE 7
94 #define ENV_LOG_SYSLOG "PULSE_LOG_SYSLOG"
95 #define ENV_LOG_JOURNAL "PULSE_LOG_JOURNAL"
96 #define ENV_LOG_LEVEL "PULSE_LOG"
97 #define ENV_LOG_COLORS "PULSE_LOG_COLORS"
98 #define ENV_LOG_PRINT_TIME "PULSE_LOG_TIME"
99 #define ENV_LOG_PRINT_FILE "PULSE_LOG_FILE"
100 #define ENV_LOG_PRINT_META "PULSE_LOG_META"
101 #define ENV_LOG_PRINT_LEVEL "PULSE_LOG_LEVEL"
102 #define ENV_LOG_BACKTRACE "PULSE_LOG_BACKTRACE"
103 #define ENV_LOG_BACKTRACE_SKIP "PULSE_LOG_BACKTRACE_SKIP"
104 #define ENV_LOG_NO_RATELIMIT "PULSE_LOG_NO_RATE_LIMIT"
105 #define LOG_MAX_SUFFIX_NUMBER 99
108 #define ENV_LOG_DLOG_CLIENT "PULSE_LOG_DLOG_CLIENT"
109 #define DAEMON_BINARY_NAME "pulseaudio"
112 static char *ident = NULL; /* in local charset format */
113 static pa_log_target target = { PA_LOG_STDERR, NULL };
114 static pa_log_target_type_t target_override;
115 static bool target_override_set = false;
116 static pa_log_level_t maximum_level = PA_LOG_ERROR, maximum_level_override = PA_LOG_ERROR;
117 static unsigned show_backtrace = 0, show_backtrace_override = 0, skip_backtrace = 0;
118 static pa_log_flags_t flags = 0, flags_override = 0;
119 static bool no_rate_limit = false;
120 static int log_fd = -1;
121 static int write_type = 0;
124 static const int level_to_syslog[] = {
125 [PA_LOG_ERROR] = LOG_ERR,
126 [PA_LOG_WARN] = LOG_WARNING,
127 [PA_LOG_NOTICE] = LOG_NOTICE,
128 [PA_LOG_INFO] = LOG_INFO,
129 [PA_LOG_DEBUG] = LOG_DEBUG
133 /* These are actually equivalent to the syslog ones
134 * but we don't want to depend on syslog.h */
135 #ifdef HAVE_SYSTEMD_JOURNAL
136 static const int level_to_journal[] = {
145 static const char level_to_char[] = {
146 [PA_LOG_ERROR] = 'E',
148 [PA_LOG_NOTICE] = 'N',
153 void pa_log_set_ident(const char *p) {
156 if (!(ident = pa_utf8_to_locale(p)))
157 ident = pa_ascii_filter(p);
160 /* To make valgrind shut up. */
161 static void ident_destructor(void) PA_GCC_DESTRUCTOR;
162 static void ident_destructor(void) {
163 if (!pa_in_valgrind())
169 void pa_log_set_level(pa_log_level_t l) {
170 pa_assert(l < PA_LOG_LEVEL_MAX);
175 int pa_log_set_target(pa_log_target *t) {
184 #ifdef HAVE_SYSTEMD_JOURNAL
189 case PA_LOG_DLOG_COLOR:
194 if ((fd = pa_open_cloexec(t->file, O_WRONLY | O_TRUNC | O_CREAT, S_IRUSR | S_IWUSR)) < 0) {
195 pa_log(_("Failed to open target file '%s'."), t->file);
199 case PA_LOG_NEWFILE: {
204 file_path = pa_sprintf_malloc("%s.xx", t->file);
205 p = file_path + strlen(t->file);
207 for (version = 0; version <= LOG_MAX_SUFFIX_NUMBER; version++) {
208 memset(p, 0, 3); /* Overwrite the ".xx" part in file_path with zero bytes. */
211 pa_snprintf(p, 4, ".%u", version); /* Why 4? ".xx" + termitating zero byte. */
213 if ((fd = pa_open_cloexec(file_path, O_WRONLY | O_TRUNC | O_CREAT | O_EXCL, S_IRUSR | S_IWUSR)) >= 0)
217 if (version > LOG_MAX_SUFFIX_NUMBER) {
218 pa_log(_("Tried to open target file '%s', '%s.1', '%s.2' ... '%s.%d', but all failed."),
219 t->file, t->file, t->file, t->file, LOG_MAX_SUFFIX_NUMBER);
223 pa_log_debug("Opened target file %s\n", file_path);
230 target.type = t->type;
231 pa_xfree(target.file);
232 target.file = pa_xstrdup(t->file);
243 void pa_log_set_flags(pa_log_flags_t _flags, pa_log_merge_t merge) {
244 pa_assert(!(_flags & ~(PA_LOG_COLORS|PA_LOG_PRINT_TIME|PA_LOG_PRINT_FILE|PA_LOG_PRINT_META|PA_LOG_PRINT_LEVEL)));
246 if (merge == PA_LOG_SET)
248 else if (merge == PA_LOG_UNSET)
254 void pa_log_set_show_backtrace(unsigned nlevels) {
255 show_backtrace = nlevels;
258 void pa_log_set_skip_backtrace(unsigned nlevels) {
259 skip_backtrace = nlevels;
262 #ifdef HAVE_EXECINFO_H
264 static char* get_backtrace(unsigned show_nframes) {
267 char **symbols, *e, *r;
271 pa_assert(show_nframes > 0);
273 n_frames = backtrace(trace, PA_ELEMENTSOF(trace));
278 symbols = backtrace_symbols(trace, n_frames);
284 n = PA_MIN((unsigned) n_frames, s + show_nframes);
288 for (j = s; j < n; j++) {
291 a += strlen(pa_path_get_filename(symbols[j]));
294 r = pa_xnew(char, a);
299 for (j = s; j < n; j++) {
307 sym = pa_path_get_filename(symbols[j]);
322 static void init_defaults(void) {
327 char binary[256] = {0, };
334 if (pa_get_binary_name(binary, sizeof(binary)))
335 pa_log_set_ident(binary);
338 if (getenv(ENV_LOG_SYSLOG)) {
339 target_override = PA_LOG_SYSLOG;
340 target_override_set = true;
343 #ifdef HAVE_SYSTEMD_JOURNAL
344 if (getenv(ENV_LOG_JOURNAL)) {
345 target_override = PA_LOG_JOURNAL;
346 target_override_set = true;
350 if ((e = getenv(ENV_LOG_LEVEL))) {
351 maximum_level_override = (pa_log_level_t) atoi(e);
353 if (maximum_level_override >= PA_LOG_LEVEL_MAX)
354 maximum_level_override = PA_LOG_LEVEL_MAX-1;
358 if (strnlen(binary, sizeof(binary)) > 0 &&
359 !pa_safe_streq(binary, DAEMON_BINARY_NAME)) {
360 target_override = PA_LOG_DLOG;
361 target_override_set = true;
362 maximum_level_override = PA_LOG_INFO;
364 if ((e = getenv(ENV_LOG_DLOG_CLIENT))) {
365 target_override = PA_LOG_DLOG;
366 target_override_set = true;
367 maximum_level_override = atoi(e);
371 if (getenv(ENV_LOG_COLORS))
372 flags_override |= PA_LOG_COLORS;
374 if (getenv(ENV_LOG_PRINT_TIME))
375 flags_override |= PA_LOG_PRINT_TIME;
377 if (getenv(ENV_LOG_PRINT_FILE))
378 flags_override |= PA_LOG_PRINT_FILE;
380 if (getenv(ENV_LOG_PRINT_META))
381 flags_override |= PA_LOG_PRINT_META;
383 if (getenv(ENV_LOG_PRINT_LEVEL))
384 flags_override |= PA_LOG_PRINT_LEVEL;
386 if ((e = getenv(ENV_LOG_BACKTRACE))) {
387 show_backtrace_override = (unsigned) atoi(e);
389 if (show_backtrace_override <= 0)
390 show_backtrace_override = 0;
393 if ((e = getenv(ENV_LOG_BACKTRACE_SKIP))) {
394 skip_backtrace = (unsigned) atoi(e);
396 if (skip_backtrace <= 0)
400 if (getenv(ENV_LOG_NO_RATELIMIT))
401 no_rate_limit = true;
407 static void log_syslog(pa_log_level_t level, char *t, char *timestamp, char *location, char *bt) {
410 openlog(ident, LOG_PID, LOG_USER);
412 if ((local_t = pa_utf8_to_locale(t)))
415 syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, t, pa_strempty(bt));
420 void pa_log_levelv_meta(
421 pa_log_level_t level,
429 int saved_errno = errno;
431 pa_log_target_type_t _target;
432 pa_log_level_t _maximum_level;
433 unsigned _show_backtrace;
434 pa_log_flags_t _flags;
436 /* We don't use dynamic memory allocation here to minimize the hit
438 char text[16*1024], location[128], timestamp[32];
440 pa_assert(level < PA_LOG_LEVEL_MAX);
445 _target = target_override_set ? target_override : target.type;
446 _maximum_level = PA_MAX(maximum_level, maximum_level_override);
447 _show_backtrace = PA_MAX(show_backtrace, show_backtrace_override);
448 _flags = flags | flags_override;
450 if (PA_LIKELY(level > _maximum_level)) {
455 pa_vsnprintf(text, sizeof(text), format, ap);
458 if ((_target == PA_LOG_DLOG) && file && line > 0 && func)
459 pa_snprintf(location, sizeof(location), "%s: %s(%i) > ",
460 pa_path_get_filename(file), func, line);
463 if ((_flags & PA_LOG_PRINT_META) && file && line > 0 && func)
464 pa_snprintf(location, sizeof(location), "[%s][%s:%i %s()] ",
465 pa_strnull(pa_thread_get_name(pa_thread_self())), file, line, func);
466 else if ((_flags & (PA_LOG_PRINT_META|PA_LOG_PRINT_FILE)) && file)
467 pa_snprintf(location, sizeof(location), "[%s] %s: ",
468 pa_strnull(pa_thread_get_name(pa_thread_self())), pa_path_get_filename(file));
472 if (_flags & PA_LOG_PRINT_TIME) {
473 static pa_usec_t start, last;
476 u = pa_rtclock_now();
486 /* This is not thread safe, but this is a debugging tool only
490 pa_snprintf(timestamp, sizeof(timestamp), "(%4llu.%03llu|%4llu.%03llu) ",
491 (unsigned long long) (a / PA_USEC_PER_SEC),
492 (unsigned long long) (((a / PA_USEC_PER_MSEC)) % 1000),
493 (unsigned long long) (r / PA_USEC_PER_SEC),
494 (unsigned long long) (((r / PA_USEC_PER_MSEC)) % 1000));
499 #ifdef HAVE_EXECINFO_H
500 if (_show_backtrace > 0)
501 bt = get_backtrace(_show_backtrace);
504 if (!pa_utf8_valid(text))
505 pa_logl(level, "Invalid UTF-8 string following below:");
507 for (t = text; t; t = n) {
508 if ((n = strchr(t, '\n'))) {
513 /* We ignore strings only made out of whitespace */
514 if (t[strspn(t, "\t ")] == 0)
519 case PA_LOG_STDERR: {
520 const char *prefix = "", *suffix = "", *grey = "";
524 /* Yes indeed. Useless, but fun! */
525 if ((_flags & PA_LOG_COLORS) && isatty(STDERR_FILENO)) {
526 if (level <= PA_LOG_ERROR)
527 prefix = "\x1B[1;31m";
528 else if (level <= PA_LOG_WARN)
534 if (grey[0] || prefix[0])
539 /* We shouldn't be using dynamic allocation here to
540 * minimize the hit in RT threads */
541 if ((local_t = pa_utf8_to_locale(t)))
544 if (_flags & PA_LOG_PRINT_LEVEL)
545 fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp, level_to_char[level], location, prefix, t, grey, pa_strempty(bt), suffix);
547 fprintf(stderr, "%s%s%s%s%s%s%s\n", timestamp, location, prefix, t, grey, pa_strempty(bt), suffix);
559 log_syslog(level, t, timestamp, location, bt);
563 #ifdef HAVE_SYSTEMD_JOURNAL
565 if (sd_journal_send("MESSAGE=%s", t,
566 "PRIORITY=%i", level_to_journal[level],
567 "CODE_FILE=%s", file,
568 "CODE_FUNC=%s", func,
569 "CODE_LINE=%d", line,
570 "PULSE_BACKTRACE=%s", pa_strempty(bt),
573 pa_log_target new_target = { .type = PA_LOG_SYSLOG, .file = NULL };
575 syslog(level_to_syslog[PA_LOG_ERROR], "%s%s%s", timestamp, __FILE__,
576 "Error writing logs to the journal. Redirect log messages to syslog.");
577 log_syslog(level, t, timestamp, location, bt);
579 pa_log_target new_target = { .type = PA_LOG_STDERR, .file = NULL };
582 fprintf(stderr, "%s\n", "Error writing logs to the journal. Redirect log messages to console.");
583 fprintf(stderr, "%s\n", t);
585 pa_log_set_target(&new_target);
591 case PA_LOG_NEWFILE: {
594 if ((local_t = pa_utf8_to_locale(t)))
600 if (_flags & PA_LOG_PRINT_LEVEL)
601 pa_snprintf(metadata, sizeof(metadata), "%s%c: %s", timestamp, level_to_char[level], location);
603 pa_snprintf(metadata, sizeof(metadata), "%s%s", timestamp, location);
605 if ((pa_write(log_fd, metadata, strlen(metadata), &write_type) < 0)
606 || (pa_write(log_fd, t, strlen(t), &write_type) < 0)
607 || (bt && pa_write(log_fd, bt, strlen(bt), &write_type) < 0)
608 || (pa_write(log_fd, "\n", 1, &write_type) < 0)) {
609 pa_log_target new_target = { .type = PA_LOG_STDERR, .file = NULL };
611 fprintf(stderr, "%s\n", "Error writing logs to a file descriptor. Redirect log messages to console.");
612 fprintf(stderr, "%s %s\n", metadata, t);
613 pa_log_set_target(&new_target);
626 openlog(ident, LOG_PID, LOG_USER);
628 if ((local_t = pa_utf8_to_locale(t)))
633 print_system_log(DLOG_DEBUG, DLOG_TAG, "%s%s%s%s", location, timestamp, t, pa_strempty(bt));
636 case PA_LOG_NOTICE: /* no notice category in dlog, use info instead */
637 print_system_log(DLOG_INFO, DLOG_TAG, "%s%s%s%s", location, timestamp, t, pa_strempty(bt));
640 print_system_log(DLOG_WARN, DLOG_TAG, "%s%s%s%s", location, timestamp, t, pa_strempty(bt));
643 print_system_log(DLOG_ERROR, DLOG_TAG, "%s%s%s%s", location, timestamp, t, pa_strempty(bt));
646 print_system_log(DLOG_DEBUG, DLOG_TAG, "%s%s%s%s", location, timestamp, t, pa_strempty(bt));
654 case PA_LOG_DLOG_COLOR: {
657 openlog(ident, LOG_PID, LOG_USER);
659 if ((local_t = pa_utf8_to_locale(t)))
664 print_system_log(DLOG_DEBUG, DLOG_TAG, "\033[%dm%s%s%s%s\033[0m", COLOR_GREEN, location, timestamp, t, pa_strempty(bt));
667 case PA_LOG_NOTICE: /* no notice category in dlog, use info instead */
668 print_system_log(DLOG_INFO, DLOG_TAG, "\033[%dm%s%s%s%s\033[0m", COLOR_BLUE, location, timestamp, t, pa_strempty(bt));
671 print_system_log(DLOG_WARN, DLOG_TAG, "\033[%dm%s%s%s%s\033[0m", COLOR_MAGENTA, location, timestamp, t, pa_strempty(bt));
674 print_system_log(DLOG_ERROR, DLOG_TAG, "\033[%dm%s%s%s%s\033[0m", COLOR_RED, location, timestamp, t, pa_strempty(bt));
677 print_system_log(DLOG_DEBUG, DLOG_TAG, "\033[%dm%s%s%s%s\033[0m", COLOR_GREEN, location, timestamp, t, pa_strempty(bt));
697 void pa_log_level_meta(
698 pa_log_level_t level,
702 const char *format, ...) {
705 va_start(ap, format);
706 pa_log_levelv_meta(level, file, line, func, format, ap);
710 void pa_log_levelv(pa_log_level_t level, const char *format, va_list ap) {
711 pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
714 void pa_log_level(pa_log_level_t level, const char *format, ...) {
717 va_start(ap, format);
718 pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
722 bool pa_log_ratelimit(pa_log_level_t level) {
723 /* Not more than 10 messages every 5s */
724 static PA_DEFINE_RATELIMIT(ratelimit, 5 * PA_USEC_PER_SEC, 10);
731 return pa_ratelimit_test(&ratelimit, level);
734 pa_log_target *pa_log_target_new(pa_log_target_type_t type, const char *file) {
735 pa_log_target *t = NULL;
737 t = pa_xnew(pa_log_target, 1);
740 t->file = pa_xstrdup(file);
745 void pa_log_target_free(pa_log_target *t) {
752 pa_log_target *pa_log_parse_target(const char *string) {
753 pa_log_target *t = NULL;
757 if (pa_streq(string, "stderr"))
758 t = pa_log_target_new(PA_LOG_STDERR, NULL);
759 else if (pa_streq(string, "syslog"))
760 t = pa_log_target_new(PA_LOG_SYSLOG, NULL);
761 #ifdef HAVE_SYSTEMD_JOURNAL
762 else if (pa_streq(string, "journal"))
763 t = pa_log_target_new(PA_LOG_JOURNAL, NULL);
765 else if (pa_streq(string, "null"))
766 t = pa_log_target_new(PA_LOG_NULL, NULL);
767 else if (pa_startswith(string, "file:"))
768 t = pa_log_target_new(PA_LOG_FILE, string + 5);
769 else if (pa_startswith(string, "newfile:"))
770 t = pa_log_target_new(PA_LOG_NEWFILE, string + 8);
772 else if (pa_streq(string, "dlog"))
773 t = pa_log_target_new(PA_LOG_DLOG, NULL);
774 else if (pa_streq(string, "dlog-color"))
775 t = pa_log_target_new(PA_LOG_DLOG_COLOR, NULL);
778 pa_log(_("Invalid log target."));
783 char *pa_log_target_to_string(const pa_log_target *t) {
790 string = pa_xstrdup("stderr");
793 string = pa_xstrdup("syslog");
795 #ifdef HAVE_SYSTEMD_JOURNAL
797 string = pa_xstrdup("journal");
802 string = pa_xstrdup("dlog");
804 case PA_LOG_DLOG_COLOR:
805 string = pa_xstrdup("dlog-color");
809 string = pa_xstrdup("null");
812 string = pa_sprintf_malloc("file:%s", t->file);
815 string = pa_sprintf_malloc("newfile:%s", t->file);