diff options
author | Nick Mathewson <nickm@torproject.org> | 2018-06-22 10:30:45 -0400 |
---|---|---|
committer | Nick Mathewson <nickm@torproject.org> | 2018-06-22 10:31:51 -0400 |
commit | 97b15a1d7c51764888d2172711e3f3a71fb01916 (patch) | |
tree | 2d7be35820f099e0d7da91f0e4eb49baa99476e4 /src/common/log.c | |
parent | 2cf033f238c111bef62552da16117568435d3a18 (diff) | |
download | tor-97b15a1d7c51764888d2172711e3f3a71fb01916.tar.gz tor-97b15a1d7c51764888d2172711e3f3a71fb01916.zip |
Extract the locking and logging code
The locking code gets its own module, since it's more fundamental
than the higher-level locking code.
Extracting the logging code was the whole point here. :)
Diffstat (limited to 'src/common/log.c')
-rw-r--r-- | src/common/log.c | 1480 |
1 files changed, 0 insertions, 1480 deletions
diff --git a/src/common/log.c b/src/common/log.c deleted file mode 100644 index bb4b1e1215..0000000000 --- a/src/common/log.c +++ /dev/null @@ -1,1480 +0,0 @@ -/* Copyright (c) 2001, Matej Pfajfar. - * Copyright (c) 2001-2004, Roger Dingledine. - * Copyright (c) 2004-2006, Roger Dingledine, Nick Mathewson. - * Copyright (c) 2007-2018, The Tor Project, Inc. */ -/* See LICENSE for licensing information */ - -/** - * \file log.c - * \brief Functions to send messages to log files or the console. - **/ - -#include "orconfig.h" -#include <stdarg.h> -// #include <stdio.h> -#include <stdlib.h> -#include <string.h> -#ifdef HAVE_SYS_TIME_H -#include <sys/time.h> -#endif -#ifdef HAVE_TIME_H -#include <time.h> -#endif -#ifdef HAVE_UNISTD_H -#include <unistd.h> -#endif -#ifdef HAVE_SYS_TYPES_H -#include <sys/types.h> -#endif -#ifdef HAVE_FCNTL_H -#include <fcntl.h> -#endif -#include "common/util.h" -#define LOG_PRIVATE -#include "common/torlog.h" -#include "lib/container/smartlist.h" -#include "lib/err/torerr.h" -#include "lib/malloc/util_malloc.h" -#include "lib/wallclock/tor_gettimeofday.h" -#include "lib/wallclock/approx_time.h" - -#ifdef HAVE_ANDROID_LOG_H -#include <android/log.h> -#endif // HAVE_ANDROID_LOG_H. - -/** Given a severity, yields an index into log_severity_list_t.masks to use - * for that severity. */ -#define SEVERITY_MASK_IDX(sev) ((sev) - LOG_ERR) - -/** @{ */ -/** The string we stick at the end of a log message when it is too long, - * and its length. */ -#define TRUNCATED_STR "[...truncated]" -#define TRUNCATED_STR_LEN 14 -/** @} */ - -/** Defining compile-time constants for Tor log levels (used by the Rust - * log wrapper at src/rust/tor_log) */ -const int LOG_WARN_ = LOG_WARN; -const int LOG_NOTICE_ = LOG_NOTICE; -const log_domain_mask_t LD_GENERAL_ = LD_GENERAL; -const log_domain_mask_t LD_NET_ = LD_NET; - -/** Information for a single logfile; only used in log.c */ -typedef struct logfile_t { - struct logfile_t *next; /**< Next logfile_t in the linked list. */ - char *filename; /**< Filename to open. */ - int fd; /**< fd to receive log messages, or -1 for none. */ - int seems_dead; /**< Boolean: true if the stream seems to be kaput. */ - int needs_close; /**< Boolean: true if the stream gets closed on shutdown. */ - int is_temporary; /**< Boolean: close after initializing logging subsystem.*/ - int is_syslog; /**< Boolean: send messages to syslog. */ - int is_android; /**< Boolean: send messages to Android's log subsystem. */ - char *android_tag; /**< Identity Tag used in Android's log subsystem. */ - log_callback callback; /**< If not NULL, send messages to this function. */ - log_severity_list_t *severities; /**< Which severity of messages should we - * log for each log domain? */ -} logfile_t; - -static void log_free_(logfile_t *victim); -#define log_free(lg) \ - FREE_AND_NULL(logfile_t, log_free_, (lg)) - -/** Helper: map a log severity to descriptive string. */ -static inline const char * -sev_to_string(int severity) -{ - switch (severity) { - case LOG_DEBUG: return "debug"; - case LOG_INFO: return "info"; - case LOG_NOTICE: return "notice"; - case LOG_WARN: return "warn"; - case LOG_ERR: return "err"; - default: /* Call assert, not tor_assert, since tor_assert - * calls log on failure. */ - raw_assert_unreached(); return "UNKNOWN"; // LCOV_EXCL_LINE - } -} - -/** Helper: decide whether to include the function name in the log message. */ -static inline int -should_log_function_name(log_domain_mask_t domain, int severity) -{ - switch (severity) { - case LOG_DEBUG: - case LOG_INFO: - /* All debugging messages occur in interesting places. */ - return (domain & LD_NOFUNCNAME) == 0; - case LOG_NOTICE: - case LOG_WARN: - case LOG_ERR: - /* We care about places where bugs occur. */ - return (domain & (LD_BUG|LD_NOFUNCNAME)) == LD_BUG; - default: - /* Call assert, not tor_assert, since tor_assert calls log on failure. */ - raw_assert(0); return 0; // LCOV_EXCL_LINE - } -} - -#ifdef HAVE_ANDROID_LOG_H -/** Helper function to convert Tor's log severity into the matching - * Android log priority. - */ -static int -severity_to_android_log_priority(int severity) -{ - switch (severity) { - case LOG_DEBUG: - return ANDROID_LOG_VERBOSE; - case LOG_INFO: - return ANDROID_LOG_DEBUG; - case LOG_NOTICE: - return ANDROID_LOG_INFO; - case LOG_WARN: - return ANDROID_LOG_WARN; - case LOG_ERR: - return ANDROID_LOG_ERROR; - default: - // LCOV_EXCL_START - raw_assert(0); - return 0; - // LCOV_EXCL_STOP - } -} -#endif // HAVE_ANDROID_LOG_H. - -/** A mutex to guard changes to logfiles and logging. */ -static tor_mutex_t log_mutex; -/** True iff we have initialized log_mutex */ -static int log_mutex_initialized = 0; - -/** Linked list of logfile_t. */ -static logfile_t *logfiles = NULL; -/** Boolean: do we report logging domains? */ -static int log_domains_are_logged = 0; - -#ifdef HAVE_SYSLOG_H -/** The number of open syslog log handlers that we have. When this reaches 0, - * we can close our connection to the syslog facility. */ -static int syslog_count = 0; -#endif - -/** Represents a log message that we are going to send to callback-driven - * loggers once we can do so in a non-reentrant way. */ -typedef struct pending_log_message_t { - int severity; /**< The severity of the message */ - log_domain_mask_t domain; /**< The domain of the message */ - char *fullmsg; /**< The message, with all decorations */ - char *msg; /**< The content of the message */ -} pending_log_message_t; - -/** Log messages waiting to be replayed onto callback-based logs */ -static smartlist_t *pending_cb_messages = NULL; - -/** Callback to invoke when pending_cb_messages becomes nonempty. */ -static pending_callback_callback pending_cb_cb = NULL; - -/** Log messages waiting to be replayed once the logging system is initialized. - */ -static smartlist_t *pending_startup_messages = NULL; - -/** Number of bytes of messages queued in pending_startup_messages. (This is - * the length of the messages, not the number of bytes used to store - * them.) */ -static size_t pending_startup_messages_len; - -/** True iff we should store messages while waiting for the logs to get - * configured. */ -static int queue_startup_messages = 1; - -/** True iff __PRETTY_FUNCTION__ includes parenthesized arguments. */ -static int pretty_fn_has_parens = 0; - -/** Don't store more than this many bytes of messages while waiting for the - * logs to get configured. */ -#define MAX_STARTUP_MSG_LEN (1<<16) - -/** Lock the log_mutex to prevent others from changing the logfile_t list */ -#define LOCK_LOGS() STMT_BEGIN \ - tor_assert(log_mutex_initialized); \ - tor_mutex_acquire(&log_mutex); \ - STMT_END -/** Unlock the log_mutex */ -#define UNLOCK_LOGS() STMT_BEGIN \ - tor_assert(log_mutex_initialized); \ - tor_mutex_release(&log_mutex); \ - STMT_END - -/** What's the lowest log level anybody cares about? Checking this lets us - * bail out early from log_debug if we aren't debugging. */ -int log_global_min_severity_ = LOG_NOTICE; - -static void delete_log(logfile_t *victim); -static void close_log(logfile_t *victim); - -static char *domain_to_string(log_domain_mask_t domain, - char *buf, size_t buflen); -static inline char *format_msg(char *buf, size_t buf_len, - log_domain_mask_t domain, int severity, const char *funcname, - const char *suffix, - const char *format, va_list ap, size_t *msg_len_out) - CHECK_PRINTF(7,0); - -/** Name of the application: used to generate the message we write at the - * start of each new log. */ -static char *appname = NULL; - -/** Set the "application name" for the logs to <b>name</b>: we'll use this - * name in the message we write when starting up, and at the start of each new - * log. - * - * Tor uses this string to write the version number to the log file. */ -void -log_set_application_name(const char *name) -{ - tor_free(appname); - appname = name ? tor_strdup(name) : NULL; -} - -/** Return true if some of the running logs might be interested in a log - * message of the given severity in the given domains. If this function - * returns true, the log message might be ignored anyway, but if it returns - * false, it is definitely_ safe not to log the message. */ -int -log_message_is_interesting(int severity, log_domain_mask_t domain) -{ - (void) domain; - return (severity <= log_global_min_severity_); -} - -/** - * As tor_log, but takes an optional function name, and does not treat its - * <b>string</b> as a printf format. - * - * For use by Rust integration. - */ -void -tor_log_string(int severity, log_domain_mask_t domain, - const char *function, const char *string) -{ - log_fn_(severity, domain, function, "%s", string); -} - -/** Log time granularity in milliseconds. */ -static int log_time_granularity = 1; - -/** Define log time granularity for all logs to be <b>granularity_msec</b> - * milliseconds. */ -void -set_log_time_granularity(int granularity_msec) -{ - log_time_granularity = granularity_msec; - tor_log_sigsafe_err_set_granularity(granularity_msec); -} - -/** Helper: Write the standard prefix for log lines to a - * <b>buf_len</b> character buffer in <b>buf</b>. - */ -static inline size_t -log_prefix_(char *buf, size_t buf_len, int severity) -{ - time_t t; - struct timeval now; - struct tm tm; - size_t n; - int r, ms; - - tor_gettimeofday(&now); - t = (time_t)now.tv_sec; - ms = (int)now.tv_usec / 1000; - if (log_time_granularity >= 1000) { - t -= t % (log_time_granularity / 1000); - ms = 0; - } else { - ms -= ((int)now.tv_usec / 1000) % log_time_granularity; - } - - n = strftime(buf, buf_len, "%b %d %H:%M:%S", tor_localtime_r(&t, &tm)); - r = tor_snprintf(buf+n, buf_len-n, ".%.3i [%s] ", ms, - sev_to_string(severity)); - - if (r<0) - return buf_len-1; - else - return n+r; -} - -/** If lf refers to an actual file that we have just opened, and the file - * contains no data, log an "opening new logfile" message at the top. - * - * Return -1 if the log is broken and needs to be deleted, else return 0. - */ -static int -log_tor_version(logfile_t *lf, int reset) -{ - char buf[256]; - size_t n; - int is_new; - - if (!lf->needs_close) - /* If it doesn't get closed, it isn't really a file. */ - return 0; - if (lf->is_temporary) - /* If it's temporary, it isn't really a file. */ - return 0; - - is_new = lf->fd >= 0 && tor_fd_getpos(lf->fd) == 0; - - if (reset && !is_new) - /* We are resetting, but we aren't at the start of the file; no - * need to log again. */ - return 0; - n = log_prefix_(buf, sizeof(buf), LOG_NOTICE); - if (appname) { - tor_snprintf(buf+n, sizeof(buf)-n, - "%s opening %slog file.\n", appname, is_new?"new ":""); - } else { - tor_snprintf(buf+n, sizeof(buf)-n, - "Tor %s opening %slog file.\n", VERSION, is_new?"new ":""); - } - if (write_all(lf->fd, buf, strlen(buf), 0) < 0) /* error */ - return -1; /* failed */ - return 0; -} - -static const char bug_suffix[] = " (on Tor " VERSION -#ifndef _MSC_VER - " " -#include "micro-revision.i" -#endif - ")"; - -/** Helper: Format a log message into a fixed-sized buffer. (This is - * factored out of <b>logv</b> so that we never format a message more - * than once.) Return a pointer to the first character of the message - * portion of the formatted string. - */ -static inline char * -format_msg(char *buf, size_t buf_len, - log_domain_mask_t domain, int severity, const char *funcname, - const char *suffix, - const char *format, va_list ap, size_t *msg_len_out) -{ - size_t n; - int r; - char *end_of_prefix; - char *buf_end; - - raw_assert(buf_len >= 16); /* prevent integer underflow and stupidity */ - buf_len -= 2; /* subtract 2 characters so we have room for \n\0 */ - buf_end = buf+buf_len; /* point *after* the last char we can write to */ - - n = log_prefix_(buf, buf_len, severity); - end_of_prefix = buf+n; - - if (log_domains_are_logged) { - char *cp = buf+n; - if (cp == buf_end) goto format_msg_no_room_for_domains; - *cp++ = '{'; - if (cp == buf_end) goto format_msg_no_room_for_domains; - cp = domain_to_string(domain, cp, (buf+buf_len-cp)); - if (cp == buf_end) goto format_msg_no_room_for_domains; - *cp++ = '}'; - if (cp == buf_end) goto format_msg_no_room_for_domains; - *cp++ = ' '; - if (cp == buf_end) goto format_msg_no_room_for_domains; - end_of_prefix = cp; - n = cp-buf; - format_msg_no_room_for_domains: - /* This will leave end_of_prefix and n unchanged, and thus cause - * whatever log domain string we had written to be clobbered. */ - ; - } - - if (funcname && should_log_function_name(domain, severity)) { - r = tor_snprintf(buf+n, buf_len-n, - pretty_fn_has_parens ? "%s: " : "%s(): ", - funcname); - if (r<0) - n = strlen(buf); - else - n += r; - } - - if (domain == LD_BUG && buf_len-n > 6) { - memcpy(buf+n, "Bug: ", 6); - n += 5; - } - - r = tor_vsnprintf(buf+n,buf_len-n,format,ap); - if (r < 0) { - /* The message was too long; overwrite the end of the buffer with - * "[...truncated]" */ - if (buf_len >= TRUNCATED_STR_LEN) { - size_t offset = buf_len-TRUNCATED_STR_LEN; - /* We have an extra 2 characters after buf_len to hold the \n\0, - * so it's safe to add 1 to the size here. */ - strlcpy(buf+offset, TRUNCATED_STR, buf_len-offset+1); - } - /* Set 'n' to the end of the buffer, where we'll be writing \n\0. - * Since we already subtracted 2 from buf_len, this is safe.*/ - n = buf_len; - } else { - n += r; - if (suffix) { - size_t suffix_len = strlen(suffix); - if (buf_len-n >= suffix_len) { - memcpy(buf+n, suffix, suffix_len); - n += suffix_len; - } - } - } - - if (domain == LD_BUG && - buf_len - n > strlen(bug_suffix)+1) { - memcpy(buf+n, bug_suffix, strlen(bug_suffix)); - n += strlen(bug_suffix); - } - - buf[n]='\n'; - buf[n+1]='\0'; - *msg_len_out = n+1; - return end_of_prefix; -} - -/* Create a new pending_log_message_t with appropriate values */ -static pending_log_message_t * -pending_log_message_new(int severity, log_domain_mask_t domain, - const char *fullmsg, const char *shortmsg) -{ - pending_log_message_t *m = tor_malloc(sizeof(pending_log_message_t)); - m->severity = severity; - m->domain = domain; - m->fullmsg = fullmsg ? tor_strdup(fullmsg) : NULL; - m->msg = tor_strdup(shortmsg); - return m; -} - -#define pending_log_message_free(msg) \ - FREE_AND_NULL(pending_log_message_t, pending_log_message_free_, (msg)) - -/** Release all storage held by <b>msg</b>. */ -static void -pending_log_message_free_(pending_log_message_t *msg) -{ - if (!msg) - return; - tor_free(msg->msg); - tor_free(msg->fullmsg); - tor_free(msg); -} - -/** Helper function: returns true iff the log file, given in <b>lf</b>, is - * handled externally via the system log API, the Android logging API, or is an - * external callback function. */ -static inline int -logfile_is_external(const logfile_t *lf) -{ - raw_assert(lf); - return lf->is_syslog || lf->is_android || lf->callback; -} - -/** Return true iff <b>lf</b> would like to receive a message with the - * specified <b>severity</b> in the specified <b>domain</b>. - */ -static inline int -logfile_wants_message(const logfile_t *lf, int severity, - log_domain_mask_t domain) -{ - if (! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) { - return 0; - } - if (! (lf->fd >= 0 || logfile_is_external(lf))) { - return 0; - } - if (lf->seems_dead) { - return 0; - } - - return 1; -} - -/** Send a message to <b>lf</b>. The full message, with time prefix and - * severity, is in <b>buf</b>. The message itself is in - * <b>msg_after_prefix</b>. If <b>callbacks_deferred</b> points to true, then - * we already deferred this message for pending callbacks and don't need to do - * it again. Otherwise, if we need to do it, do it, and set - * <b>callbacks_deferred</b> to 1. */ -static inline void -logfile_deliver(logfile_t *lf, const char *buf, size_t msg_len, - const char *msg_after_prefix, log_domain_mask_t domain, - int severity, int *callbacks_deferred) -{ - - if (lf->is_syslog) { -#ifdef HAVE_SYSLOG_H -#ifdef MAXLINE - /* Some syslog implementations have limits on the length of what you can - * pass them, and some very old ones do not detect overflow so well. - * Regrettably, they call their maximum line length MAXLINE. */ -#if MAXLINE < 64 -#warn "MAXLINE is a very low number; it might not be from syslog.h after all" -#endif - char *m = msg_after_prefix; - if (msg_len >= MAXLINE) - m = tor_strndup(msg_after_prefix, MAXLINE-1); - syslog(severity, "%s", m); - if (m != msg_after_prefix) { - tor_free(m); - } -#else /* !(defined(MAXLINE)) */ - /* We have syslog but not MAXLINE. That's promising! */ - syslog(severity, "%s", msg_after_prefix); -#endif /* defined(MAXLINE) */ -#endif /* defined(HAVE_SYSLOG_H) */ - } else if (lf->is_android) { -#ifdef HAVE_ANDROID_LOG_H - int priority = severity_to_android_log_priority(severity); - __android_log_write(priority, lf->android_tag, msg_after_prefix); -#endif // HAVE_ANDROID_LOG_H. - } else if (lf->callback) { - if (domain & LD_NOCB) { - if (!*callbacks_deferred && pending_cb_messages) { - smartlist_add(pending_cb_messages, - pending_log_message_new(severity,domain,NULL,msg_after_prefix)); - *callbacks_deferred = 1; - if (smartlist_len(pending_cb_messages) == 1 && pending_cb_cb) { - pending_cb_cb(); - } - } - } else { - lf->callback(severity, domain, msg_after_prefix); - } - } else { - if (write_all(lf->fd, buf, msg_len, 0) < 0) { /* error */ - /* don't log the error! mark this log entry to be blown away, and - * continue. */ - lf->seems_dead = 1; - } - } -} - -/** Helper: sends a message to the appropriate logfiles, at loglevel - * <b>severity</b>. If provided, <b>funcname</b> is prepended to the - * message. The actual message is derived as from tor_snprintf(format,ap). - */ -MOCK_IMPL(STATIC void, -logv,(int severity, log_domain_mask_t domain, const char *funcname, - const char *suffix, const char *format, va_list ap)) -{ - char buf[10240]; - size_t msg_len = 0; - int formatted = 0; - logfile_t *lf; - char *end_of_prefix=NULL; - int callbacks_deferred = 0; - - /* Call assert, not tor_assert, since tor_assert calls log on failure. */ - raw_assert(format); - /* check that severity is sane. Overrunning the masks array leads to - * interesting and hard to diagnose effects */ - raw_assert(severity >= LOG_ERR && severity <= LOG_DEBUG); - /* check that we've initialised the log mutex before we try to lock it */ - raw_assert(log_mutex_initialized); - LOCK_LOGS(); - - if ((! (domain & LD_NOCB)) && pending_cb_messages - && smartlist_len(pending_cb_messages)) - flush_pending_log_callbacks(); - - if (queue_startup_messages && - pending_startup_messages_len < MAX_STARTUP_MSG_LEN) { - end_of_prefix = - format_msg(buf, sizeof(buf), domain, severity, funcname, suffix, - format, ap, &msg_len); - formatted = 1; - - smartlist_add(pending_startup_messages, - pending_log_message_new(severity,domain,buf,end_of_prefix)); - pending_startup_messages_len += msg_len; - } - - for (lf = logfiles; lf; lf = lf->next) { - if (! logfile_wants_message(lf, severity, domain)) - continue; - - if (!formatted) { - end_of_prefix = - format_msg(buf, sizeof(buf), domain, severity, funcname, suffix, - format, ap, &msg_len); - formatted = 1; - } - - logfile_deliver(lf, buf, msg_len, end_of_prefix, domain, severity, - &callbacks_deferred); - } - UNLOCK_LOGS(); -} - -/** Output a message to the log. It gets logged to all logfiles that - * care about messages with <b>severity</b> in <b>domain</b>. The content - * is formatted printf-style based on <b>format</b> and extra arguments. - * */ -void -tor_log(int severity, log_domain_mask_t domain, const char *format, ...) -{ - va_list ap; - if (severity > log_global_min_severity_) - return; - va_start(ap,format); -#ifdef TOR_UNIT_TESTS - if (domain & LD_NO_MOCK) - logv__real(severity, domain, NULL, NULL, format, ap); - else -#endif - logv(severity, domain, NULL, NULL, format, ap); - va_end(ap); -} - -/** Helper function; return true iff the <b>n</b>-element array <b>array</b> - * contains <b>item</b>. */ -static int -int_array_contains(const int *array, int n, int item) -{ - int j; - for (j = 0; j < n; ++j) { - if (array[j] == item) - return 1; - } - return 0; -} - -/** Function to call whenever the list of logs changes to get ready to log - * from signal handlers. */ -void -tor_log_update_sigsafe_err_fds(void) -{ - const logfile_t *lf; - int found_real_stderr = 0; - - int fds[TOR_SIGSAFE_LOG_MAX_FDS]; - int n_fds; - - LOCK_LOGS(); - /* Reserve the first one for stderr. This is safe because when we daemonize, - * we dup2 /dev/null to stderr, */ - fds[0] = STDERR_FILENO; - n_fds = 1; - - for (lf = logfiles; lf; lf = lf->next) { - /* Don't try callback to the control port, or syslogs: We can't - * do them from a signal handler. Don't try stdout: we always do stderr. - */ - if (lf->is_temporary || logfile_is_external(lf) - || lf->seems_dead || lf->fd < 0) - continue; - if (lf->severities->masks[SEVERITY_MASK_IDX(LOG_ERR)] & - (LD_BUG|LD_GENERAL)) { - if (lf->fd == STDERR_FILENO) - found_real_stderr = 1; - /* Avoid duplicates */ - if (int_array_contains(fds, n_fds, lf->fd)) - continue; - fds[n_fds++] = lf->fd; - if (n_fds == TOR_SIGSAFE_LOG_MAX_FDS) - break; - } - } - - if (!found_real_stderr && - int_array_contains(fds, n_fds, STDOUT_FILENO)) { - /* Don't use a virtual stderr when we're also logging to stdout. */ - raw_assert(n_fds >= 2); /* Don't tor_assert inside log fns */ - fds[0] = fds[--n_fds]; - } - - UNLOCK_LOGS(); - - tor_log_set_sigsafe_err_fds(fds, n_fds); -} - -/** Add to <b>out</b> a copy of every currently configured log file name. Used - * to enable access to these filenames with the sandbox code. */ -void -tor_log_get_logfile_names(smartlist_t *out) -{ - logfile_t *lf; - tor_assert(out); - - LOCK_LOGS(); - - for (lf = logfiles; lf; lf = lf->next) { - if (lf->is_temporary || logfile_is_external(lf)) - continue; - if (lf->filename == NULL) - continue; - smartlist_add_strdup(out, lf->filename); - } - - UNLOCK_LOGS(); -} - -/** Implementation of the log_fn backend, used when we have - * variadic macros. All arguments are as for log_fn, except for - * <b>fn</b>, which is the name of the calling functions. */ -void -log_fn_(int severity, log_domain_mask_t domain, const char *fn, - const char *format, ...) -{ - va_list ap; - if (severity > log_global_min_severity_) - return; - va_start(ap,format); - logv(severity, domain, fn, NULL, format, ap); - va_end(ap); -} -void -log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain, - const char *fn, const char *format, ...) -{ - va_list ap; - char *m; - if (severity > log_global_min_severity_) - return; - m = rate_limit_log(ratelim, approx_time()); - if (m == NULL) - return; - va_start(ap, format); - logv(severity, domain, fn, m, format, ap); - va_end(ap); - tor_free(m); -} - -/** Free all storage held by <b>victim</b>. */ -static void -log_free_(logfile_t *victim) -{ - if (!victim) - return; - tor_free(victim->severities); - tor_free(victim->filename); - tor_free(victim->android_tag); - tor_free(victim); -} - -/** Close all open log files, and free other static memory. */ -void -logs_free_all(void) -{ - logfile_t *victim, *next; - smartlist_t *messages, *messages2; - LOCK_LOGS(); - next = logfiles; - logfiles = NULL; - messages = pending_cb_messages; - pending_cb_messages = NULL; - pending_cb_cb = NULL; - messages2 = pending_startup_messages; - pending_startup_messages = NULL; - UNLOCK_LOGS(); - while (next) { - victim = next; - next = next->next; - close_log(victim); - log_free(victim); - } - tor_free(appname); - - SMARTLIST_FOREACH(messages, pending_log_message_t *, msg, { - pending_log_message_free(msg); - }); - smartlist_free(messages); - - if (messages2) { - SMARTLIST_FOREACH(messages2, pending_log_message_t *, msg, { - pending_log_message_free(msg); - }); - smartlist_free(messages2); - } - - /* We _could_ destroy the log mutex here, but that would screw up any logs - * that happened between here and the end of execution. */ -} - -/** Remove and free the log entry <b>victim</b> from the linked-list - * logfiles (it is probably present, but it might not be due to thread - * racing issues). After this function is called, the caller shouldn't - * refer to <b>victim</b> anymore. - * - * Long-term, we need to do something about races in the log subsystem - * in general. See bug 222 for more details. - */ -static void -delete_log(logfile_t *victim) -{ - logfile_t *tmpl; - if (victim == logfiles) - logfiles = victim->next; - else { - for (tmpl = logfiles; tmpl && tmpl->next != victim; tmpl=tmpl->next) ; -// tor_assert(tmpl); -// tor_assert(tmpl->next == victim); - if (!tmpl) - return; - tmpl->next = victim->next; - } - log_free(victim); -} - -/** Helper: release system resources (but not memory) held by a single - * logfile_t. */ -static void -close_log(logfile_t *victim) -{ - if (victim->needs_close && victim->fd >= 0) { - close(victim->fd); - victim->fd = -1; - } else if (victim->is_syslog) { -#ifdef HAVE_SYSLOG_H - if (--syslog_count == 0) { - /* There are no other syslogs; close the logging facility. */ - closelog(); - } -#endif /* defined(HAVE_SYSLOG_H) */ - } -} - -/** Adjust a log severity configuration in <b>severity_out</b> to contain - * every domain between <b>loglevelMin</b> and <b>loglevelMax</b>, inclusive. - */ -void -set_log_severity_config(int loglevelMin, int loglevelMax, - log_severity_list_t *severity_out) -{ - int i; - tor_assert(loglevelMin >= loglevelMax); - tor_assert(loglevelMin >= LOG_ERR && loglevelMin <= LOG_DEBUG); - tor_assert(loglevelMax >= LOG_ERR && loglevelMax <= LOG_DEBUG); - memset(severity_out, 0, sizeof(log_severity_list_t)); - for (i = loglevelMin; i >= loglevelMax; --i) { - severity_out->masks[SEVERITY_MASK_IDX(i)] = ~0u; - } -} - -/** Add a log handler named <b>name</b> to send all messages in <b>severity</b> - * to <b>fd</b>. Copies <b>severity</b>. Helper: does no locking. */ -static void -add_stream_log_impl(const log_severity_list_t *severity, - const char *name, int fd) -{ - logfile_t *lf; - lf = tor_malloc_zero(sizeof(logfile_t)); - lf->fd = fd; - lf->filename = tor_strdup(name); - lf->severities = tor_memdup(severity, sizeof(log_severity_list_t)); - lf->next = logfiles; - - logfiles = lf; - log_global_min_severity_ = get_min_log_level(); -} - -/** Add a log handler named <b>name</b> to send all messages in <b>severity</b> - * to <b>fd</b>. Steals a reference to <b>severity</b>; the caller must - * not use it after calling this function. */ -void -add_stream_log(const log_severity_list_t *severity, const char *name, int fd) -{ - LOCK_LOGS(); - add_stream_log_impl(severity, name, fd); - UNLOCK_LOGS(); -} - -/** Initialize the global logging facility */ -void -init_logging(int disable_startup_queue) -{ - if (!log_mutex_initialized) { - tor_mutex_init(&log_mutex); - log_mutex_initialized = 1; - } -#ifdef __GNUC__ - if (strchr(__PRETTY_FUNCTION__, '(')) { - pretty_fn_has_parens = 1; - } -#endif - if (pending_cb_messages == NULL) - pending_cb_messages = smartlist_new(); - if (disable_startup_queue) - queue_startup_messages = 0; - if (pending_startup_messages == NULL && queue_startup_messages) { - pending_startup_messages = smartlist_new(); - } -} - -/** Set whether we report logging domains as a part of our log messages. - */ -void -logs_set_domain_logging(int enabled) -{ - LOCK_LOGS(); - log_domains_are_logged = enabled; - UNLOCK_LOGS(); -} - -/** Add a log handler to receive messages during startup (before the real - * logs are initialized). - */ -void -add_temp_log(int min_severity) -{ - log_severity_list_t *s = tor_malloc_zero(sizeof(log_severity_list_t)); - set_log_severity_config(min_severity, LOG_ERR, s); - LOCK_LOGS(); - add_stream_log_impl(s, "<temp>", fileno(stdout)); - tor_free(s); - logfiles->is_temporary = 1; - UNLOCK_LOGS(); -} - -/** - * Register "cb" as the callback to call when there are new pending log - * callbacks to be flushed with flush_pending_log_callbacks(). - * - * Note that this callback, if present, can be invoked from any thread. - * - * This callback must not log. - * - * It is intentional that this function contains the name "callback" twice: it - * sets a "callback" to be called on the condition that there is a "pending - * callback". - **/ -void -logs_set_pending_callback_callback(pending_callback_callback cb) -{ - pending_cb_cb = cb; -} - -/** - * Add a log handler to send messages in <b>severity</b> - * to the function <b>cb</b>. - */ -int -add_callback_log(const log_severity_list_t *severity, log_callback cb) -{ - logfile_t *lf; - lf = tor_malloc_zero(sizeof(logfile_t)); - lf->fd = -1; - lf->severities = tor_memdup(severity, sizeof(log_severity_list_t)); - lf->filename = tor_strdup("<callback>"); - lf->callback = cb; - lf->next = logfiles; - - LOCK_LOGS(); - logfiles = lf; - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); - return 0; -} - -/** Adjust the configured severity of any logs whose callback function is - * <b>cb</b>. */ -void -change_callback_log_severity(int loglevelMin, int loglevelMax, - log_callback cb) -{ - logfile_t *lf; - log_severity_list_t severities; - set_log_severity_config(loglevelMin, loglevelMax, &severities); - LOCK_LOGS(); - for (lf = logfiles; lf; lf = lf->next) { - if (lf->callback == cb) { - memcpy(lf->severities, &severities, sizeof(severities)); - } - } - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); -} - -/** If there are any log messages that were generated with LD_NOCB waiting to - * be sent to callback-based loggers, send them now. */ -void -flush_pending_log_callbacks(void) -{ - logfile_t *lf; - smartlist_t *messages, *messages_tmp; - - LOCK_LOGS(); - if (!pending_cb_messages || 0 == smartlist_len(pending_cb_messages)) { - UNLOCK_LOGS(); - return; - } - - messages = pending_cb_messages; - pending_cb_messages = smartlist_new(); - do { - SMARTLIST_FOREACH_BEGIN(messages, pending_log_message_t *, msg) { - const int severity = msg->severity; - const int domain = msg->domain; - for (lf = logfiles; lf; lf = lf->next) { - if (! lf->callback || lf->seems_dead || - ! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) { - continue; - } - lf->callback(severity, domain, msg->msg); - } - pending_log_message_free(msg); - } SMARTLIST_FOREACH_END(msg); - smartlist_clear(messages); - - messages_tmp = pending_cb_messages; - pending_cb_messages = messages; - messages = messages_tmp; - } while (smartlist_len(messages)); - - smartlist_free(messages); - - UNLOCK_LOGS(); -} - -/** Flush all the messages we stored from startup while waiting for log - * initialization. - */ -void -flush_log_messages_from_startup(void) -{ - logfile_t *lf; - - LOCK_LOGS(); - queue_startup_messages = 0; - pending_startup_messages_len = 0; - if (! pending_startup_messages) - goto out; - - SMARTLIST_FOREACH_BEGIN(pending_startup_messages, pending_log_message_t *, - msg) { - int callbacks_deferred = 0; - for (lf = logfiles; lf; lf = lf->next) { - if (! logfile_wants_message(lf, msg->severity, msg->domain)) - continue; - - /* We configure a temporary startup log that goes to stdout, so we - * shouldn't replay to stdout/stderr*/ - if (lf->fd == STDOUT_FILENO || lf->fd == STDERR_FILENO) { - continue; - } - - logfile_deliver(lf, msg->fullmsg, strlen(msg->fullmsg), msg->msg, - msg->domain, msg->severity, &callbacks_deferred); - } - pending_log_message_free(msg); - } SMARTLIST_FOREACH_END(msg); - smartlist_free(pending_startup_messages); - pending_startup_messages = NULL; - - out: - UNLOCK_LOGS(); -} - -/** Close any log handlers added by add_temp_log() or marked by - * mark_logs_temp(). */ -void -close_temp_logs(void) -{ - logfile_t *lf, **p; - - LOCK_LOGS(); - for (p = &logfiles; *p; ) { - if ((*p)->is_temporary) { - lf = *p; - /* we use *p here to handle the edge case of the head of the list */ - *p = (*p)->next; - close_log(lf); - log_free(lf); - } else { - p = &((*p)->next); - } - } - - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); -} - -/** Make all currently temporary logs (set to be closed by close_temp_logs) - * live again, and close all non-temporary logs. */ -void -rollback_log_changes(void) -{ - logfile_t *lf; - LOCK_LOGS(); - for (lf = logfiles; lf; lf = lf->next) - lf->is_temporary = ! lf->is_temporary; - UNLOCK_LOGS(); - close_temp_logs(); -} - -/** Configure all log handles to be closed by close_temp_logs(). */ -void -mark_logs_temp(void) -{ - logfile_t *lf; - LOCK_LOGS(); - for (lf = logfiles; lf; lf = lf->next) - lf->is_temporary = 1; - UNLOCK_LOGS(); -} - -/** - * Add a log handler to send messages to <b>filename</b>. If opening the - * logfile fails, -1 is returned and errno is set appropriately (by open(2)). - */ -int -add_file_log(const log_severity_list_t *severity, const char *filename, - const int truncate_log) -{ - int fd; - logfile_t *lf; - - int open_flags = O_WRONLY|O_CREAT; - open_flags |= truncate_log ? O_TRUNC : O_APPEND; - - fd = tor_open_cloexec(filename, open_flags, 0640); - if (fd<0) - return -1; - if (tor_fd_seekend(fd)<0) { - close(fd); - return -1; - } - - LOCK_LOGS(); - add_stream_log_impl(severity, filename, fd); - logfiles->needs_close = 1; - lf = logfiles; - log_global_min_severity_ = get_min_log_level(); - - if (log_tor_version(lf, 0) < 0) { - delete_log(lf); - } - UNLOCK_LOGS(); - - return 0; -} - -#ifdef HAVE_SYSLOG_H -/** - * Add a log handler to send messages to they system log facility. - * - * If this is the first log handler, opens syslog with ident Tor or - * Tor-<syslog_identity_tag> if that is not NULL. - */ -int -add_syslog_log(const log_severity_list_t *severity, - const char* syslog_identity_tag) -{ - logfile_t *lf; - if (syslog_count++ == 0) { - /* This is the first syslog. */ - static char buf[256]; - if (syslog_identity_tag) { - tor_snprintf(buf, sizeof(buf), "Tor-%s", syslog_identity_tag); - } else { - tor_snprintf(buf, sizeof(buf), "Tor"); - } - openlog(buf, LOG_PID | LOG_NDELAY, LOGFACILITY); - } - - lf = tor_malloc_zero(sizeof(logfile_t)); - lf->fd = -1; - lf->severities = tor_memdup(severity, sizeof(log_severity_list_t)); - lf->filename = tor_strdup("<syslog>"); - lf->is_syslog = 1; - - LOCK_LOGS(); - lf->next = logfiles; - logfiles = lf; - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); - return 0; -} -#endif /* defined(HAVE_SYSLOG_H) */ - -#ifdef HAVE_ANDROID_LOG_H -/** - * Add a log handler to send messages to the Android platform log facility. - */ -int -add_android_log(const log_severity_list_t *severity, - const char *android_tag) -{ - logfile_t *lf = NULL; - - lf = tor_malloc_zero(sizeof(logfile_t)); - lf->fd = -1; - lf->severities = tor_memdup(severity, sizeof(log_severity_list_t)); - lf->filename = tor_strdup("<android>"); - lf->is_android = 1; - - if (android_tag == NULL) - lf->android_tag = tor_strdup("Tor"); - else { - char buf[256]; - tor_snprintf(buf, sizeof(buf), "Tor-%s", android_tag); - lf->android_tag = tor_strdup(buf); - } - - LOCK_LOGS(); - lf->next = logfiles; - logfiles = lf; - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); - return 0; -} -#endif // HAVE_ANDROID_LOG_H. - -/** If <b>level</b> is a valid log severity, return the corresponding - * numeric value. Otherwise, return -1. */ -int -parse_log_level(const char *level) -{ - if (!strcasecmp(level, "err")) - return LOG_ERR; - if (!strcasecmp(level, "warn")) - return LOG_WARN; - if (!strcasecmp(level, "notice")) - return LOG_NOTICE; - if (!strcasecmp(level, "info")) - return LOG_INFO; - if (!strcasecmp(level, "debug")) - return LOG_DEBUG; - return -1; -} - -/** Return the string equivalent of a given log level. */ -const char * -log_level_to_string(int level) -{ - return sev_to_string(level); -} - -/** NULL-terminated array of names for log domains such that domain_list[dom] - * is a description of <b>dom</b>. - * - * Remember to update doc/tor.1.txt if you modify this list. - * */ -static const char *domain_list[] = { - "GENERAL", "CRYPTO", "NET", "CONFIG", "FS", "PROTOCOL", "MM", - "HTTP", "APP", "CONTROL", "CIRC", "REND", "BUG", "DIR", "DIRSERV", - "OR", "EDGE", "ACCT", "HIST", "HANDSHAKE", "HEARTBEAT", "CHANNEL", - "SCHED", "GUARD", "CONSDIFF", "DOS", NULL -}; - -/** Return a bitmask for the log domain for which <b>domain</b> is the name, - * or 0 if there is no such name. */ -static log_domain_mask_t -parse_log_domain(const char *domain) -{ - int i; - for (i=0; domain_list[i]; ++i) { - if (!strcasecmp(domain, domain_list[i])) - return (1u<<i); - } - return 0; -} - -/** Translate a bitmask of log domains to a string. */ -static char * -domain_to_string(log_domain_mask_t domain, char *buf, size_t buflen) -{ - char *cp = buf; - char *eos = buf+buflen; - - buf[0] = '\0'; - if (! domain) - return buf; - while (1) { - const char *d; - int bit = tor_log2(domain); - size_t n; - if ((unsigned)bit >= ARRAY_LENGTH(domain_list)-1 || - bit >= N_LOGGING_DOMAINS) { - tor_snprintf(buf, buflen, "<BUG:Unknown domain %lx>", (long)domain); - return buf+strlen(buf); - } - d = domain_list[bit]; - n = strlcpy(cp, d, eos-cp); - if (n >= buflen) { - tor_snprintf(buf, buflen, "<BUG:Truncating domain %lx>", (long)domain); - return buf+strlen(buf); - } - cp += n; - domain &= ~(1<<bit); - - if (domain == 0 || (eos-cp) < 2) - return cp; - - memcpy(cp, ",", 2); /*Nul-terminated ,"*/ - cp++; - } -} - -/** Parse a log severity pattern in *<b>cfg_ptr</b>. Advance cfg_ptr after - * the end of the severityPattern. Set the value of <b>severity_out</b> to - * the parsed pattern. Return 0 on success, -1 on failure. - * - * The syntax for a SeverityPattern is: - * <pre> - * SeverityPattern = *(DomainSeverity SP)* DomainSeverity - * DomainSeverity = (DomainList SP)? SeverityRange - * SeverityRange = MinSeverity ("-" MaxSeverity )? - * DomainList = "[" (SP? DomainSpec SP? ",") SP? DomainSpec "]" - * DomainSpec = "*" | Domain | "~" Domain - * </pre> - * A missing MaxSeverity defaults to ERR. Severities and domains are - * case-insensitive. "~" indicates negation for a domain; negation happens - * last inside a DomainList. Only one SeverityRange without a DomainList is - * allowed per line. - */ -int -parse_log_severity_config(const char **cfg_ptr, - log_severity_list_t *severity_out) -{ - const char *cfg = *cfg_ptr; - int got_anything = 0; - int got_an_unqualified_range = 0; - memset(severity_out, 0, sizeof(*severity_out)); - - cfg = eat_whitespace(cfg); - while (*cfg) { - const char *dash, *space; - char *sev_lo, *sev_hi; - int low, high, i; - log_domain_mask_t domains = ~0u; - - if (*cfg == '[') { - int err = 0; - char *domains_str; - smartlist_t *domains_list; - log_domain_mask_t neg_domains = 0; - const char *closebracket = strchr(cfg, ']'); - if (!closebracket) - return -1; - domains = 0; - domains_str = tor_strndup(cfg+1, closebracket-cfg-1); - domains_list = smartlist_new(); - smartlist_split_string(domains_list, domains_str, ",", SPLIT_SKIP_SPACE, - -1); - tor_free(domains_str); - SMARTLIST_FOREACH_BEGIN(domains_list, const char *, domain) { - if (!strcmp(domain, "*")) { - domains = ~0u; - } else { - int d; - int negate=0; - if (*domain == '~') { - negate = 1; - ++domain; - } - d = parse_log_domain(domain); - if (!d) { - log_warn(LD_CONFIG, "No such logging domain as %s", domain); - err = 1; - } else { - if (negate) - neg_domains |= d; - else - domains |= d; - } - } - } SMARTLIST_FOREACH_END(domain); - SMARTLIST_FOREACH(domains_list, char *, d, tor_free(d)); - smartlist_free(domains_list); - if (err) - return -1; - if (domains == 0 && neg_domains) - domains = ~neg_domains; - else - domains &= ~neg_domains; - cfg = eat_whitespace(closebracket+1); - } else { - ++got_an_unqualified_range; - } - if (!strcasecmpstart(cfg, "file") || - !strcasecmpstart(cfg, "stderr") || - !strcasecmpstart(cfg, "stdout") || - !strcasecmpstart(cfg, "syslog") || - !strcasecmpstart(cfg, "android")) { - goto done; - } - if (got_an_unqualified_range > 1) - return -1; - - space = find_whitespace(cfg); - dash = strchr(cfg, '-'); - if (dash && dash < space) { - sev_lo = tor_strndup(cfg, dash-cfg); - sev_hi = tor_strndup(dash+1, space-(dash+1)); - } else { - sev_lo = tor_strndup(cfg, space-cfg); - sev_hi = tor_strdup("ERR"); - } - low = parse_log_level(sev_lo); - high = parse_log_level(sev_hi); - tor_free(sev_lo); - tor_free(sev_hi); - if (low == -1) - return -1; - if (high == -1) - return -1; - - got_anything = 1; - for (i=low; i >= high; --i) - severity_out->masks[SEVERITY_MASK_IDX(i)] |= domains; - - cfg = eat_whitespace(space); - } - - done: - *cfg_ptr = cfg; - return got_anything ? 0 : -1; -} - -/** Return the least severe log level that any current log is interested in. */ -int -get_min_log_level(void) -{ - logfile_t *lf; - int i; - int min = LOG_ERR; - for (lf = logfiles; lf; lf = lf->next) { - for (i = LOG_DEBUG; i > min; --i) - if (lf->severities->masks[SEVERITY_MASK_IDX(i)]) - min = i; - } - return min; -} - -/** Switch all logs to output at most verbose level. */ -void -switch_logs_debug(void) -{ - logfile_t *lf; - int i; - LOCK_LOGS(); - for (lf = logfiles; lf; lf=lf->next) { - for (i = LOG_DEBUG; i >= LOG_ERR; --i) - lf->severities->masks[SEVERITY_MASK_IDX(i)] = ~0u; - } - log_global_min_severity_ = get_min_log_level(); - UNLOCK_LOGS(); -} - -/** Truncate all the log files. */ -void -truncate_logs(void) -{ - logfile_t *lf; - for (lf = logfiles; lf; lf = lf->next) { - if (lf->fd >= 0) { - tor_ftruncate(lf->fd); - } - } -} |