Branch data Line data Source code
1 : : /***
2 : : This file is part of PulseAudio.
3 : :
4 : : Copyright 2004-2006 Lennart Poettering
5 : : Copyright 2006 Pierre Ossman <ossman@cendio.se> for Cendio AB
6 : :
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.
11 : :
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.
16 : :
17 : : You should have received a copy of the GNU Lesser General Public
18 : : License along with PulseAudio; if not, write to the Free Software
19 : : Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307
20 : : USA.
21 : : ***/
22 : :
23 : : #ifdef HAVE_CONFIG_H
24 : : #include <config.h>
25 : : #endif
26 : :
27 : : #include <stdarg.h>
28 : : #include <stdio.h>
29 : : #include <unistd.h>
30 : : #include <string.h>
31 : : #include <errno.h>
32 : :
33 : : #ifdef HAVE_EXECINFO_H
34 : : #include <execinfo.h>
35 : : #endif
36 : :
37 : : #ifdef HAVE_SYSLOG_H
38 : : #include <syslog.h>
39 : : #endif
40 : :
41 : : #include <pulse/gccmacro.h>
42 : : #include <pulse/rtclock.h>
43 : : #include <pulse/utf8.h>
44 : : #include <pulse/xmalloc.h>
45 : : #include <pulse/util.h>
46 : : #include <pulse/timeval.h>
47 : :
48 : : #include <pulsecore/macro.h>
49 : : #include <pulsecore/core-util.h>
50 : : #include <pulsecore/once.h>
51 : : #include <pulsecore/ratelimit.h>
52 : : #include <pulsecore/thread.h>
53 : :
54 : : #include "log.h"
55 : :
56 : : #define ENV_LOG_SYSLOG "PULSE_LOG_SYSLOG"
57 : : #define ENV_LOG_LEVEL "PULSE_LOG"
58 : : #define ENV_LOG_COLORS "PULSE_LOG_COLORS"
59 : : #define ENV_LOG_PRINT_TIME "PULSE_LOG_TIME"
60 : : #define ENV_LOG_PRINT_FILE "PULSE_LOG_FILE"
61 : : #define ENV_LOG_PRINT_META "PULSE_LOG_META"
62 : : #define ENV_LOG_PRINT_LEVEL "PULSE_LOG_LEVEL"
63 : : #define ENV_LOG_BACKTRACE "PULSE_LOG_BACKTRACE"
64 : : #define ENV_LOG_BACKTRACE_SKIP "PULSE_LOG_BACKTRACE_SKIP"
65 : : #define ENV_LOG_NO_RATELIMIT "PULSE_LOG_NO_RATE_LIMIT"
66 : :
67 : : static char *ident = NULL; /* in local charset format */
68 : : static pa_log_target_t target = PA_LOG_STDERR, target_override;
69 : : static pa_bool_t target_override_set = FALSE;
70 : : static pa_log_level_t maximum_level = PA_LOG_ERROR, maximum_level_override = PA_LOG_ERROR;
71 : : static unsigned show_backtrace = 0, show_backtrace_override = 0, skip_backtrace = 0;
72 : : static pa_log_flags_t flags = 0, flags_override = 0;
73 : : static pa_bool_t no_rate_limit = FALSE;
74 : : static int log_fd = -1;
75 : :
76 : : #ifdef HAVE_SYSLOG_H
77 : : static const int level_to_syslog[] = {
78 : : [PA_LOG_ERROR] = LOG_ERR,
79 : : [PA_LOG_WARN] = LOG_WARNING,
80 : : [PA_LOG_NOTICE] = LOG_NOTICE,
81 : : [PA_LOG_INFO] = LOG_INFO,
82 : : [PA_LOG_DEBUG] = LOG_DEBUG
83 : : };
84 : : #endif
85 : :
86 : : static const char level_to_char[] = {
87 : : [PA_LOG_ERROR] = 'E',
88 : : [PA_LOG_WARN] = 'W',
89 : : [PA_LOG_NOTICE] = 'N',
90 : : [PA_LOG_INFO] = 'I',
91 : : [PA_LOG_DEBUG] = 'D'
92 : : };
93 : :
94 : 18 : void pa_log_set_ident(const char *p) {
95 : 18 : pa_xfree(ident);
96 : :
97 [ - + ]: 18 : if (!(ident = pa_utf8_to_locale(p)))
98 : 0 : ident = pa_ascii_filter(p);
99 : 18 : }
100 : :
101 : : /* To make valgrind shut up. */
102 : : static void ident_destructor(void) PA_GCC_DESTRUCTOR;
103 : 27 : static void ident_destructor(void) {
104 [ - + ]: 27 : if (!pa_in_valgrind())
105 : 27 : return;
106 : :
107 : 0 : pa_xfree(ident);
108 : : }
109 : :
110 : 3 : void pa_log_set_level(pa_log_level_t l) {
111 [ - + ]: 3 : pa_assert(l < PA_LOG_LEVEL_MAX);
112 : :
113 : 3 : maximum_level = l;
114 : 3 : }
115 : :
116 : 0 : void pa_log_set_target(pa_log_target_t t) {
117 [ # # ]: 0 : pa_assert(t < PA_LOG_TARGET_MAX);
118 : :
119 : 0 : target = t;
120 : 0 : }
121 : :
122 : 0 : void pa_log_set_flags(pa_log_flags_t _flags, pa_log_merge_t merge) {
123 [ # # ]: 0 : pa_assert(!(_flags & ~(PA_LOG_COLORS|PA_LOG_PRINT_TIME|PA_LOG_PRINT_FILE|PA_LOG_PRINT_META|PA_LOG_PRINT_LEVEL)));
124 : :
125 [ # # ]: 0 : if (merge == PA_LOG_SET)
126 : 0 : flags |= _flags;
127 [ # # ]: 0 : else if (merge == PA_LOG_UNSET)
128 : 0 : flags &= ~_flags;
129 : : else
130 : 0 : flags = _flags;
131 : 0 : }
132 : :
133 : 0 : void pa_log_set_fd(int fd) {
134 [ # # ]: 0 : if (fd >= 0)
135 : 0 : log_fd = fd;
136 [ # # ]: 0 : else if (log_fd >= 0) {
137 : 0 : pa_close(log_fd);
138 : 0 : log_fd = -1;
139 : : }
140 : 0 : }
141 : :
142 : 0 : void pa_log_set_show_backtrace(unsigned nlevels) {
143 : 0 : show_backtrace = nlevels;
144 : 0 : }
145 : :
146 : 0 : void pa_log_set_skip_backtrace(unsigned nlevels) {
147 : 0 : skip_backtrace = nlevels;
148 : 0 : }
149 : :
150 : : #ifdef HAVE_EXECINFO_H
151 : :
152 : 0 : static char* get_backtrace(unsigned show_nframes) {
153 : : void* trace[32];
154 : : int n_frames;
155 : : char **symbols, *e, *r;
156 : : unsigned j, n, s;
157 : : size_t a;
158 : :
159 [ # # ]: 0 : pa_assert(show_nframes > 0);
160 : :
161 : 0 : n_frames = backtrace(trace, PA_ELEMENTSOF(trace));
162 : :
163 [ # # ]: 0 : if (n_frames <= 0)
164 : : return NULL;
165 : :
166 : 0 : symbols = backtrace_symbols(trace, n_frames);
167 : :
168 [ # # ]: 0 : if (!symbols)
169 : : return NULL;
170 : :
171 : 0 : s = skip_backtrace;
172 : 0 : n = PA_MIN((unsigned) n_frames, s + show_nframes);
173 : :
174 : 0 : a = 4;
175 : :
176 [ # # ]: 0 : for (j = s; j < n; j++) {
177 [ # # ]: 0 : if (j > s)
178 : 0 : a += 2;
179 : 0 : a += strlen(pa_path_get_filename(symbols[j]));
180 : : }
181 : :
182 : 0 : r = pa_xnew(char, a);
183 : :
184 : : strcpy(r, " (");
185 : 0 : e = r + 2;
186 : :
187 [ # # ]: 0 : for (j = s; j < n; j++) {
188 : : const char *sym;
189 : :
190 [ # # ]: 0 : if (j > s) {
191 : : strcpy(e, "<<");
192 : 0 : e += 2;
193 : : }
194 : :
195 : 0 : sym = pa_path_get_filename(symbols[j]);
196 : :
197 : : strcpy(e, sym);
198 : 0 : e += strlen(sym);
199 : : }
200 : :
201 : : strcpy(e, ")");
202 : :
203 : 0 : free(symbols);
204 : :
205 : 0 : return r;
206 : : }
207 : :
208 : : #endif
209 : :
210 : 89612 : static void init_defaults(void) {
211 [ + + ]: 89612 : PA_ONCE_BEGIN {
212 : :
213 : : const char *e;
214 : :
215 [ + - ]: 18 : if (!ident) {
216 : : char binary[256];
217 [ + - ]: 18 : if (pa_get_binary_name(binary, sizeof(binary)))
218 : 18 : pa_log_set_ident(binary);
219 : : }
220 : :
221 [ - + ]: 18 : if (getenv(ENV_LOG_SYSLOG)) {
222 : 0 : target_override = PA_LOG_SYSLOG;
223 : 0 : target_override_set = TRUE;
224 : : }
225 : :
226 [ - + ]: 18 : if ((e = getenv(ENV_LOG_LEVEL))) {
227 : 0 : maximum_level_override = (pa_log_level_t) atoi(e);
228 : :
229 [ # # ]: 0 : if (maximum_level_override >= PA_LOG_LEVEL_MAX)
230 : 0 : maximum_level_override = PA_LOG_LEVEL_MAX-1;
231 : : }
232 : :
233 [ - + ]: 18 : if (getenv(ENV_LOG_COLORS))
234 : 0 : flags_override |= PA_LOG_COLORS;
235 : :
236 [ - + ]: 18 : if (getenv(ENV_LOG_PRINT_TIME))
237 : 0 : flags_override |= PA_LOG_PRINT_TIME;
238 : :
239 [ - + ]: 18 : if (getenv(ENV_LOG_PRINT_FILE))
240 : 0 : flags_override |= PA_LOG_PRINT_FILE;
241 : :
242 [ - + ]: 18 : if (getenv(ENV_LOG_PRINT_META))
243 : 0 : flags_override |= PA_LOG_PRINT_META;
244 : :
245 [ - + ]: 18 : if (getenv(ENV_LOG_PRINT_LEVEL))
246 : 0 : flags_override |= PA_LOG_PRINT_LEVEL;
247 : :
248 [ - + ]: 18 : if ((e = getenv(ENV_LOG_BACKTRACE))) {
249 : 0 : show_backtrace_override = (unsigned) atoi(e);
250 : :
251 [ # # ]: 0 : if (show_backtrace_override <= 0)
252 : 0 : show_backtrace_override = 0;
253 : : }
254 : :
255 [ - + ]: 18 : if ((e = getenv(ENV_LOG_BACKTRACE_SKIP))) {
256 : 0 : skip_backtrace = (unsigned) atoi(e);
257 : :
258 [ # # ]: 0 : if (skip_backtrace <= 0)
259 : 0 : skip_backtrace = 0;
260 : : }
261 : :
262 [ - + ]: 18 : if (getenv(ENV_LOG_NO_RATELIMIT))
263 : 0 : no_rate_limit = TRUE;
264 : :
265 : 18 : } PA_ONCE_END;
266 : 89606 : }
267 : :
268 : 89593 : void pa_log_levelv_meta(
269 : : pa_log_level_t level,
270 : : const char*file,
271 : : int line,
272 : : const char *func,
273 : : const char *format,
274 : : va_list ap) {
275 : :
276 : : char *t, *n;
277 : 89593 : int saved_errno = errno;
278 : 89614 : char *bt = NULL;
279 : : pa_log_target_t _target;
280 : : pa_log_level_t _maximum_level;
281 : : unsigned _show_backtrace;
282 : : pa_log_flags_t _flags;
283 : :
284 : : /* We don't use dynamic memory allocation here to minimize the hit
285 : : * in RT threads */
286 : : char text[16*1024], location[128], timestamp[32];
287 : :
288 [ - + ]: 89614 : pa_assert(level < PA_LOG_LEVEL_MAX);
289 [ - + ]: 89614 : pa_assert(format);
290 : :
291 : 89614 : init_defaults();
292 : :
293 [ + + ]: 89615 : _target = target_override_set ? target_override : target;
294 : 89615 : _maximum_level = PA_MAX(maximum_level, maximum_level_override);
295 : 89615 : _show_backtrace = PA_MAX(show_backtrace, show_backtrace_override);
296 : 89615 : _flags = flags | flags_override;
297 : :
298 [ + + ]: 89615 : if (PA_LIKELY(level > _maximum_level)) {
299 : 89546 : errno = saved_errno;
300 : 89617 : return;
301 : : }
302 : :
303 : 69 : pa_vsnprintf(text, sizeof(text), format, ap);
304 : :
305 [ - + ][ # # ]: 70 : if ((_flags & PA_LOG_PRINT_META) && file && line > 0 && func)
306 : 0 : pa_snprintf(location, sizeof(location), "[%s][%s:%i %s()] ", pa_thread_get_name(pa_thread_self()), file, line, func);
307 [ - + ]: 70 : else if ((_flags & (PA_LOG_PRINT_META|PA_LOG_PRINT_FILE)) && file)
308 : 0 : pa_snprintf(location, sizeof(location), "[%s] %s: ", pa_thread_get_name(pa_thread_self()), pa_path_get_filename(file));
309 : : else
310 : 70 : location[0] = 0;
311 : :
312 [ - + ]: 70 : if (_flags & PA_LOG_PRINT_TIME) {
313 : : static pa_usec_t start, last;
314 : : pa_usec_t u, a, r;
315 : :
316 : 0 : u = pa_rtclock_now();
317 : :
318 [ # # ]: 0 : PA_ONCE_BEGIN {
319 : 0 : start = u;
320 : 0 : last = u;
321 : 0 : } PA_ONCE_END;
322 : :
323 : 0 : r = u - last;
324 : 0 : a = u - start;
325 : :
326 : : /* This is not thread safe, but this is a debugging tool only
327 : : * anyway. */
328 : 0 : last = u;
329 : :
330 : 0 : pa_snprintf(timestamp, sizeof(timestamp), "(%4llu.%03llu|%4llu.%03llu) ",
331 : 0 : (unsigned long long) (a / PA_USEC_PER_SEC),
332 : 0 : (unsigned long long) (((a / PA_USEC_PER_MSEC)) % 1000),
333 : 0 : (unsigned long long) (r / PA_USEC_PER_SEC),
334 : 0 : (unsigned long long) (((r / PA_USEC_PER_MSEC)) % 1000));
335 : :
336 : : } else
337 : 70 : timestamp[0] = 0;
338 : :
339 : : #ifdef HAVE_EXECINFO_H
340 [ - + ]: 70 : if (_show_backtrace > 0)
341 : 0 : bt = get_backtrace(_show_backtrace);
342 : : #endif
343 : :
344 [ - + ]: 70 : if (!pa_utf8_valid(text))
345 : 69 : pa_logl(level, "Invalid UTF-8 string following below:");
346 : :
347 [ + + ]: 144 : for (t = text; t; t = n) {
348 [ + + ]: 74 : if ((n = strchr(t, '\n'))) {
349 : 5 : *n = 0;
350 : 5 : n++;
351 : : }
352 : :
353 : : /* We ignore strings only made out of whitespace */
354 [ + ][ - + ]: 149 : if (t[strspn(t, "\t ")] == 0)
[ + - ][ # # ]
[ + + ]
355 : 5 : continue;
356 : :
357 [ + - - - ]: 69 : switch (_target) {
358 : :
359 : : case PA_LOG_STDERR: {
360 : 69 : const char *prefix = "", *suffix = "", *grey = "";
361 : : char *local_t;
362 : :
363 : : #ifndef OS_IS_WIN32
364 : : /* Yes indeed. Useless, but fun! */
365 [ - + ][ # # ]: 69 : if ((_flags & PA_LOG_COLORS) && isatty(STDERR_FILENO)) {
366 [ # # ]: 0 : if (level <= PA_LOG_ERROR)
367 : : prefix = "\x1B[1;31m";
368 [ # # ]: 0 : else if (level <= PA_LOG_WARN)
369 : 0 : prefix = "\x1B[1m";
370 : :
371 [ # # ]: 0 : if (bt)
372 : 0 : grey = "\x1B[2m";
373 : :
374 [ # # ][ # # ]: 0 : if (grey[0] || prefix[0])
375 : 0 : suffix = "\x1B[0m";
376 : : }
377 : : #endif
378 : :
379 : : /* We shouldn't be using dynamic allocation here to
380 : : * minimize the hit in RT threads */
381 [ + - ]: 69 : if ((local_t = pa_utf8_to_locale(t)))
382 : 70 : t = local_t;
383 : :
384 [ - + ]: 70 : if (_flags & PA_LOG_PRINT_LEVEL)
385 : 0 : fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp, level_to_char[level], location, prefix, t, grey, pa_strempty(bt), suffix);
386 : : else
387 : 70 : fprintf(stderr, "%s%s%s%s%s%s%s\n", timestamp, location, prefix, t, grey, pa_strempty(bt), suffix);
388 : : #ifdef OS_IS_WIN32
389 : : fflush(stderr);
390 : : #endif
391 : :
392 : 70 : pa_xfree(local_t);
393 : :
394 : 70 : break;
395 : : }
396 : :
397 : : #ifdef HAVE_SYSLOG_H
398 : : case PA_LOG_SYSLOG: {
399 : : char *local_t;
400 : :
401 : 0 : openlog(ident, LOG_PID, LOG_USER);
402 : :
403 [ # # ]: 0 : if ((local_t = pa_utf8_to_locale(t)))
404 : 0 : t = local_t;
405 : :
406 : 0 : syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, t, pa_strempty(bt));
407 : 0 : pa_xfree(local_t);
408 : :
409 : 0 : break;
410 : : }
411 : : #endif
412 : :
413 : : case PA_LOG_FD: {
414 [ # # ]: 0 : if (log_fd >= 0) {
415 : : char metadata[256];
416 : :
417 : 0 : pa_snprintf(metadata, sizeof(metadata), "\n%c %s %s", level_to_char[level], timestamp, location);
418 : :
419 [ # # ][ # # ]: 0 : if ((write(log_fd, metadata, strlen(metadata)) < 0) || (write(log_fd, t, strlen(t)) < 0)) {
420 : 0 : saved_errno = errno;
421 : 0 : pa_log_set_fd(-1);
422 : 0 : fprintf(stderr, "%s\n", "Error writing logs to a file descriptor. Redirect log messages to console.");
423 : 0 : fprintf(stderr, "%s %s\n", metadata, t);
424 : 0 : pa_log_set_target(PA_LOG_STDERR);
425 : : }
426 : : }
427 : :
428 : : break;
429 : : }
430 : : case PA_LOG_NULL:
431 : : default:
432 : : break;
433 : : }
434 : : }
435 : :
436 : 70 : pa_xfree(bt);
437 : 70 : errno = saved_errno;
438 : : }
439 : :
440 : 89594 : void pa_log_level_meta(
441 : : pa_log_level_t level,
442 : : const char*file,
443 : : int line,
444 : : const char *func,
445 : : const char *format, ...) {
446 : :
447 : : va_list ap;
448 : 89594 : va_start(ap, format);
449 : 89594 : pa_log_levelv_meta(level, file, line, func, format, ap);
450 : 89609 : va_end(ap);
451 : 89609 : }
452 : :
453 : 0 : void pa_log_levelv(pa_log_level_t level, const char *format, va_list ap) {
454 : 0 : pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
455 : 0 : }
456 : :
457 : 0 : void pa_log_level(pa_log_level_t level, const char *format, ...) {
458 : : va_list ap;
459 : :
460 : 0 : va_start(ap, format);
461 : 0 : pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
462 : 0 : va_end(ap);
463 : 0 : }
464 : :
465 : 0 : pa_bool_t pa_log_ratelimit(pa_log_level_t level) {
466 : : /* Not more than 10 messages every 5s */
467 : : static PA_DEFINE_RATELIMIT(ratelimit, 5 * PA_USEC_PER_SEC, 10);
468 : :
469 : 0 : init_defaults();
470 : :
471 [ # # ]: 0 : if (no_rate_limit)
472 : : return TRUE;
473 : :
474 : 0 : return pa_ratelimit_test(&ratelimit, level);
475 : : }
|
