src/common/log.c

   1 /* Copyright 2001,2002,2003 Roger Dingledine, Matej Pfajfar. */
   2 /* See LICENSE for licensing information */
   3 /* $Id$ */
   4 const char log_c_id[] = "$Id$";
   5
   6 /**
   7  * \file log.c
   8  *
   9  * \brief Functions to send messages to log files or the console.
  10  */
  11
  12 #include "orconfig.h"
  13 #include <stdarg.h>
  14 #include <assert.h>
  15 #include <stdlib.h>
  16 #include <string.h>
  17 #include "./util.h"
  18 #include "./log.h"
  19
  20 #define TRUNCATED_STR "[...truncated]"
  21 #define TRUNCATED_STR_LEN 14
  22
  23 /** Information for a single logfile; only used in log.c */
  24 typedef struct logfile_t {
  25   struct logfile_t *next; /**< Next logfile_t in the linked list. */
  26   char *filename; /**< Filename to open. */
  27   FILE *file; /**< Stream to receive log messages. */
  28   int needs_close; /**< Boolean: true if the stream gets closed on shutdown. */
  29   int loglevel; /**< Lowest severity level to send to this stream. */
  30   int max_loglevel; /**< Highest severity level to send to this stream. */
  31   int is_temporary; /**< Boolean: close after initializing logging subsystem.*/
  32   int is_syslog; /**< Boolean: send messages to syslog. */
  33   log_callback callback; /**< If not NULL, send messages to this function. */
  34 } logfile_t;
  35
  36 /** Helper: map a log severity to descriptive string. */
  37 static INLINE const char *sev_to_string(int severity) {
  38   switch (severity) {
  39     case LOG_DEBUG:   return "debug";
  40     case LOG_INFO:    return "info";
  41     case LOG_NOTICE:  return "notice";
  42     case LOG_WARN:    return "warn";
  43     case LOG_ERR:     return "err";
  44     default:          assert(0); return "UNKNOWN";
  45   }
  46 }
  47
  48 /** Linked list of logfile_t. */
  49 static logfile_t *logfiles = NULL;
  50 #ifdef HAVE_SYSLOG_H
  51 static int syslog_count = 0;
  52 #endif
  53
  54 static void delete_log(logfile_t *victim);
  55 static void close_log(logfile_t *victim);
  56 static int reset_log(logfile_t *lf);
  57
  58 static INLINE size_t
  59 _log_prefix(char *buf, size_t buf_len, int severity)
  60 {
  61   time_t t;
  62   struct timeval now;
  63   size_t n;
  64   int r;
  65
  66   tor_gettimeofday(&now);
  67   t = (time_t)now.tv_sec;
  68
  69   n = strftime(buf, buf_len, "%b %d %H:%M:%S", localtime(&t));
  70   r = tor_snprintf(buf+n, buf_len-n,
  71                 ".%.3ld [%s] ",
  72                 (long)now.tv_usec / 1000, sev_to_string(severity));
  73   if (r<0)
  74     return buf_len-1;
  75   else
  76     return n+r;
  77 }
  78
  79 /** If lf refers to an actual file that we have just opened, and the file
  80  * contains no data, log an "opening new logfile" message at the top.
  81  *
  82  * Return -1 if the log is broken and needs to be deleted, else return 0.
  83  */
  84 static int log_tor_version(logfile_t *lf, int reset)
  85 {
  86   char buf[256];
  87   size_t n;
  88   int is_new;
  89
  90   if (!lf->needs_close)
  91     /* If it doesn't get closed, it isn't really a file. */
  92     return 0;
  93   if (lf->is_temporary)
  94     /* If it's temporary, it isn't really a file. */
  95     return 0;
  96 #ifdef HAVE_FTELLO
  97   is_new = (ftello(lf->file) == 0);
  98 #else
  99   is_new = (ftell(lf->file) == 0);
 100 #endif
 101   if (reset && !is_new)
 102     /* We are resetting, but we aren't at the start of the file; no
 103      * need to log again. */
 104     return 0;
 105   n = _log_prefix(buf, sizeof(buf), LOG_NOTICE);
 106   tor_snprintf(buf+n, sizeof(buf)-n,
 107                "Tor %s opening %slog file.\n", VERSION, is_new?"new ":"");
 108   if (fputs(buf, lf->file) == EOF ||
 109       fflush(lf->file) == EOF) /* error */
 110     return -1; /* failed */
 111   return 0;
 112 }
 113
 114 /** Helper: Format a log message into a fixed-sized buffer. (This is
 115  * factored out of <b>logv</b> so that we never format a message more
 116  * than once.)  Return a pointer to the first character of the message
 117  * portion of the formatted string.
 118  */
 119 static INLINE char *format_msg(char *buf, size_t buf_len,
 120                               int severity, const char *funcname,
 121                               const char *format, va_list ap)
 122 {
 123   size_t n;
 124   int r;
 125   char *end_of_prefix;
 126
 127   tor_assert(buf_len >= 2); /* prevent integer underflow */
 128   buf_len -= 2; /* subtract 2 characters so we have room for \n\0 */
 129
 130   n = _log_prefix(buf, buf_len, severity);
 131   end_of_prefix = buf+n;
 132
 133   if (funcname) {
 134     r = tor_snprintf(buf+n, buf_len-n, "%s(): ", funcname);
 135     if (r<0)
 136       n = strlen(buf);
 137     else
 138       n += r;
 139   }
 140
 141   r = tor_vsnprintf(buf+n,buf_len-n,format,ap);
 142   if (r < 0) {
 143     /* The message was too long; overwrite the end of the buffer with
 144      * "[...truncated]" */
 145     if (buf_len >= TRUNCATED_STR_LEN) {
 146       int offset = buf_len-TRUNCATED_STR_LEN;
 147       /* We have an extra 2 characters after buf_len to hold the \n\0,
 148        * so it's safe to add 1 to the size here. */
 149       strlcpy(buf+offset, TRUNCATED_STR, buf_len-offset+1);
 150     }
 151     /* Set 'n' to the end of the buffer, where we'll be writing \n\0.
 152      * Since we already subtracted 2 from buf_len, this is safe.*/
 153     n = buf_len;
 154   } else {
 155     n += r;
 156   }
 157   buf[n]='\n';
 158   buf[n+1]='\0';
 159   return end_of_prefix;
 160 }
 161
 162 /** Helper: sends a message to the appropriate logfiles, at loglevel
 163  * <b>severity</b>.  If provided, <b>funcname</b> is prepended to the
 164  * message.  The actual message is derived as from tor_snprintf(format,ap).
 165  */
 166 static void
 167 logv(int severity, const char *funcname, const char *format, va_list ap)
 168 {
 169   char buf[10024];
 170   int formatted = 0;
 171   logfile_t *lf;
 172   char *end_of_prefix=NULL;
 173
 174   assert(format);
 175   lf = logfiles;
 176   while (lf) {
 177     if (severity > lf->loglevel || severity < lf->max_loglevel) {
 178       lf = lf->next;
 179       continue;
 180     }
 181     if (! (lf->file || lf->is_syslog || lf->callback)) {
 182       lf = lf->next;
 183       continue;
 184     }
 185
 186     if (!formatted) {
 187       end_of_prefix =
 188         format_msg(buf, sizeof(buf), severity, funcname, format, ap);
 189       formatted = 1;
 190     }
 191     if (lf->is_syslog) {
 192 #ifdef HAVE_SYSLOG_H
 193       syslog(severity, "%s", end_of_prefix);
 194 #endif
 195       lf = lf->next;
 196       continue;
 197     } else if (lf->callback) {
 198       lf->callback(severity, end_of_prefix);
 199       lf = lf->next;
 200       continue;
 201     }
 202     if (fputs(buf, lf->file) == EOF ||
 203         fflush(lf->file) == EOF) { /* error */
 204       /* don't log the error! Blow away this log entry and continue. */
 205       logfile_t *victim = lf;
 206       lf = victim->next;
 207       delete_log(victim);
 208     } else {
 209       lf = lf->next;
 210     }
 211   }
 212 }
 213
 214 /** Output a message to the log. */
 215 void _log(int severity, const char *format, ...)
 216 {
 217   va_list ap;
 218   va_start(ap,format);
 219   logv(severity, NULL, format, ap);
 220   va_end(ap);
 221 }
 222
 223 /** Output a message to the log, prefixed with a function name <b>fn</b>. */
 224 #ifdef __GNUC__
 225 void _log_fn(int severity, const char *fn, const char *format, ...)
 226 {
 227   va_list ap;
 228   va_start(ap,format);
 229   logv(severity, fn, format, ap);
 230   va_end(ap);
 231 }
 232 #else
 233 const char *_log_fn_function_name=NULL;
 234 void _log_fn(int severity, const char *format, ...)
 235 {
 236   va_list ap;
 237   va_start(ap,format);
 238   logv(severity, _log_fn_function_name, format, ap);
 239   va_end(ap);
 240   _log_fn_function_name = NULL;
 241 }
 242 #endif
 243
 244 /** Close all open log files. */
 245 void close_logs()
 246 {
 247   logfile_t *victim;
 248   while (logfiles) {
 249     victim = logfiles;
 250     logfiles = logfiles->next;
 251     close_log(victim);
 252     tor_free(victim->filename);
 253     tor_free(victim);
 254   }
 255 }
 256
 257 /** Close and re-open all log files; used to rotate logs on SIGHUP. */
 258 void reset_logs()
 259 {
 260   logfile_t *lf = logfiles;
 261   while (lf) {
 262     if (reset_log(lf)) {
 263       /* error. don't log it. delete the log entry and continue. */
 264       logfile_t *victim = lf;
 265       lf = victim->next;
 266       delete_log(victim);
 267       continue;
 268     }
 269     lf = lf->next;
 270   }
 271 }
 272
 273 /** Remove and free the log entry <b>victim</b> from the linked-list
 274  * logfiles (it must be present in the list when this function is
 275  * called). After this function is called, the caller shouldn't refer
 276  * to <b>victim</b> anymore.
 277  */
 278 static void delete_log(logfile_t *victim) {
 279   logfile_t *tmpl;
 280   if (victim == logfiles)
 281     logfiles = victim->next;
 282   else {
 283     for (tmpl = logfiles; tmpl && tmpl->next != victim; tmpl=tmpl->next) ;
 284     tor_assert(tmpl);
 285     tor_assert(tmpl->next == victim);
 286     tmpl->next = victim->next;
 287   }
 288   tor_free(victim->filename);
 289   tor_free(victim);
 290 }
 291
 292 /** DOCDOC */
 293 static void close_log(logfile_t *victim)
 294 {
 295   if (victim->needs_close && victim->file) {
 296     fclose(victim->file);
 297   } else if (victim->is_syslog) {
 298 #ifdef HAVE_SYSLOG_H
 299     if (--syslog_count == 0)
 300       /* There are no other syslogs; close the logging facility. */
 301       closelog();
 302 #endif
 303   }
 304 }
 305
 306 /** DOCDOC */
 307 static int reset_log(logfile_t *lf)
 308 {
 309   if (lf->needs_close) {
 310     if (fclose(lf->file)==EOF ||
 311        !(lf->file = fopen(lf->filename, "a"))) {
 312       return -1;
 313     } else {
 314       if (log_tor_version(lf, 1) < 0)
 315         return -1;
 316     }
 317   }
 318   return 0;
 319 }
 320
 321 /** Add a log handler to send all messages of severity <b>loglevel</b>
 322  * or higher to <b>stream</b>. */
 323 void add_stream_log(int loglevelMin, int loglevelMax, const char *name, FILE *stream)
 324 {
 325   logfile_t *lf;
 326   lf = tor_malloc_zero(sizeof(logfile_t));
 327   lf->filename = tor_strdup(name);
 328   lf->loglevel = loglevelMin;
 329   lf->max_loglevel = loglevelMax;
 330   lf->file = stream;
 331   lf->next = logfiles;
 332   logfiles = lf;
 333 }
 334
 335 /** Add a log handler to receive messages during startup (before the real
 336  * logs are initialized).
 337  */
 338 void add_temp_log(void)
 339 {
 340   add_stream_log(LOG_NOTICE, LOG_ERR, "<temp>", stdout);
 341   logfiles->is_temporary = 1;
 342 }
 343
 344 int add_callback_log(int loglevelMin, int loglevelMax, log_callback cb)
 345 {
 346   logfile_t *lf;
 347   lf = tor_malloc_zero(sizeof(logfile_t));
 348   lf->loglevel = loglevelMin;
 349   lf->max_loglevel = loglevelMax;
 350   lf->filename = tor_strdup("<callback>");
 351   lf->callback = cb;
 352   lf->next = logfiles;
 353   logfiles = lf;
 354   return 0;
 355 }
 356
 357 /** Close any log handlers added by add_temp_log or marked by mark_logs_temp */
 358 void close_temp_logs(void)
 359 {
 360   logfile_t *lf, **p;
 361   for (p = &logfiles; *p; ) {
 362     if ((*p)->is_temporary) {
 363       lf = *p;
 364       /* we use *p here to handle the edge case of the head of the list */
 365       *p = (*p)->next;
 366       close_log(lf);
 367       tor_free(lf->filename);
 368       tor_free(lf);
 369     } else {
 370       p = &((*p)->next);
 371     }
 372   }
 373 }
 374
 375 /** Configure all log handles to be closed by close_temp_logs */
 376 void mark_logs_temp(void)
 377 {
 378   logfile_t *lf;
 379   for (lf = logfiles; lf; lf = lf->next)
 380     lf->is_temporary = 1;
 381 }
 382
 383 /**
 384  * Add a log handler to send messages to <b>filename</b>. If opening
 385  * the logfile fails, -1 is returned and errno is set appropriately
 386  * (by fopen).
 387  */
 388 int add_file_log(int loglevelMin, int loglevelMax, const char *filename)
 389 {
 390   FILE *f;
 391   f = fopen(filename, "a");
 392   if (!f) return -1;
 393   add_stream_log(loglevelMin, loglevelMax, filename, f);
 394   logfiles->needs_close = 1;
 395   if (log_tor_version(logfiles, 0) < 0) {
 396     delete_log(logfiles);
 397   }
 398   return 0;
 399 }
 400
 401 #ifdef HAVE_SYSLOG_H
 402 /**
 403  * Add a log handler to send messages to they system log facility.
 404  */
 405 int add_syslog_log(int loglevelMin, int loglevelMax)
 406 {
 407   logfile_t *lf;
 408   if (syslog_count++ == 0)
 409     /* This is the first syslog. */
 410     openlog("Tor", LOG_NDELAY, LOG_DAEMON);
 411
 412   lf = tor_malloc_zero(sizeof(logfile_t));
 413   lf->loglevel = loglevelMin;
 414   lf->filename = tor_strdup("<syslog>");
 415   lf->max_loglevel = loglevelMax;
 416   lf->is_syslog = 1;
 417   lf->next = logfiles;
 418   logfiles = lf;
 419   return 0;
 420 }
 421 #endif
 422
 423 /** If <b>level</b> is a valid log severity, return the corresponding
 424  * numeric value.  Otherwise, return -1. */
 425 int parse_log_level(const char *level) {
 426   if (!strcasecmp(level, "err"))
 427     return LOG_ERR;
 428   if (!strcasecmp(level, "warn"))
 429     return LOG_WARN;
 430   if (!strcasecmp(level, "notice"))
 431     return LOG_NOTICE;
 432   if (!strcasecmp(level, "info"))
 433     return LOG_INFO;
 434   if (!strcasecmp(level, "debug"))
 435     return LOG_DEBUG;
 436   return -1;
 437 }
 438
 439 const char *log_level_to_string(int level)
 440 {
 441   return sev_to_string(level);
 442 }
 443
 444 int get_min_log_level(void)
 445 {
 446   logfile_t *lf;
 447   int min = LOG_ERR;
 448   for (lf = logfiles; lf; lf = lf->next) {
 449     if (lf->loglevel > min)
 450       min = lf->loglevel;
 451   }
 452   return min;
 453 }
 454
 455 /** Switch all logs to output at most verbose level. */
 456 void switch_logs_debug(void)
 457 {
 458   logfile_t *lf;
 459   for (lf = logfiles; lf; lf=lf->next) {
 460     lf->loglevel = LOG_DEBUG;
 461   }
 462 }
 463