Update comments in get_interface_addresses_ioctl
[tor.git] / src / common / log.c
blob7ede6100a2c7959c0a043c3972909f93b4620aa9
1 /* Copyright (c) 2001, Matej Pfajfar.
2 * Copyright (c) 2001-2004, Roger Dingledine.
3 * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson.
4 * Copyright (c) 2007-2015, The Tor Project, Inc. */
5 /* See LICENSE for licensing information */
7 /**
8 * \file log.c
9 * \brief Functions to send messages to log files or the console.
10 **/
12 #include "orconfig.h"
13 #include <stdarg.h>
14 #include <assert.h>
15 // #include <stdio.h>
16 #include <stdlib.h>
17 #include <string.h>
18 #ifdef HAVE_SYS_TIME_H
19 #include <sys/time.h>
20 #endif
21 #ifdef HAVE_TIME_H
22 #include <time.h>
23 #endif
24 #ifdef HAVE_UNISTD_H
25 #include <unistd.h>
26 #endif
27 #ifdef HAVE_SYS_TYPES_H
28 #include <sys/types.h>
29 #endif
30 #ifdef HAVE_FCNTL_H
31 #include <fcntl.h>
32 #endif
33 #include "compat.h"
34 #include "util.h"
35 #define LOG_PRIVATE
36 #include "torlog.h"
37 #include "container.h"
39 /** Given a severity, yields an index into log_severity_list_t.masks to use
40 * for that severity. */
41 #define SEVERITY_MASK_IDX(sev) ((sev) - LOG_ERR)
43 /** @{ */
44 /** The string we stick at the end of a log message when it is too long,
45 * and its length. */
46 #define TRUNCATED_STR "[...truncated]"
47 #define TRUNCATED_STR_LEN 14
48 /** @} */
50 /** Information for a single logfile; only used in log.c */
51 typedef struct logfile_t {
52 struct logfile_t *next; /**< Next logfile_t in the linked list. */
53 char *filename; /**< Filename to open. */
54 int fd; /**< fd to receive log messages, or -1 for none. */
55 int seems_dead; /**< Boolean: true if the stream seems to be kaput. */
56 int needs_close; /**< Boolean: true if the stream gets closed on shutdown. */
57 int is_temporary; /**< Boolean: close after initializing logging subsystem.*/
58 int is_syslog; /**< Boolean: send messages to syslog. */
59 log_callback callback; /**< If not NULL, send messages to this function. */
60 log_severity_list_t *severities; /**< Which severity of messages should we
61 * log for each log domain? */
62 } logfile_t;
64 static void log_free(logfile_t *victim);
66 /** Helper: map a log severity to descriptive string. */
67 static INLINE const char *
68 sev_to_string(int severity)
70 switch (severity) {
71 case LOG_DEBUG: return "debug";
72 case LOG_INFO: return "info";
73 case LOG_NOTICE: return "notice";
74 case LOG_WARN: return "warn";
75 case LOG_ERR: return "err";
76 default: /* Call assert, not tor_assert, since tor_assert
77 * calls log on failure. */
78 assert(0); return "UNKNOWN";
82 /** Helper: decide whether to include the function name in the log message. */
83 static INLINE int
84 should_log_function_name(log_domain_mask_t domain, int severity)
86 switch (severity) {
87 case LOG_DEBUG:
88 case LOG_INFO:
89 /* All debugging messages occur in interesting places. */
90 return (domain & LD_NOFUNCNAME) == 0;
91 case LOG_NOTICE:
92 case LOG_WARN:
93 case LOG_ERR:
94 /* We care about places where bugs occur. */
95 return (domain & (LD_BUG|LD_NOFUNCNAME)) == LD_BUG;
96 default:
97 /* Call assert, not tor_assert, since tor_assert calls log on failure. */
98 assert(0); return 0;
102 /** A mutex to guard changes to logfiles and logging. */
103 static tor_mutex_t log_mutex;
104 /** True iff we have initialized log_mutex */
105 static int log_mutex_initialized = 0;
107 /** Linked list of logfile_t. */
108 static logfile_t *logfiles = NULL;
109 /** Boolean: do we report logging domains? */
110 static int log_domains_are_logged = 0;
112 #ifdef HAVE_SYSLOG_H
113 /** The number of open syslog log handlers that we have. When this reaches 0,
114 * we can close our connection to the syslog facility. */
115 static int syslog_count = 0;
116 #endif
118 /** Represents a log message that we are going to send to callback-driven
119 * loggers once we can do so in a non-reentrant way. */
120 typedef struct pending_log_message_t {
121 int severity; /**< The severity of the message */
122 log_domain_mask_t domain; /**< The domain of the message */
123 char *fullmsg; /**< The message, with all decorations */
124 char *msg; /**< The content of the message */
125 } pending_log_message_t;
127 /** Log messages waiting to be replayed onto callback-based logs */
128 static smartlist_t *pending_cb_messages = NULL;
130 /** Log messages waiting to be replayed once the logging system is initialized.
132 static smartlist_t *pending_startup_messages = NULL;
134 /** Number of bytes of messages queued in pending_startup_messages. (This is
135 * the length of the messages, not the number of bytes used to store
136 * them.) */
137 static size_t pending_startup_messages_len;
139 /** True iff we should store messages while waiting for the logs to get
140 * configured. */
141 static int queue_startup_messages = 1;
143 /** True iff __PRETTY_FUNCTION__ includes parenthesized arguments. */
144 static int pretty_fn_has_parens = 0;
146 /** Don't store more than this many bytes of messages while waiting for the
147 * logs to get configured. */
148 #define MAX_STARTUP_MSG_LEN (1<<16)
150 /** Lock the log_mutex to prevent others from changing the logfile_t list */
151 #define LOCK_LOGS() STMT_BEGIN \
152 tor_mutex_acquire(&log_mutex); \
153 STMT_END
154 /** Unlock the log_mutex */
155 #define UNLOCK_LOGS() STMT_BEGIN tor_mutex_release(&log_mutex); STMT_END
157 /** What's the lowest log level anybody cares about? Checking this lets us
158 * bail out early from log_debug if we aren't debugging. */
159 int log_global_min_severity_ = LOG_NOTICE;
161 static void delete_log(logfile_t *victim);
162 static void close_log(logfile_t *victim);
164 static char *domain_to_string(log_domain_mask_t domain,
165 char *buf, size_t buflen);
166 static INLINE char *format_msg(char *buf, size_t buf_len,
167 log_domain_mask_t domain, int severity, const char *funcname,
168 const char *suffix,
169 const char *format, va_list ap, size_t *msg_len_out)
170 CHECK_PRINTF(7,0);
172 /** Name of the application: used to generate the message we write at the
173 * start of each new log. */
174 static char *appname = NULL;
176 /** Set the "application name" for the logs to <b>name</b>: we'll use this
177 * name in the message we write when starting up, and at the start of each new
178 * log.
180 * Tor uses this string to write the version number to the log file. */
181 void
182 log_set_application_name(const char *name)
184 tor_free(appname);
185 appname = name ? tor_strdup(name) : NULL;
188 /** Log time granularity in milliseconds. */
189 static int log_time_granularity = 1;
191 /** Define log time granularity for all logs to be <b>granularity_msec</b>
192 * milliseconds. */
193 void
194 set_log_time_granularity(int granularity_msec)
196 log_time_granularity = granularity_msec;
199 /** Helper: Write the standard prefix for log lines to a
200 * <b>buf_len</b> character buffer in <b>buf</b>.
202 static INLINE size_t
203 log_prefix_(char *buf, size_t buf_len, int severity)
205 time_t t;
206 struct timeval now;
207 struct tm tm;
208 size_t n;
209 int r, ms;
211 tor_gettimeofday(&now);
212 t = (time_t)now.tv_sec;
213 ms = (int)now.tv_usec / 1000;
214 if (log_time_granularity >= 1000) {
215 t -= t % (log_time_granularity / 1000);
216 ms = 0;
217 } else {
218 ms -= ((int)now.tv_usec / 1000) % log_time_granularity;
221 n = strftime(buf, buf_len, "%b %d %H:%M:%S", tor_localtime_r(&t, &tm));
222 r = tor_snprintf(buf+n, buf_len-n, ".%.3i [%s] ", ms,
223 sev_to_string(severity));
225 if (r<0)
226 return buf_len-1;
227 else
228 return n+r;
231 /** If lf refers to an actual file that we have just opened, and the file
232 * contains no data, log an "opening new logfile" message at the top.
234 * Return -1 if the log is broken and needs to be deleted, else return 0.
236 static int
237 log_tor_version(logfile_t *lf, int reset)
239 char buf[256];
240 size_t n;
241 int is_new;
243 if (!lf->needs_close)
244 /* If it doesn't get closed, it isn't really a file. */
245 return 0;
246 if (lf->is_temporary)
247 /* If it's temporary, it isn't really a file. */
248 return 0;
250 is_new = lf->fd >= 0 && tor_fd_getpos(lf->fd) == 0;
252 if (reset && !is_new)
253 /* We are resetting, but we aren't at the start of the file; no
254 * need to log again. */
255 return 0;
256 n = log_prefix_(buf, sizeof(buf), LOG_NOTICE);
257 if (appname) {
258 tor_snprintf(buf+n, sizeof(buf)-n,
259 "%s opening %slog file.\n", appname, is_new?"new ":"");
260 } else {
261 tor_snprintf(buf+n, sizeof(buf)-n,
262 "Tor %s opening %slog file.\n", VERSION, is_new?"new ":"");
264 if (write_all(lf->fd, buf, strlen(buf), 0) < 0) /* error */
265 return -1; /* failed */
266 return 0;
269 const char bug_suffix[] = " (on Tor " VERSION
270 #ifndef _MSC_VER
272 #include "micro-revision.i"
273 #endif
274 ")";
276 /** Helper: Format a log message into a fixed-sized buffer. (This is
277 * factored out of <b>logv</b> so that we never format a message more
278 * than once.) Return a pointer to the first character of the message
279 * portion of the formatted string.
281 static INLINE char *
282 format_msg(char *buf, size_t buf_len,
283 log_domain_mask_t domain, int severity, const char *funcname,
284 const char *suffix,
285 const char *format, va_list ap, size_t *msg_len_out)
287 size_t n;
288 int r;
289 char *end_of_prefix;
290 char *buf_end;
292 assert(buf_len >= 16); /* prevent integer underflow and general stupidity */
293 buf_len -= 2; /* subtract 2 characters so we have room for \n\0 */
294 buf_end = buf+buf_len; /* point *after* the last char we can write to */
296 n = log_prefix_(buf, buf_len, severity);
297 end_of_prefix = buf+n;
299 if (log_domains_are_logged) {
300 char *cp = buf+n;
301 if (cp == buf_end) goto format_msg_no_room_for_domains;
302 *cp++ = '{';
303 if (cp == buf_end) goto format_msg_no_room_for_domains;
304 cp = domain_to_string(domain, cp, (buf+buf_len-cp));
305 if (cp == buf_end) goto format_msg_no_room_for_domains;
306 *cp++ = '}';
307 if (cp == buf_end) goto format_msg_no_room_for_domains;
308 *cp++ = ' ';
309 if (cp == buf_end) goto format_msg_no_room_for_domains;
310 end_of_prefix = cp;
311 n = cp-buf;
312 format_msg_no_room_for_domains:
313 /* This will leave end_of_prefix and n unchanged, and thus cause
314 * whatever log domain string we had written to be clobbered. */
318 if (funcname && should_log_function_name(domain, severity)) {
319 r = tor_snprintf(buf+n, buf_len-n,
320 pretty_fn_has_parens ? "%s: " : "%s(): ",
321 funcname);
322 if (r<0)
323 n = strlen(buf);
324 else
325 n += r;
328 if (domain == LD_BUG && buf_len-n > 6) {
329 memcpy(buf+n, "Bug: ", 6);
330 n += 5;
333 r = tor_vsnprintf(buf+n,buf_len-n,format,ap);
334 if (r < 0) {
335 /* The message was too long; overwrite the end of the buffer with
336 * "[...truncated]" */
337 if (buf_len >= TRUNCATED_STR_LEN) {
338 size_t offset = buf_len-TRUNCATED_STR_LEN;
339 /* We have an extra 2 characters after buf_len to hold the \n\0,
340 * so it's safe to add 1 to the size here. */
341 strlcpy(buf+offset, TRUNCATED_STR, buf_len-offset+1);
343 /* Set 'n' to the end of the buffer, where we'll be writing \n\0.
344 * Since we already subtracted 2 from buf_len, this is safe.*/
345 n = buf_len;
346 } else {
347 n += r;
348 if (suffix) {
349 size_t suffix_len = strlen(suffix);
350 if (buf_len-n >= suffix_len) {
351 memcpy(buf+n, suffix, suffix_len);
352 n += suffix_len;
357 if (domain == LD_BUG &&
358 buf_len - n > strlen(bug_suffix)+1) {
359 memcpy(buf+n, bug_suffix, strlen(bug_suffix));
360 n += strlen(bug_suffix);
363 buf[n]='\n';
364 buf[n+1]='\0';
365 *msg_len_out = n+1;
366 return end_of_prefix;
369 /* Create a new pending_log_message_t with appropriate values */
370 static pending_log_message_t *
371 pending_log_message_new(int severity, log_domain_mask_t domain,
372 const char *fullmsg, const char *shortmsg)
374 pending_log_message_t *m = tor_malloc(sizeof(pending_log_message_t));
375 m->severity = severity;
376 m->domain = domain;
377 m->fullmsg = fullmsg ? tor_strdup(fullmsg) : NULL;
378 m->msg = tor_strdup(shortmsg);
379 return m;
382 /** Release all storage held by <b>msg</b>. */
383 static void
384 pending_log_message_free(pending_log_message_t *msg)
386 if (!msg)
387 return;
388 tor_free(msg->msg);
389 tor_free(msg->fullmsg);
390 tor_free(msg);
393 /** Return true iff <b>lf</b> would like to receive a message with the
394 * specified <b>severity</b> in the specified <b>domain</b>.
396 static INLINE int
397 logfile_wants_message(const logfile_t *lf, int severity,
398 log_domain_mask_t domain)
400 if (! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
401 return 0;
403 if (! (lf->fd >= 0 || lf->is_syslog || lf->callback)) {
404 return 0;
406 if (lf->seems_dead) {
407 return 0;
410 return 1;
413 /** Send a message to <b>lf</b>. The full message, with time prefix and
414 * severity, is in <b>buf</b>. The message itself is in
415 * <b>msg_after_prefix</b>. If <b>callbacks_deferred</b> points to true, then
416 * we already deferred this message for pending callbacks and don't need to do
417 * it again. Otherwise, if we need to do it, do it, and set
418 * <b>callbacks_deferred</b> to 1. */
419 static INLINE void
420 logfile_deliver(logfile_t *lf, const char *buf, size_t msg_len,
421 const char *msg_after_prefix, log_domain_mask_t domain,
422 int severity, int *callbacks_deferred)
425 if (lf->is_syslog) {
426 #ifdef HAVE_SYSLOG_H
427 #ifdef MAXLINE
428 /* Some syslog implementations have limits on the length of what you can
429 * pass them, and some very old ones do not detect overflow so well.
430 * Regrettably, they call their maximum line length MAXLINE. */
431 #if MAXLINE < 64
432 #warn "MAXLINE is a very low number; it might not be from syslog.h after all"
433 #endif
434 char *m = msg_after_prefix;
435 if (msg_len >= MAXLINE)
436 m = tor_strndup(msg_after_prefix, MAXLINE-1);
437 syslog(severity, "%s", m);
438 if (m != msg_after_prefix) {
439 tor_free(m);
441 #else
442 /* We have syslog but not MAXLINE. That's promising! */
443 syslog(severity, "%s", msg_after_prefix);
444 #endif
445 #endif
446 } else if (lf->callback) {
447 if (domain & LD_NOCB) {
448 if (!*callbacks_deferred && pending_cb_messages) {
449 smartlist_add(pending_cb_messages,
450 pending_log_message_new(severity,domain,NULL,msg_after_prefix));
451 *callbacks_deferred = 1;
453 } else {
454 lf->callback(severity, domain, msg_after_prefix);
456 } else {
457 if (write_all(lf->fd, buf, msg_len, 0) < 0) { /* error */
458 /* don't log the error! mark this log entry to be blown away, and
459 * continue. */
460 lf->seems_dead = 1;
465 /** Helper: sends a message to the appropriate logfiles, at loglevel
466 * <b>severity</b>. If provided, <b>funcname</b> is prepended to the
467 * message. The actual message is derived as from tor_snprintf(format,ap).
469 MOCK_IMPL(STATIC void,
470 logv,(int severity, log_domain_mask_t domain, const char *funcname,
471 const char *suffix, const char *format, va_list ap))
473 char buf[10240];
474 size_t msg_len = 0;
475 int formatted = 0;
476 logfile_t *lf;
477 char *end_of_prefix=NULL;
478 int callbacks_deferred = 0;
480 /* Call assert, not tor_assert, since tor_assert calls log on failure. */
481 assert(format);
482 /* check that severity is sane. Overrunning the masks array leads to
483 * interesting and hard to diagnose effects */
484 assert(severity >= LOG_ERR && severity <= LOG_DEBUG);
485 LOCK_LOGS();
487 if ((! (domain & LD_NOCB)) && smartlist_len(pending_cb_messages))
488 flush_pending_log_callbacks();
490 if (queue_startup_messages &&
491 pending_startup_messages_len < MAX_STARTUP_MSG_LEN) {
492 end_of_prefix =
493 format_msg(buf, sizeof(buf), domain, severity, funcname, suffix,
494 format, ap, &msg_len);
495 formatted = 1;
497 smartlist_add(pending_startup_messages,
498 pending_log_message_new(severity,domain,buf,end_of_prefix));
499 pending_startup_messages_len += msg_len;
502 for (lf = logfiles; lf; lf = lf->next) {
503 if (! logfile_wants_message(lf, severity, domain))
504 continue;
506 if (!formatted) {
507 end_of_prefix =
508 format_msg(buf, sizeof(buf), domain, severity, funcname, suffix,
509 format, ap, &msg_len);
510 formatted = 1;
513 logfile_deliver(lf, buf, msg_len, end_of_prefix, domain, severity,
514 &callbacks_deferred);
516 UNLOCK_LOGS();
519 /** Output a message to the log. It gets logged to all logfiles that
520 * care about messages with <b>severity</b> in <b>domain</b>. The content
521 * is formatted printf-style based on <b>format</b> and extra arguments.
522 * */
523 void
524 tor_log(int severity, log_domain_mask_t domain, const char *format, ...)
526 va_list ap;
527 if (severity > log_global_min_severity_)
528 return;
529 va_start(ap,format);
530 logv(severity, domain, NULL, NULL, format, ap);
531 va_end(ap);
534 /** Maximum number of fds that will get notifications if we crash */
535 #define MAX_SIGSAFE_FDS 8
536 /** Array of fds to log crash-style warnings to. */
537 static int sigsafe_log_fds[MAX_SIGSAFE_FDS] = { STDERR_FILENO };
538 /** The number of elements used in sigsafe_log_fds */
539 static int n_sigsafe_log_fds = 1;
541 /** Write <b>s</b> to each element of sigsafe_log_fds. Return 0 on success, -1
542 * on failure. */
543 static int
544 tor_log_err_sigsafe_write(const char *s)
546 int i;
547 ssize_t r;
548 size_t len = strlen(s);
549 int err = 0;
550 for (i=0; i < n_sigsafe_log_fds; ++i) {
551 r = write(sigsafe_log_fds[i], s, len);
552 err += (r != (ssize_t)len);
554 return err ? -1 : 0;
557 /** Given a list of string arguments ending with a NULL, writes them
558 * to our logs and to stderr (if possible). This function is safe to call
559 * from within a signal handler. */
560 void
561 tor_log_err_sigsafe(const char *m, ...)
563 va_list ap;
564 const char *x;
565 char timebuf[33];
566 time_t now = time(NULL);
568 if (!m)
569 return;
570 if (log_time_granularity >= 2000) {
571 int g = log_time_granularity / 1000;
572 now -= now % g;
574 timebuf[0] = now < 0 ? '-' : ' ';
575 if (now < 0) now = -now;
576 timebuf[1] = '\0';
577 format_dec_number_sigsafe(now, timebuf+1, sizeof(timebuf)-1);
578 tor_log_err_sigsafe_write("\n=========================================="
579 "================== T=");
580 tor_log_err_sigsafe_write(timebuf);
581 tor_log_err_sigsafe_write("\n");
582 tor_log_err_sigsafe_write(m);
583 va_start(ap, m);
584 while ((x = va_arg(ap, const char*))) {
585 tor_log_err_sigsafe_write(x);
587 va_end(ap);
590 /** Set *<b>out</b> to a pointer to an array of the fds to log errors to from
591 * inside a signal handler. Return the number of elements in the array. */
593 tor_log_get_sigsafe_err_fds(const int **out)
595 *out = sigsafe_log_fds;
596 return n_sigsafe_log_fds;
599 /** Helper function; return true iff the <b>n</b>-element array <b>array</b>
600 * contains <b>item</b>. */
601 static int
602 int_array_contains(const int *array, int n, int item)
604 int j;
605 for (j = 0; j < n; ++j) {
606 if (array[j] == item)
607 return 1;
609 return 0;
612 /** Function to call whenever the list of logs changes to get ready to log
613 * from signal handlers. */
614 void
615 tor_log_update_sigsafe_err_fds(void)
617 const logfile_t *lf;
618 int found_real_stderr = 0;
620 LOCK_LOGS();
621 /* Reserve the first one for stderr. This is safe because when we daemonize,
622 * we dup2 /dev/null to stderr, */
623 sigsafe_log_fds[0] = STDERR_FILENO;
624 n_sigsafe_log_fds = 1;
626 for (lf = logfiles; lf; lf = lf->next) {
627 /* Don't try callback to the control port, or syslogs: We can't
628 * do them from a signal handler. Don't try stdout: we always do stderr.
630 if (lf->is_temporary || lf->is_syslog ||
631 lf->callback || lf->seems_dead || lf->fd < 0)
632 continue;
633 if (lf->severities->masks[SEVERITY_MASK_IDX(LOG_ERR)] &
634 (LD_BUG|LD_GENERAL)) {
635 if (lf->fd == STDERR_FILENO)
636 found_real_stderr = 1;
637 /* Avoid duplicates */
638 if (int_array_contains(sigsafe_log_fds, n_sigsafe_log_fds, lf->fd))
639 continue;
640 sigsafe_log_fds[n_sigsafe_log_fds++] = lf->fd;
641 if (n_sigsafe_log_fds == MAX_SIGSAFE_FDS)
642 break;
646 if (!found_real_stderr &&
647 int_array_contains(sigsafe_log_fds, n_sigsafe_log_fds, STDOUT_FILENO)) {
648 /* Don't use a virtual stderr when we're also logging to stdout. */
649 assert(n_sigsafe_log_fds >= 2); /* Don't use assert inside log functions*/
650 sigsafe_log_fds[0] = sigsafe_log_fds[--n_sigsafe_log_fds];
653 UNLOCK_LOGS();
656 /** Add to <b>out</b> a copy of every currently configured log file name. Used
657 * to enable access to these filenames with the sandbox code. */
658 void
659 tor_log_get_logfile_names(smartlist_t *out)
661 logfile_t *lf;
662 tor_assert(out);
664 LOCK_LOGS();
666 for (lf = logfiles; lf; lf = lf->next) {
667 if (lf->is_temporary || lf->is_syslog || lf->callback)
668 continue;
669 if (lf->filename == NULL)
670 continue;
671 smartlist_add(out, tor_strdup(lf->filename));
674 UNLOCK_LOGS();
677 /** Implementation of the log_fn backend, used when we have
678 * variadic macros. All arguments are as for log_fn, except for
679 * <b>fn</b>, which is the name of the calling functions. */
680 void
681 log_fn_(int severity, log_domain_mask_t domain, const char *fn,
682 const char *format, ...)
684 va_list ap;
685 if (severity > log_global_min_severity_)
686 return;
687 va_start(ap,format);
688 logv(severity, domain, fn, NULL, format, ap);
689 va_end(ap);
691 void
692 log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain,
693 const char *fn, const char *format, ...)
695 va_list ap;
696 char *m;
697 if (severity > log_global_min_severity_)
698 return;
699 m = rate_limit_log(ratelim, approx_time());
700 if (m == NULL)
701 return;
702 va_start(ap, format);
703 logv(severity, domain, fn, m, format, ap);
704 va_end(ap);
705 tor_free(m);
708 /** Free all storage held by <b>victim</b>. */
709 static void
710 log_free(logfile_t *victim)
712 if (!victim)
713 return;
714 tor_free(victim->severities);
715 tor_free(victim->filename);
716 tor_free(victim);
719 /** Close all open log files, and free other static memory. */
720 void
721 logs_free_all(void)
723 logfile_t *victim, *next;
724 smartlist_t *messages, *messages2;
725 LOCK_LOGS();
726 next = logfiles;
727 logfiles = NULL;
728 messages = pending_cb_messages;
729 pending_cb_messages = NULL;
730 messages2 = pending_startup_messages;
731 pending_startup_messages = NULL;
732 UNLOCK_LOGS();
733 while (next) {
734 victim = next;
735 next = next->next;
736 close_log(victim);
737 log_free(victim);
739 tor_free(appname);
741 SMARTLIST_FOREACH(messages, pending_log_message_t *, msg, {
742 pending_log_message_free(msg);
744 smartlist_free(messages);
746 if (messages2) {
747 SMARTLIST_FOREACH(messages2, pending_log_message_t *, msg, {
748 pending_log_message_free(msg);
750 smartlist_free(messages2);
753 /* We _could_ destroy the log mutex here, but that would screw up any logs
754 * that happened between here and the end of execution. */
757 /** Remove and free the log entry <b>victim</b> from the linked-list
758 * logfiles (it is probably present, but it might not be due to thread
759 * racing issues). After this function is called, the caller shouldn't
760 * refer to <b>victim</b> anymore.
762 * Long-term, we need to do something about races in the log subsystem
763 * in general. See bug 222 for more details.
765 static void
766 delete_log(logfile_t *victim)
768 logfile_t *tmpl;
769 if (victim == logfiles)
770 logfiles = victim->next;
771 else {
772 for (tmpl = logfiles; tmpl && tmpl->next != victim; tmpl=tmpl->next) ;
773 // tor_assert(tmpl);
774 // tor_assert(tmpl->next == victim);
775 if (!tmpl)
776 return;
777 tmpl->next = victim->next;
779 log_free(victim);
782 /** Helper: release system resources (but not memory) held by a single
783 * logfile_t. */
784 static void
785 close_log(logfile_t *victim)
787 if (victim->needs_close && victim->fd >= 0) {
788 close(victim->fd);
789 victim->fd = -1;
790 } else if (victim->is_syslog) {
791 #ifdef HAVE_SYSLOG_H
792 if (--syslog_count == 0) {
793 /* There are no other syslogs; close the logging facility. */
794 closelog();
796 #endif
800 /** Adjust a log severity configuration in <b>severity_out</b> to contain
801 * every domain between <b>loglevelMin</b> and <b>loglevelMax</b>, inclusive.
803 void
804 set_log_severity_config(int loglevelMin, int loglevelMax,
805 log_severity_list_t *severity_out)
807 int i;
808 tor_assert(loglevelMin >= loglevelMax);
809 tor_assert(loglevelMin >= LOG_ERR && loglevelMin <= LOG_DEBUG);
810 tor_assert(loglevelMax >= LOG_ERR && loglevelMax <= LOG_DEBUG);
811 memset(severity_out, 0, sizeof(log_severity_list_t));
812 for (i = loglevelMin; i >= loglevelMax; --i) {
813 severity_out->masks[SEVERITY_MASK_IDX(i)] = ~0u;
817 /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
818 * to <b>fd</b>. Copies <b>severity</b>. Helper: does no locking. */
819 static void
820 add_stream_log_impl(const log_severity_list_t *severity,
821 const char *name, int fd)
823 logfile_t *lf;
824 lf = tor_malloc_zero(sizeof(logfile_t));
825 lf->fd = fd;
826 lf->filename = tor_strdup(name);
827 lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
828 lf->next = logfiles;
830 logfiles = lf;
831 log_global_min_severity_ = get_min_log_level();
834 /** Add a log handler named <b>name</b> to send all messages in <b>severity</b>
835 * to <b>fd</b>. Steals a reference to <b>severity</b>; the caller must
836 * not use it after calling this function. */
837 void
838 add_stream_log(const log_severity_list_t *severity, const char *name, int fd)
840 LOCK_LOGS();
841 add_stream_log_impl(severity, name, fd);
842 UNLOCK_LOGS();
845 /** Initialize the global logging facility */
846 void
847 init_logging(int disable_startup_queue)
849 if (!log_mutex_initialized) {
850 tor_mutex_init(&log_mutex);
851 log_mutex_initialized = 1;
853 #ifdef __GNUC__
854 if (strchr(__PRETTY_FUNCTION__, '(')) {
855 pretty_fn_has_parens = 1;
857 #endif
858 if (pending_cb_messages == NULL)
859 pending_cb_messages = smartlist_new();
860 if (disable_startup_queue)
861 queue_startup_messages = 0;
862 if (pending_startup_messages == NULL && queue_startup_messages) {
863 pending_startup_messages = smartlist_new();
867 /** Set whether we report logging domains as a part of our log messages.
869 void
870 logs_set_domain_logging(int enabled)
872 LOCK_LOGS();
873 log_domains_are_logged = enabled;
874 UNLOCK_LOGS();
877 /** Add a log handler to receive messages during startup (before the real
878 * logs are initialized).
880 void
881 add_temp_log(int min_severity)
883 log_severity_list_t *s = tor_malloc_zero(sizeof(log_severity_list_t));
884 set_log_severity_config(min_severity, LOG_ERR, s);
885 LOCK_LOGS();
886 add_stream_log_impl(s, "<temp>", fileno(stdout));
887 tor_free(s);
888 logfiles->is_temporary = 1;
889 UNLOCK_LOGS();
893 * Add a log handler to send messages in <b>severity</b>
894 * to the function <b>cb</b>.
897 add_callback_log(const log_severity_list_t *severity, log_callback cb)
899 logfile_t *lf;
900 lf = tor_malloc_zero(sizeof(logfile_t));
901 lf->fd = -1;
902 lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
903 lf->filename = tor_strdup("<callback>");
904 lf->callback = cb;
905 lf->next = logfiles;
907 LOCK_LOGS();
908 logfiles = lf;
909 log_global_min_severity_ = get_min_log_level();
910 UNLOCK_LOGS();
911 return 0;
914 /** Adjust the configured severity of any logs whose callback function is
915 * <b>cb</b>. */
916 void
917 change_callback_log_severity(int loglevelMin, int loglevelMax,
918 log_callback cb)
920 logfile_t *lf;
921 log_severity_list_t severities;
922 set_log_severity_config(loglevelMin, loglevelMax, &severities);
923 LOCK_LOGS();
924 for (lf = logfiles; lf; lf = lf->next) {
925 if (lf->callback == cb) {
926 memcpy(lf->severities, &severities, sizeof(severities));
929 log_global_min_severity_ = get_min_log_level();
930 UNLOCK_LOGS();
933 /** If there are any log messages that were generated with LD_NOCB waiting to
934 * be sent to callback-based loggers, send them now. */
935 void
936 flush_pending_log_callbacks(void)
938 logfile_t *lf;
939 smartlist_t *messages, *messages_tmp;
941 LOCK_LOGS();
942 if (0 == smartlist_len(pending_cb_messages)) {
943 UNLOCK_LOGS();
944 return;
947 messages = pending_cb_messages;
948 pending_cb_messages = smartlist_new();
949 do {
950 SMARTLIST_FOREACH_BEGIN(messages, pending_log_message_t *, msg) {
951 const int severity = msg->severity;
952 const int domain = msg->domain;
953 for (lf = logfiles; lf; lf = lf->next) {
954 if (! lf->callback || lf->seems_dead ||
955 ! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
956 continue;
958 lf->callback(severity, domain, msg->msg);
960 pending_log_message_free(msg);
961 } SMARTLIST_FOREACH_END(msg);
962 smartlist_clear(messages);
964 messages_tmp = pending_cb_messages;
965 pending_cb_messages = messages;
966 messages = messages_tmp;
967 } while (smartlist_len(messages));
969 smartlist_free(messages);
971 UNLOCK_LOGS();
974 /** Flush all the messages we stored from startup while waiting for log
975 * initialization.
977 void
978 flush_log_messages_from_startup(void)
980 logfile_t *lf;
982 LOCK_LOGS();
983 queue_startup_messages = 0;
984 pending_startup_messages_len = 0;
985 if (! pending_startup_messages)
986 goto out;
988 SMARTLIST_FOREACH_BEGIN(pending_startup_messages, pending_log_message_t *,
989 msg) {
990 int callbacks_deferred = 0;
991 for (lf = logfiles; lf; lf = lf->next) {
992 if (! logfile_wants_message(lf, msg->severity, msg->domain))
993 continue;
995 /* We configure a temporary startup log that goes to stdout, so we
996 * shouldn't replay to stdout/stderr*/
997 if (lf->fd == STDOUT_FILENO || lf->fd == STDERR_FILENO) {
998 continue;
1001 logfile_deliver(lf, msg->fullmsg, strlen(msg->fullmsg), msg->msg,
1002 msg->domain, msg->severity, &callbacks_deferred);
1004 pending_log_message_free(msg);
1005 } SMARTLIST_FOREACH_END(msg);
1006 smartlist_free(pending_startup_messages);
1007 pending_startup_messages = NULL;
1009 out:
1010 UNLOCK_LOGS();
1013 /** Close any log handlers added by add_temp_log() or marked by
1014 * mark_logs_temp(). */
1015 void
1016 close_temp_logs(void)
1018 logfile_t *lf, **p;
1020 LOCK_LOGS();
1021 for (p = &logfiles; *p; ) {
1022 if ((*p)->is_temporary) {
1023 lf = *p;
1024 /* we use *p here to handle the edge case of the head of the list */
1025 *p = (*p)->next;
1026 close_log(lf);
1027 log_free(lf);
1028 } else {
1029 p = &((*p)->next);
1033 log_global_min_severity_ = get_min_log_level();
1034 UNLOCK_LOGS();
1037 /** Make all currently temporary logs (set to be closed by close_temp_logs)
1038 * live again, and close all non-temporary logs. */
1039 void
1040 rollback_log_changes(void)
1042 logfile_t *lf;
1043 LOCK_LOGS();
1044 for (lf = logfiles; lf; lf = lf->next)
1045 lf->is_temporary = ! lf->is_temporary;
1046 UNLOCK_LOGS();
1047 close_temp_logs();
1050 /** Configure all log handles to be closed by close_temp_logs(). */
1051 void
1052 mark_logs_temp(void)
1054 logfile_t *lf;
1055 LOCK_LOGS();
1056 for (lf = logfiles; lf; lf = lf->next)
1057 lf->is_temporary = 1;
1058 UNLOCK_LOGS();
1062 * Add a log handler to send messages to <b>filename</b>. If opening the
1063 * logfile fails, -1 is returned and errno is set appropriately (by open(2)).
1066 add_file_log(const log_severity_list_t *severity, const char *filename,
1067 const int truncate)
1069 int fd;
1070 logfile_t *lf;
1072 int open_flags = O_WRONLY|O_CREAT;
1073 open_flags |= truncate ? O_TRUNC : O_APPEND;
1075 fd = tor_open_cloexec(filename, open_flags, 0644);
1076 if (fd<0)
1077 return -1;
1078 if (tor_fd_seekend(fd)<0) {
1079 close(fd);
1080 return -1;
1083 LOCK_LOGS();
1084 add_stream_log_impl(severity, filename, fd);
1085 logfiles->needs_close = 1;
1086 lf = logfiles;
1087 log_global_min_severity_ = get_min_log_level();
1089 if (log_tor_version(lf, 0) < 0) {
1090 delete_log(lf);
1092 UNLOCK_LOGS();
1094 return 0;
1097 #ifdef HAVE_SYSLOG_H
1099 * Add a log handler to send messages to they system log facility.
1101 * If this is the first log handler, opens syslog with ident Tor or
1102 * Tor-<syslog_identity_tag> if that is not NULL.
1105 add_syslog_log(const log_severity_list_t *severity,
1106 const char* syslog_identity_tag)
1108 logfile_t *lf;
1109 if (syslog_count++ == 0) {
1110 /* This is the first syslog. */
1111 static char buf[256];
1112 if (syslog_identity_tag) {
1113 tor_snprintf(buf, sizeof(buf), "Tor-%s", syslog_identity_tag);
1114 } else {
1115 tor_snprintf(buf, sizeof(buf), "Tor");
1117 openlog(buf, LOG_PID | LOG_NDELAY, LOGFACILITY);
1120 lf = tor_malloc_zero(sizeof(logfile_t));
1121 lf->fd = -1;
1122 lf->severities = tor_memdup(severity, sizeof(log_severity_list_t));
1123 lf->filename = tor_strdup("<syslog>");
1124 lf->is_syslog = 1;
1126 LOCK_LOGS();
1127 lf->next = logfiles;
1128 logfiles = lf;
1129 log_global_min_severity_ = get_min_log_level();
1130 UNLOCK_LOGS();
1131 return 0;
1133 #endif
1135 /** If <b>level</b> is a valid log severity, return the corresponding
1136 * numeric value. Otherwise, return -1. */
1138 parse_log_level(const char *level)
1140 if (!strcasecmp(level, "err"))
1141 return LOG_ERR;
1142 if (!strcasecmp(level, "warn"))
1143 return LOG_WARN;
1144 if (!strcasecmp(level, "notice"))
1145 return LOG_NOTICE;
1146 if (!strcasecmp(level, "info"))
1147 return LOG_INFO;
1148 if (!strcasecmp(level, "debug"))
1149 return LOG_DEBUG;
1150 return -1;
1153 /** Return the string equivalent of a given log level. */
1154 const char *
1155 log_level_to_string(int level)
1157 return sev_to_string(level);
1160 /** NULL-terminated array of names for log domains such that domain_list[dom]
1161 * is a description of <b>dom</b>. */
1162 static const char *domain_list[] = {
1163 "GENERAL", "CRYPTO", "NET", "CONFIG", "FS", "PROTOCOL", "MM",
1164 "HTTP", "APP", "CONTROL", "CIRC", "REND", "BUG", "DIR", "DIRSERV",
1165 "OR", "EDGE", "ACCT", "HIST", "HANDSHAKE", "HEARTBEAT", "CHANNEL",
1166 "SCHED", NULL
1169 /** Return a bitmask for the log domain for which <b>domain</b> is the name,
1170 * or 0 if there is no such name. */
1171 static log_domain_mask_t
1172 parse_log_domain(const char *domain)
1174 int i;
1175 for (i=0; domain_list[i]; ++i) {
1176 if (!strcasecmp(domain, domain_list[i]))
1177 return (1u<<i);
1179 return 0;
1182 /** Translate a bitmask of log domains to a string. */
1183 static char *
1184 domain_to_string(log_domain_mask_t domain, char *buf, size_t buflen)
1186 char *cp = buf;
1187 char *eos = buf+buflen;
1189 buf[0] = '\0';
1190 if (! domain)
1191 return buf;
1192 while (1) {
1193 const char *d;
1194 int bit = tor_log2(domain);
1195 size_t n;
1196 if ((unsigned)bit >= ARRAY_LENGTH(domain_list)-1 ||
1197 bit >= N_LOGGING_DOMAINS) {
1198 tor_snprintf(buf, buflen, "<BUG:Unknown domain %lx>", (long)domain);
1199 return buf+strlen(buf);
1201 d = domain_list[bit];
1202 n = strlcpy(cp, d, eos-cp);
1203 if (n >= buflen) {
1204 tor_snprintf(buf, buflen, "<BUG:Truncating domain %lx>", (long)domain);
1205 return buf+strlen(buf);
1207 cp += n;
1208 domain &= ~(1<<bit);
1210 if (domain == 0 || (eos-cp) < 2)
1211 return cp;
1213 memcpy(cp, ",", 2); /*Nul-terminated ,"*/
1214 cp++;
1218 /** Parse a log severity pattern in *<b>cfg_ptr</b>. Advance cfg_ptr after
1219 * the end of the severityPattern. Set the value of <b>severity_out</b> to
1220 * the parsed pattern. Return 0 on success, -1 on failure.
1222 * The syntax for a SeverityPattern is:
1223 * <pre>
1224 * SeverityPattern = *(DomainSeverity SP)* DomainSeverity
1225 * DomainSeverity = (DomainList SP)? SeverityRange
1226 * SeverityRange = MinSeverity ("-" MaxSeverity )?
1227 * DomainList = "[" (SP? DomainSpec SP? ",") SP? DomainSpec "]"
1228 * DomainSpec = "*" | Domain | "~" Domain
1229 * </pre>
1230 * A missing MaxSeverity defaults to ERR. Severities and domains are
1231 * case-insensitive. "~" indicates negation for a domain; negation happens
1232 * last inside a DomainList. Only one SeverityRange without a DomainList is
1233 * allowed per line.
1236 parse_log_severity_config(const char **cfg_ptr,
1237 log_severity_list_t *severity_out)
1239 const char *cfg = *cfg_ptr;
1240 int got_anything = 0;
1241 int got_an_unqualified_range = 0;
1242 memset(severity_out, 0, sizeof(*severity_out));
1244 cfg = eat_whitespace(cfg);
1245 while (*cfg) {
1246 const char *dash, *space;
1247 char *sev_lo, *sev_hi;
1248 int low, high, i;
1249 log_domain_mask_t domains = ~0u;
1251 if (*cfg == '[') {
1252 int err = 0;
1253 char *domains_str;
1254 smartlist_t *domains_list;
1255 log_domain_mask_t neg_domains = 0;
1256 const char *closebracket = strchr(cfg, ']');
1257 if (!closebracket)
1258 return -1;
1259 domains = 0;
1260 domains_str = tor_strndup(cfg+1, closebracket-cfg-1);
1261 domains_list = smartlist_new();
1262 smartlist_split_string(domains_list, domains_str, ",", SPLIT_SKIP_SPACE,
1263 -1);
1264 tor_free(domains_str);
1265 SMARTLIST_FOREACH_BEGIN(domains_list, const char *, domain) {
1266 if (!strcmp(domain, "*")) {
1267 domains = ~0u;
1268 } else {
1269 int d;
1270 int negate=0;
1271 if (*domain == '~') {
1272 negate = 1;
1273 ++domain;
1275 d = parse_log_domain(domain);
1276 if (!d) {
1277 log_warn(LD_CONFIG, "No such logging domain as %s", domain);
1278 err = 1;
1279 } else {
1280 if (negate)
1281 neg_domains |= d;
1282 else
1283 domains |= d;
1286 } SMARTLIST_FOREACH_END(domain);
1287 SMARTLIST_FOREACH(domains_list, char *, d, tor_free(d));
1288 smartlist_free(domains_list);
1289 if (err)
1290 return -1;
1291 if (domains == 0 && neg_domains)
1292 domains = ~neg_domains;
1293 else
1294 domains &= ~neg_domains;
1295 cfg = eat_whitespace(closebracket+1);
1296 } else {
1297 ++got_an_unqualified_range;
1299 if (!strcasecmpstart(cfg, "file") ||
1300 !strcasecmpstart(cfg, "stderr") ||
1301 !strcasecmpstart(cfg, "stdout") ||
1302 !strcasecmpstart(cfg, "syslog")) {
1303 goto done;
1305 if (got_an_unqualified_range > 1)
1306 return -1;
1308 space = strchr(cfg, ' ');
1309 dash = strchr(cfg, '-');
1310 if (!space)
1311 space = strchr(cfg, '\0');
1312 if (dash && dash < space) {
1313 sev_lo = tor_strndup(cfg, dash-cfg);
1314 sev_hi = tor_strndup(dash+1, space-(dash+1));
1315 } else {
1316 sev_lo = tor_strndup(cfg, space-cfg);
1317 sev_hi = tor_strdup("ERR");
1319 low = parse_log_level(sev_lo);
1320 high = parse_log_level(sev_hi);
1321 tor_free(sev_lo);
1322 tor_free(sev_hi);
1323 if (low == -1)
1324 return -1;
1325 if (high == -1)
1326 return -1;
1328 got_anything = 1;
1329 for (i=low; i >= high; --i)
1330 severity_out->masks[SEVERITY_MASK_IDX(i)] |= domains;
1332 cfg = eat_whitespace(space);
1335 done:
1336 *cfg_ptr = cfg;
1337 return got_anything ? 0 : -1;
1340 /** Return the least severe log level that any current log is interested in. */
1342 get_min_log_level(void)
1344 logfile_t *lf;
1345 int i;
1346 int min = LOG_ERR;
1347 for (lf = logfiles; lf; lf = lf->next) {
1348 for (i = LOG_DEBUG; i > min; --i)
1349 if (lf->severities->masks[SEVERITY_MASK_IDX(i)])
1350 min = i;
1352 return min;
1355 /** Switch all logs to output at most verbose level. */
1356 void
1357 switch_logs_debug(void)
1359 logfile_t *lf;
1360 int i;
1361 LOCK_LOGS();
1362 for (lf = logfiles; lf; lf=lf->next) {
1363 for (i = LOG_DEBUG; i >= LOG_ERR; --i)
1364 lf->severities->masks[SEVERITY_MASK_IDX(i)] = ~0u;
1366 log_global_min_severity_ = get_min_log_level();
1367 UNLOCK_LOGS();
1370 /** Truncate all the log files. */
1371 void
1372 truncate_logs(void)
1374 logfile_t *lf;
1375 for (lf = logfiles; lf; lf = lf->next) {
1376 if (lf->fd >= 0) {
1377 tor_ftruncate(lf->fd);