summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--changes/ticket69384
-rw-r--r--src/common/log.c253
-rw-r--r--src/common/torlog.h3
-rw-r--r--src/or/config.c6
-rw-r--r--src/or/main.c2
-rw-r--r--src/test/bench.c2
-rw-r--r--src/test/test.c2
-rw-r--r--src/test/test_bt_cl.c2
-rw-r--r--src/test/test_logging.c4
-rw-r--r--src/tools/tor-checkkey.c2
-rw-r--r--src/tools/tor-gencert.c2
-rw-r--r--src/tools/tor-resolve.c2
12 files changed, 205 insertions, 79 deletions
diff --git a/changes/ticket6938 b/changes/ticket6938
new file mode 100644
index 0000000000..4e3979a7e9
--- /dev/null
+++ b/changes/ticket6938
@@ -0,0 +1,4 @@
+ o Minor features:
+
+ - When opening a log file at startup, send it every log message that we
+ generated between startup and opening it. Closes ticket 6938.
diff --git a/src/common/log.c b/src/common/log.c
index 2e51e5c578..4b3817780b 100644
--- a/src/common/log.c
+++ b/src/common/log.c
@@ -117,15 +117,33 @@ static int syslog_count = 0;
/** 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_cb_message_t {
+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_cb_message_t;
+} pending_log_message_t;
/** Log messages waiting to be replayed onto callback-based logs */
static smartlist_t *pending_cb_messages = 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;
+
+/** 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_mutex_acquire(&log_mutex); \
@@ -329,6 +347,102 @@ format_msg(char *buf, size_t buf_len,
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;
+}
+
+/** 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);
+}
+
+/** 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 || lf->is_syslog || lf->callback)) {
+ 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
+ /* We have syslog but not MAXLINE. That's promising! */
+ syslog(severity, "%s", msg_after_prefix);
+#endif
+#endif
+ } 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;
+ }
+ } 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).
@@ -354,20 +468,21 @@ logv,(int severity, log_domain_mask_t domain, const char *funcname,
if ((! (domain & LD_NOCB)) && smartlist_len(pending_cb_messages))
flush_pending_log_callbacks();
- lf = logfiles;
- while (lf) {
- if (! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
- lf = lf->next;
- continue;
- }
- if (! (lf->fd >= 0 || lf->is_syslog || lf->callback)) {
- lf = lf->next;
- continue;
- }
- if (lf->seems_dead) {
- lf = lf->next;
+ 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 =
@@ -376,51 +491,8 @@ logv,(int severity, log_domain_mask_t domain, const char *funcname,
formatted = 1;
}
- if (lf->is_syslog) {
-#ifdef HAVE_SYSLOG_H
- char *m = end_of_prefix;
-#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
- if (msg_len >= MAXLINE)
- m = tor_strndup(end_of_prefix, MAXLINE-1);
-#endif
- syslog(severity, "%s", m);
-#ifdef MAXLINE
- if (m != end_of_prefix) {
- tor_free(m);
- }
-#endif
-#endif
- lf = lf->next;
- continue;
- } else if (lf->callback) {
- if (domain & LD_NOCB) {
- if (!callbacks_deferred && pending_cb_messages) {
- pending_cb_message_t *msg = tor_malloc(sizeof(pending_cb_message_t));
- msg->severity = severity;
- msg->domain = domain;
- msg->msg = tor_strdup(end_of_prefix);
- smartlist_add(pending_cb_messages, msg);
-
- callbacks_deferred = 1;
- }
- } else {
- lf->callback(severity, domain, end_of_prefix);
- }
- lf = lf->next;
- continue;
- }
- 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;
- }
- lf = lf->next;
+ logfile_deliver(lf, buf, msg_len, end_of_prefix, domain, severity,
+ &callbacks_deferred);
}
UNLOCK_LOGS();
}
@@ -724,12 +796,14 @@ void
logs_free_all(void)
{
logfile_t *victim, *next;
- smartlist_t *messages;
+ smartlist_t *messages, *messages2;
LOCK_LOGS();
next = logfiles;
logfiles = NULL;
messages = pending_cb_messages;
pending_cb_messages = NULL;
+ messages2 = pending_startup_messages;
+ pending_startup_messages = NULL;
UNLOCK_LOGS();
while (next) {
victim = next;
@@ -739,12 +813,18 @@ logs_free_all(void)
}
tor_free(appname);
- SMARTLIST_FOREACH(messages, pending_cb_message_t *, msg, {
- tor_free(msg->msg);
- tor_free(msg);
+ 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. */
}
@@ -839,7 +919,7 @@ add_stream_log(const log_severity_list_t *severity, const char *name, int fd)
/** Initialize the global logging facility */
void
-init_logging(void)
+init_logging(int disable_startup_queue)
{
if (!log_mutex_initialized) {
tor_mutex_init(&log_mutex);
@@ -847,6 +927,11 @@ init_logging(void)
}
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.
@@ -932,7 +1017,7 @@ flush_pending_log_callbacks(void)
messages = pending_cb_messages;
pending_cb_messages = smartlist_new();
do {
- SMARTLIST_FOREACH_BEGIN(messages, pending_cb_message_t *, msg) {
+ 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) {
@@ -942,8 +1027,7 @@ flush_pending_log_callbacks(void)
}
lf->callback(severity, domain, msg->msg);
}
- tor_free(msg->msg);
- tor_free(msg);
+ pending_log_message_free(msg);
} SMARTLIST_FOREACH_END(msg);
smartlist_clear(messages);
@@ -957,6 +1041,39 @@ flush_pending_log_callbacks(void)
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;
+
+ 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
diff --git a/src/common/torlog.h b/src/common/torlog.h
index 34e39b4b94..8105af4351 100644
--- a/src/common/torlog.h
+++ b/src/common/torlog.h
@@ -121,7 +121,7 @@ typedef struct log_severity_list_t {
/** Callback type used for add_callback_log. */
typedef void (*log_callback)(int severity, uint32_t domain, const char *msg);
-void init_logging(void);
+void init_logging(int disable_startup_queue);
int parse_log_level(const char *level);
const char *log_level_to_string(int level);
int parse_log_severity_config(const char **cfg,
@@ -147,6 +147,7 @@ void mark_logs_temp(void);
void change_callback_log_severity(int loglevelMin, int loglevelMax,
log_callback cb);
void flush_pending_log_callbacks(void);
+void flush_log_messages_from_startup(void);
void log_set_application_name(const char *name);
void set_log_time_granularity(int granularity_msec);
void truncate_logs(void);
diff --git a/src/or/config.c b/src/or/config.c
index 5555a2eb3b..2318e63b8e 100644
--- a/src/or/config.c
+++ b/src/or/config.c
@@ -1001,7 +1001,7 @@ options_act_reversible(const or_options_t *old_options, char **msg)
int running_tor = options->command == CMD_RUN_TOR;
int set_conn_limit = 0;
int r = -1;
- int logs_marked = 0;
+ int logs_marked = 0, logs_initialized = 0;
int old_min_log_level = get_min_log_level();
/* Daemonize _first_, since we only want to open most of this stuff in
@@ -1131,6 +1131,7 @@ options_act_reversible(const or_options_t *old_options, char **msg)
*msg = tor_strdup("Failed to init Log options. See logs for details.");
goto rollback;
}
+ logs_initialized = 1;
commit:
r = 0;
@@ -1143,6 +1144,9 @@ options_act_reversible(const or_options_t *old_options, char **msg)
tor_free(severity);
tor_log_update_sigsafe_err_fds();
}
+ if (logs_initialized) {
+ flush_log_messages_from_startup();
+ }
{
const char *badness = NULL;
diff --git a/src/or/main.c b/src/or/main.c
index 61efc1f6f2..1d26223eb6 100644
--- a/src/or/main.c
+++ b/src/or/main.c
@@ -2955,7 +2955,7 @@ tor_main(int argc, char *argv[])
update_approx_time(time(NULL));
tor_threads_init();
- init_logging();
+ init_logging(0);
#ifdef USE_DMALLOC
{
/* Instruct OpenSSL to use our internal wrappers for malloc,
diff --git a/src/test/bench.c b/src/test/bench.c
index 1204854b36..825299835b 100644
--- a/src/test/bench.c
+++ b/src/test/bench.c
@@ -631,7 +631,7 @@ main(int argc, const char **argv)
crypto_seed_rng(1);
crypto_init_siphash_key();
options = options_new();
- init_logging();
+ init_logging(1);
options->command = CMD_RUN_UNITTESTS;
options->DataDirectory = tor_strdup("");
options_init(options);
diff --git a/src/test/test.c b/src/test/test.c
index d2813ed42a..16ad6f3ae6 100644
--- a/src/test/test.c
+++ b/src/test/test.c
@@ -1366,7 +1366,7 @@ main(int c, const char **v)
update_approx_time(time(NULL));
options = options_new();
tor_threads_init();
- init_logging();
+ init_logging(1);
configure_backtrace_handler(get_version());
for (i_out = i = 1; i < c; ++i) {
diff --git a/src/test/test_bt_cl.c b/src/test/test_bt_cl.c
index 720ccd4627..d7a3cab7c3 100644
--- a/src/test/test_bt_cl.c
+++ b/src/test/test_bt_cl.c
@@ -96,7 +96,7 @@ main(int argc, char **argv)
return 1;
}
- init_logging();
+ init_logging(1);
set_log_severity_config(LOG_WARN, LOG_ERR, &severity);
add_stream_log(&severity, "stdout", STDOUT_FILENO);
tor_log_update_sigsafe_err_fds();
diff --git a/src/test/test_logging.c b/src/test/test_logging.c
index 9f57000bea..76cc9e970e 100644
--- a/src/test/test_logging.c
+++ b/src/test/test_logging.c
@@ -19,7 +19,7 @@ test_get_sigsafe_err_fds(void *arg)
int n;
log_severity_list_t include_bug, no_bug, no_bug2;
(void) arg;
- init_logging();
+ init_logging(1);
n = tor_log_get_sigsafe_err_fds(&fds);
tt_int_op(n, ==, 1);
@@ -87,7 +87,7 @@ test_sigsafe_err(void *arg)
set_log_severity_config(LOG_WARN, LOG_ERR, &include_bug);
- init_logging();
+ init_logging(1);
mark_logs_temp();
add_file_log(&include_bug, fn, 0);
tor_log_update_sigsafe_err_fds();
diff --git a/src/tools/tor-checkkey.c b/src/tools/tor-checkkey.c
index d50f12ed2a..295da33051 100644
--- a/src/tools/tor-checkkey.c
+++ b/src/tools/tor-checkkey.c
@@ -21,7 +21,7 @@ main(int c, char **v)
int wantdigest=0;
int fname_idx;
char *fname=NULL;
- init_logging();
+ init_logging(1);
if (c < 2) {
fprintf(stderr, "Hi. I'm tor-checkkey. Tell me a filename that "
diff --git a/src/tools/tor-gencert.c b/src/tools/tor-gencert.c
index fae26ef956..0fe6821ff8 100644
--- a/src/tools/tor-gencert.c
+++ b/src/tools/tor-gencert.c
@@ -525,7 +525,7 @@ int
main(int argc, char **argv)
{
int r = 1;
- init_logging();
+ init_logging(1);
/* Don't bother using acceleration. */
if (crypto_global_init(0, NULL, NULL)) {
diff --git a/src/tools/tor-resolve.c b/src/tools/tor-resolve.c
index 480c7e52ca..74af511acb 100644
--- a/src/tools/tor-resolve.c
+++ b/src/tools/tor-resolve.c
@@ -344,7 +344,7 @@ main(int argc, char **argv)
char *result_hostname = NULL;
log_severity_list_t *s = tor_malloc_zero(sizeof(log_severity_list_t));
- init_logging();
+ init_logging(1);
sandbox_disable_getaddrinfo_cache();
arg = &argv[1];
7apu2bq3rhoylwmucxizk54afw5jyda7pho4j5zdcqpwkufke7zdzwad.onion