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