code.delx.au - pulseaudio/blob - src/pulsecore/log.c

   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 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/utf8.h>
  42 #include <pulse/xmalloc.h>
  43 #include <pulse/util.h>
  44 #include <pulse/timeval.h>
  45
  46 #include <pulsecore/macro.h>
  47 #include <pulsecore/core-util.h>
  48 #include <pulsecore/rtclock.h>
  49 #include <pulsecore/once.h>
  50 #include <pulsecore/ratelimit.h>
  51
  52 #include "log.h"
  53
  54 #define ENV_LOGLEVEL "PULSE_LOG"
  55 #define ENV_LOGMETA "PULSE_LOG_META"
  56 #define ENV_LOGTIME "PULSE_LOG_TIME"
  57 #define ENV_LOGBACKTRACE "PULSE_LOG_BACKTRACE"
  58
  59 static char *log_ident = NULL, *log_ident_local = NULL;
  60 static pa_log_target_t log_target = PA_LOG_STDERR;
  61 static pa_log_func_t user_log_func = NULL;
  62 static pa_log_level_t maximal_level = PA_LOG_ERROR;
  63 static unsigned show_backtrace = 0;
  64 static pa_bool_t show_meta = FALSE;
  65 static pa_bool_t show_time = FALSE;
  66
  67 #ifdef HAVE_SYSLOG_H
  68 static const int level_to_syslog[] = {
  69     [PA_LOG_ERROR] = LOG_ERR,
  70     [PA_LOG_WARN] = LOG_WARNING,
  71     [PA_LOG_NOTICE] = LOG_NOTICE,
  72     [PA_LOG_INFO] = LOG_INFO,
  73     [PA_LOG_DEBUG] = LOG_DEBUG
  74 };
  75 #endif
  76
  77 static const char level_to_char[] = {
  78     [PA_LOG_ERROR] = 'E',
  79     [PA_LOG_WARN] = 'W',
  80     [PA_LOG_NOTICE] = 'N',
  81     [PA_LOG_INFO] = 'I',
  82     [PA_LOG_DEBUG] = 'D'
  83 };
  84
  85 void pa_log_set_ident(const char *p) {
  86     pa_xfree(log_ident);
  87     pa_xfree(log_ident_local);
  88
  89     log_ident = pa_xstrdup(p);
  90     if (!(log_ident_local = pa_utf8_to_locale(log_ident)))
  91         log_ident_local = pa_xstrdup(log_ident);
  92 }
  93
  94 /* To make valgrind shut up. */
  95 static void ident_destructor(void) PA_GCC_DESTRUCTOR;
  96 static void ident_destructor(void) {
  97     if (!pa_in_valgrind())
  98         return;
  99
 100     pa_xfree(log_ident);
 101     pa_xfree(log_ident_local);
 102 }
 103
 104 void pa_log_set_maximal_level(pa_log_level_t l) {
 105     pa_assert(l < PA_LOG_LEVEL_MAX);
 106
 107     maximal_level = l;
 108 }
 109
 110 void pa_log_set_target(pa_log_target_t t, pa_log_func_t func) {
 111     pa_assert(t == PA_LOG_USER || !func);
 112
 113     log_target = t;
 114     user_log_func = func;
 115 }
 116
 117 void pa_log_set_show_meta(pa_bool_t b) {
 118     show_meta = b;
 119 }
 120
 121 void pa_log_set_show_time(pa_bool_t b) {
 122     show_time = b;
 123 }
 124
 125 void pa_log_set_show_backtrace(unsigned nlevels) {
 126     show_backtrace = nlevels;
 127 }
 128
 129 #ifdef HAVE_EXECINFO_H
 130
 131 static char* get_backtrace(unsigned show_nframes) {
 132     void* trace[32];
 133     int n_frames;
 134     char **symbols, *e, *r;
 135     unsigned j, n;
 136     size_t a;
 137
 138     if (show_nframes <= 0)
 139         return NULL;
 140
 141     n_frames = backtrace(trace, PA_ELEMENTSOF(trace));
 142
 143     if (n_frames <= 0)
 144         return NULL;
 145
 146     symbols = backtrace_symbols(trace, n_frames);
 147
 148     if (!symbols)
 149         return NULL;
 150
 151     n = PA_MIN((unsigned) n_frames, show_nframes);
 152
 153     a = 4;
 154
 155     for (j = 0; j < n; j++) {
 156         if (j > 0)
 157             a += 2;
 158         a += strlen(symbols[j]);
 159     }
 160
 161     r = pa_xnew(char, a);
 162
 163     strcpy(r, " (");
 164     e = r + 2;
 165
 166     for (j = 0; j < n; j++) {
 167         if (j > 0) {
 168             strcpy(e, "<<");
 169             e += 2;
 170         }
 171
 172         strcpy(e, symbols[j]);
 173         e += strlen(symbols[j]);
 174     }
 175
 176     strcpy(e, ")");
 177
 178     free(symbols);
 179
 180     return r;
 181 }
 182
 183 #endif
 184
 185 void pa_log_levelv_meta(
 186         pa_log_level_t level,
 187         const char*file,
 188         int line,
 189         const char *func,
 190         const char *format,
 191         va_list ap) {
 192
 193     const char *e;
 194     char *t, *n;
 195     int saved_errno = errno;
 196     char *bt = NULL;
 197     pa_log_level_t ml;
 198 #ifdef HAVE_EXECINFO_H
 199     unsigned show_bt;
 200 #endif
 201
 202     /* We don't use dynamic memory allocation here to minimize the hit
 203      * in RT threads */
 204     char text[4096], location[128], timestamp[32];
 205
 206     pa_assert(level < PA_LOG_LEVEL_MAX);
 207     pa_assert(format);
 208
 209     ml = maximal_level;
 210
 211     if (PA_UNLIKELY((e = getenv(ENV_LOGLEVEL)))) {
 212         pa_log_level_t eml = (pa_log_level_t) atoi(e);
 213
 214         if (eml > ml)
 215             ml = eml;
 216     }
 217
 218     if (PA_LIKELY(level > ml)) {
 219         errno = saved_errno;
 220         return;
 221     }
 222
 223     pa_vsnprintf(text, sizeof(text), format, ap);
 224
 225     if ((show_meta || getenv(ENV_LOGMETA)) && file && line > 0 && func)
 226         pa_snprintf(location, sizeof(location), "[%s:%i %s()] ", file, line, func);
 227     else if (file)
 228         pa_snprintf(location, sizeof(location), "%s: ", pa_path_get_filename(file));
 229     else
 230         location[0] = 0;
 231
 232     if (show_time || getenv(ENV_LOGTIME)) {
 233         static pa_usec_t start, last;
 234         pa_usec_t u, a, r;
 235
 236         u = pa_rtclock_usec();
 237
 238         PA_ONCE_BEGIN {
 239             start = u;
 240             last = u;
 241         } PA_ONCE_END;
 242
 243         r = u - last;
 244         a = u - start;
 245
 246         /* This is not thread safe, but this is a debugging tool only
 247          * anyway. */
 248         last = u;
 249
 250         pa_snprintf(timestamp, sizeof(timestamp), "(%4llu.%03llu|%4llu.%03llu) ",
 251                     (unsigned long long) (a / PA_USEC_PER_SEC),
 252                     (unsigned long long) (((a / PA_USEC_PER_MSEC)) % 1000),
 253                     (unsigned long long) (r / PA_USEC_PER_SEC),
 254                     (unsigned long long) (((r / PA_USEC_PER_MSEC)) % 1000));
 255
 256     } else
 257         timestamp[0] = 0;
 258
 259 #ifdef HAVE_EXECINFO_H
 260     show_bt = show_backtrace;
 261
 262     if ((e = getenv(ENV_LOGBACKTRACE))) {
 263         unsigned ebt = (unsigned) atoi(e);
 264
 265         if (ebt > show_bt)
 266             show_bt = ebt;
 267     }
 268
 269     bt = get_backtrace(show_bt);
 270 #endif
 271
 272     if (!pa_utf8_valid(text))
 273         pa_log_level(level, __FILE__": invalid UTF-8 string following below:");
 274
 275     for (t = text; t; t = n) {
 276         if ((n = strchr(t, '\n'))) {
 277             *n = 0;
 278             n++;
 279         }
 280
 281         /* We ignore strings only made out of whitespace */
 282         if (t[strspn(t, "\t ")] == 0)
 283             continue;
 284
 285         switch (log_target) {
 286             case PA_LOG_STDERR: {
 287                 const char *prefix = "", *suffix = "", *grey = "";
 288                 char *local_t;
 289
 290 #ifndef OS_IS_WIN32
 291                 /* Yes indeed. Useless, but fun! */
 292                 if (isatty(STDERR_FILENO)) {
 293                     if (level <= PA_LOG_ERROR)
 294                         prefix = "\x1B[1;31m";
 295                     else if (level <= PA_LOG_WARN)
 296                         prefix = "\x1B[1m";
 297
 298                     if (bt)
 299                         grey = "\x1B[2m";
 300
 301                     if (grey[0] || prefix[0])
 302                         suffix = "\x1B[0m";
 303                 }
 304 #endif
 305
 306                 /* We shouldn't be using dynamic allocation here to
 307                  * minimize the hit in RT threads */
 308                 local_t = pa_utf8_to_locale(t);
 309                 if (!local_t)
 310                     fprintf(stderr, "%s%c: %s%s%s%s%s%s\n", timestamp, level_to_char[level], location, prefix, t, grey, pa_strempty(bt), suffix);
 311                 else {
 312                     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);
 313                     pa_xfree(local_t);
 314                 }
 315
 316                 break;
 317             }
 318
 319 #ifdef HAVE_SYSLOG_H
 320             case PA_LOG_SYSLOG: {
 321                 char *local_t;
 322
 323                 openlog(log_ident_local ? log_ident_local : "???", LOG_PID, LOG_USER);
 324
 325                 local_t = pa_utf8_to_locale(t);
 326                 if (!local_t)
 327                     syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, t, pa_strempty(bt));
 328                 else {
 329                     syslog(level_to_syslog[level], "%s%s%s%s", timestamp, location, local_t, pa_strempty(bt));
 330                     pa_xfree(local_t);
 331                 }
 332
 333                 closelog();
 334                 break;
 335             }
 336 #endif
 337
 338             case PA_LOG_USER: {
 339                 char x[1024];
 340
 341                 pa_snprintf(x, sizeof(x), "%s%s%s", timestamp, location, t);
 342                 user_log_func(level, x);
 343
 344                 break;
 345             }
 346
 347             case PA_LOG_NULL:
 348             default:
 349                 break;
 350         }
 351     }
 352
 353     errno = saved_errno;
 354 }
 355
 356 void pa_log_level_meta(
 357         pa_log_level_t level,
 358         const char*file,
 359         int line,
 360         const char *func,
 361         const char *format, ...) {
 362
 363     va_list ap;
 364     va_start(ap, format);
 365     pa_log_levelv_meta(level, file, line, func, format, ap);
 366     va_end(ap);
 367 }
 368
 369 void pa_log_levelv(pa_log_level_t level, const char *format, va_list ap) {
 370     pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
 371 }
 372
 373 void pa_log_level(pa_log_level_t level, const char *format, ...) {
 374     va_list ap;
 375
 376     va_start(ap, format);
 377     pa_log_levelv_meta(level, NULL, 0, NULL, format, ap);
 378     va_end(ap);
 379 }
 380
 381 pa_bool_t pa_log_ratelimit(void) {
 382     /* Not more than 10 messages every 5s */
 383     static PA_DEFINE_RATELIMIT(ratelimit, 5 * PA_USEC_PER_SEC, 10);
 384
 385     return pa_ratelimit_test(&ratelimit);
 386 }