[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
[or-cvs] r13019: Fix bug 575: protect the list of logs with a mutex. I couldn (in tor/trunk: . src/common src/or)
Author: nickm
Date: 2008-01-02 00:38:53 -0500 (Wed, 02 Jan 2008)
New Revision: 13019
Modified:
tor/trunk/
tor/trunk/ChangeLog
tor/trunk/src/common/log.c
tor/trunk/src/common/log.h
tor/trunk/src/or/main.c
tor/trunk/src/or/test.c
Log:
r15784@tombo: nickm | 2008-01-02 00:38:06 -0500
Fix bug 575: protect the list of logs with a mutex. I couldn't find any appreciable change in logging performance on osx, but ymmv. You can undef USE_LOG_MUTEX to see if stuff gets faster for you.
Property changes on: tor/trunk
___________________________________________________________________
svk:merge ticket from /tor/trunk [r15784] on d9e39d38-0f13-419c-a857-e10a0ce2aa0c
Modified: tor/trunk/ChangeLog
===================================================================
--- tor/trunk/ChangeLog 2008-01-02 04:57:48 UTC (rev 13018)
+++ tor/trunk/ChangeLog 2008-01-02 05:38:53 UTC (rev 13019)
@@ -9,11 +9,16 @@
o Minor performance improvements:
- Reference-count and share copies of address policy entries; only
5% of them were actually distinct.
+ - Never walk through the list of logs if we know that no log is
+ interested in a given message.
o Minor bugfixes:
- When an authority has not signed a consensus, do not try to
download a nonexistant "certificate with key 00000000". Bugfix
on 0.2.0.x. Fixes bug 569.
+ - Use a mutex to protect the list of logs, so we never write to
+ the list as it's being freed. Bugfix on 0.1.2.x. Fixes the
+ very rare bug 575, which is kind of the revenge of bug 222.
o Minor features (controller):
- Get NS events working again. (Patch from tup)
Modified: tor/trunk/src/common/log.c
===================================================================
--- tor/trunk/src/common/log.c 2008-01-02 04:57:48 UTC (rev 13018)
+++ tor/trunk/src/common/log.c 2008-01-02 05:38:53 UTC (rev 13019)
@@ -78,14 +78,28 @@
}
}
-/* XXXX We should really have this protected by a mutex or something;
- * XXXX see bug 222. */
+#define USE_LOG_MUTEX
+
+#ifdef USE_LOG_MUTEX
+/** A mutex to guard changes to logfiles and logging. */
+static tor_mutex_t *log_mutex = NULL;
+#endif
/** Linked list of logfile_t. */
static logfile_t *logfiles = NULL;
#ifdef HAVE_SYSLOG_H
static int syslog_count = 0;
#endif
+#ifdef USE_LOG_MUTEX
+#define LOCK_LOGS() STMT_BEGIN \
+ tor_mutex_acquire(log_mutex); \
+ STMT_END
+#define UNLOCK_LOGS() STMT_BEGIN tor_mutex_release(log_mutex); STMT_END
+#else
+#define LOCK_LOGS() STMT_NIL
+#define UNLOCK_LOGS() STMT_NIL
+#endif
+
/* What's the lowest log level anybody cares about? */
int _log_global_min_severity = LOG_NOTICE;
@@ -241,6 +255,7 @@
char *end_of_prefix=NULL;
assert(format);
+ LOCK_LOGS();
lf = logfiles;
while (lf) {
if (severity > lf->min_loglevel || severity < lf->max_loglevel) {
@@ -282,6 +297,7 @@
}
lf = lf->next;
}
+ UNLOCK_LOGS();
}
/** Output a message to the log. */
@@ -289,6 +305,8 @@
_log(int severity, uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (severity > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(severity, domain, NULL, format, ap);
va_end(ap);
@@ -300,6 +318,8 @@
_log_fn(int severity, uint32_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, format, ap);
va_end(ap);
@@ -310,6 +330,8 @@
_log_fn(int severity, uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (severity > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(severity, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -319,6 +341,9 @@
_log_debug(uint32_t domain, const char *format, ...)
{
va_list ap;
+ /* For GCC we do this check in the macro. */
+ if (PREDICT_LIKELY(LOG_DEBUG > _log_global_min_severity))
+ return;
va_start(ap,format);
logv(LOG_DEBUG, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -328,6 +353,8 @@
_log_info(uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (LOG_INFO > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(LOG_INFO, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -337,6 +364,8 @@
_log_notice(uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (LOG_NOTICE > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(LOG_NOTICE, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -346,6 +375,8 @@
_log_warn(uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (LOG_WARN > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(LOG_WARN, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -355,6 +386,8 @@
_log_err(uint32_t domain, const char *format, ...)
{
va_list ap;
+ if (LOG_ERR > _log_global_min_severity)
+ return;
va_start(ap,format);
logv(LOG_ERR, domain, _log_fn_function_name, format, ap);
va_end(ap);
@@ -367,8 +400,10 @@
logs_free_all(void)
{
logfile_t *victim, *next;
+ LOCK_LOGS();
next = logfiles;
logfiles = NULL;
+ UNLOCK_LOGS();
while (next) {
victim = next;
next = next->next;
@@ -423,10 +458,10 @@
}
/** Add a log handler to send all messages of severity <b>loglevel</b>
- * or higher to <b>stream</b>. */
-void
-add_stream_log(int loglevelMin, int loglevelMax,
- const char *name, FILE *stream)
+ * or higher to <b>stream</b>. DOCDOC.*/
+static void
+add_stream_log_impl(int loglevelMin, int loglevelMax,
+ const char *name, FILE *stream)
{
logfile_t *lf;
lf = tor_malloc_zero(sizeof(logfile_t));
@@ -435,21 +470,40 @@
lf->max_loglevel = loglevelMax;
lf->file = stream;
lf->next = logfiles;
+
logfiles = lf;
-
_log_global_min_severity = get_min_log_level();
}
+/** Add a log handler to send all messages of severity <b>loglevel</b>
+ * or higher to <b>stream</b>. */
+void
+add_stream_log(int loglevelMin, int loglevelMax,
+ const char *name, FILE *stream)
+{
+ LOCK_LOGS();
+ add_stream_log_impl(loglevelMin, loglevelMax, name, stream);
+ UNLOCK_LOGS();
+}
+
+/** Initialize the global logging facility */
+void
+init_logging(void)
+{
+ if (!log_mutex)
+ log_mutex = tor_mutex_new();
+}
+
/** Add a log handler to receive messages during startup (before the real
* logs are initialized).
*/
void
add_temp_log(void)
{
- add_stream_log(LOG_NOTICE, LOG_ERR, "<temp>", stdout);
+ LOCK_LOGS();
+ add_stream_log_impl(LOG_NOTICE, LOG_ERR, "<temp>", stdout);
logfiles->is_temporary = 1;
-
- _log_global_min_severity = get_min_log_level();
+ UNLOCK_LOGS();
}
/**
@@ -467,9 +521,11 @@
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;
}
@@ -480,14 +536,15 @@
log_callback cb)
{
logfile_t *lf;
+ LOCK_LOGS();
for (lf = logfiles; lf; lf = lf->next) {
if (lf->callback == cb) {
lf->min_loglevel = loglevelMin;
lf->max_loglevel = loglevelMax;
}
}
-
_log_global_min_severity = get_min_log_level();
+ UNLOCK_LOGS();
}
/** Close any log handlers added by add_temp_log or marked by mark_logs_temp */
@@ -495,6 +552,8 @@
close_temp_logs(void)
{
logfile_t *lf, **p;
+
+ LOCK_LOGS();
for (p = &logfiles; *p; ) {
if ((*p)->is_temporary) {
lf = *p;
@@ -509,6 +568,7 @@
}
_log_global_min_severity = get_min_log_level();
+ UNLOCK_LOGS();
}
/** Make all currently temporary logs (set to be closed by close_temp_logs)
@@ -517,8 +577,10 @@
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();
}
@@ -527,8 +589,10 @@
mark_logs_temp(void)
{
logfile_t *lf;
+ LOCK_LOGS();
for (lf = logfiles; lf; lf = lf->next)
lf->is_temporary = 1;
+ UNLOCK_LOGS();
}
/**
@@ -540,14 +604,22 @@
add_file_log(int loglevelMin, int loglevelMax, const char *filename)
{
FILE *f;
+ logfile_t *lf;
f = fopen(filename, "a");
if (!f) return -1;
- add_stream_log(loglevelMin, loglevelMax, filename, f);
+ LOCK_LOGS();
+ add_stream_log_impl(loglevelMin, loglevelMax, filename, f);
logfiles->needs_close = 1;
- if (log_tor_version(logfiles, 0) < 0) {
- delete_log(logfiles);
+ lf = logfiles;
+ _log_global_min_severity = get_min_log_level();
+ UNLOCK_LOGS();
+
+ if (log_tor_version(lf, 0) < 0) {
+ LOCK_LOGS();
+ delete_log(lf);
+ UNLOCK_LOGS();
}
- _log_global_min_severity = get_min_log_level();
+
return 0;
}
@@ -568,10 +640,12 @@
lf->filename = tor_strdup("<syslog>");
lf->max_loglevel = loglevelMax;
lf->is_syslog = 1;
+
+ LOCK_LOGS();
lf->next = logfiles;
logfiles = lf;
-
_log_global_min_severity = get_min_log_level();
+ UNLOCK_LOGS();
return 0;
}
#endif
@@ -619,9 +693,11 @@
switch_logs_debug(void)
{
logfile_t *lf;
+ LOCK_LOGS();
for (lf = logfiles; lf; lf=lf->next) {
lf->min_loglevel = LOG_DEBUG;
}
+ UNLOCK_LOGS();
}
#ifdef HAVE_EVENT_SET_LOG_CALLBACK
Modified: tor/trunk/src/common/log.h
===================================================================
--- tor/trunk/src/common/log.h 2008-01-02 04:57:48 UTC (rev 13018)
+++ tor/trunk/src/common/log.h 2008-01-02 05:38:53 UTC (rev 13019)
@@ -94,6 +94,7 @@
/** Callback type used for add_callback_log. */
typedef void (*log_callback)(int severity, uint32_t domain, const char *msg);
+void init_logging(void);
int parse_log_level(const char *level);
const char *log_level_to_string(int level);
void add_stream_log(int severityMin, int severityMax, const char *name,
Modified: tor/trunk/src/or/main.c
===================================================================
--- tor/trunk/src/or/main.c 2008-01-02 04:57:48 UTC (rev 13018)
+++ tor/trunk/src/or/main.c 2008-01-02 05:38:53 UTC (rev 13019)
@@ -1945,6 +1945,7 @@
_tor_dmalloc_free);
log_notice(LD_CONFIG, "Set up dmalloc; returned %d", r);
#endif
+ init_logging();
#ifdef NT_SERVICE
{
int done = 0;
Modified: tor/trunk/src/or/test.c
===================================================================
--- tor/trunk/src/or/test.c 2008-01-02 04:57:48 UTC (rev 13018)
+++ tor/trunk/src/or/test.c 2008-01-02 05:38:53 UTC (rev 13019)
@@ -3504,6 +3504,8 @@
int verbose = 0, any_selected = 0;
int loglevel = LOG_ERR;
+ init_logging();
+
for (i = 1; i < c; ++i) {
if (!strcmp(v[i], "-v") || !strcmp(v[i], "--verbose"))
verbose++;