Package: unbound
Version: 1.4.17-3
Severity: important
Dear Maintainer,
*** Please consider answering these questions, where appropriate ***
* What led up to the situation?
I have a need for verbose logging on a server with intensive traffic (2000q/s),
and of course need log rotation (on a hourly basis).
We actually have 1G of logs building up every 2 hours.
* What exactly did you do (or not do) that was effective (or
ineffective)?
I am using a custom logfile (logfile: "/var/log/unbound/query.log"),
with verbose logging (verbosity: 2), and no syslog (use-syslog: no),
and I set up logrotate to run "unbound-control log_reopen" as postrotate script.
* What was the outcome of this action?
Randomly, upon rotating, or just after, a segfault occurs, or the process just
dies.
I filed a bug report with the upstream developper, who fixed it in the latest
SVN trunk.
https://www.nlnetlabs.nl/bugs-script/show_bug.cgi?id=593
The fixed file is as follows :
http://unbound.nlnetlabs.nl/svn/trunk/util/log.c
Given this is valid for the latest SVN trunk, but not relevant for version
1.4.17,
I backported the relevant bits into my own patch.
*** End of the template - remove these lines ***
-- System Information:
Debian Release: 7.5
APT prefers stable
APT policy: (500, 'stable')
Architecture: i386 (i686)
Kernel: Linux 3.2.0-4-686-pae (SMP w/1 CPU core)
Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968)
Shell: /bin/sh linked to /bin/bash
Versions of packages unbound depends on:
ii adduser 3.113+nmu3
ii libc6 2.13-38+deb7u1
ii libevent-2.0-5 2.0.19-stable-3
ii libgcc1 1:4.7.2-5
ii libldns1 1.6.13-1
ii libpython2.7 2.7.3-6+deb7u2
ii libssl1.0.0 1.0.1e-2+deb7u11
ii openssl 1.0.1e-2+deb7u11
ii unbound-anchor 1.4.17-3
unbound recommends no packages.
unbound suggests no packages.
-- Configuration Files:
/etc/unbound/unbound.conf changed [not included]
-- no debconf information
--- util/log.c.orig 2014-07-04 18:16:38.206490000 +0900
+++ util/log.c 2014-07-04 18:18:22.403506000 +0900
@@ -66,6 +66,10 @@
static int key_created = 0;
/** pthread key for thread ids in logfile */
static ub_thread_key_t logkey;
+#ifndef THREADS_DISABLED
+/** pthread mutex to protect FILE* */
+static lock_quick_t log_lock;
+#endif
/** the identity of this executable/process */
static const char* ident="unbound";
#if defined(HAVE_SYSLOG_H) || defined(UB_ON_WINDOWS)
@@ -84,14 +88,19 @@
if(!key_created) {
key_created = 1;
ub_thread_key_create(&logkey, NULL);
+ lock_quick_init(&log_lock);
}
+ lock_quick_lock(&log_lock);
if(logfile
#if defined(HAVE_SYSLOG_H) || defined(UB_ON_WINDOWS)
|| logging_to_syslog
#endif
- )
- verbose(VERB_QUERY, "switching log to %s",
- use_syslog?"syslog":(filename&&filename[0]?filename:"stderr"));
+ ) {
+ lock_quick_unlock(&log_lock); /* verbose() needs the lock */
+ verbose(VERB_QUERY, "switching log to %s",
+ use_syslog?"syslog":(filename&&filename[0]?filename:"stderr"));
+ lock_quick_lock(&log_lock);
+ }
if(logfile && logfile != stderr)
fclose(logfile);
#ifdef HAVE_SYSLOG_H
@@ -104,6 +113,7 @@
* chroot and no longer be able to access dev/log and so on */
openlog(ident, LOG_NDELAY, LOG_DAEMON);
logging_to_syslog = 1;
+ lock_quick_unlock(&log_lock);
return;
}
#elif defined(UB_ON_WINDOWS)
@@ -112,11 +122,13 @@
}
if(use_syslog) {
logging_to_syslog = 1;
+ lock_quick_unlock(&log_lock);
return;
}
#endif /* HAVE_SYSLOG_H */
if(!filename || !filename[0]) {
logfile = stderr;
+ lock_quick_unlock(&log_lock);
return;
}
/* open the file for logging */
@@ -125,6 +137,7 @@
filename += strlen(chrootdir);
f = fopen(filename, "a");
if(!f) {
+ lock_quick_unlock(&log_lock);
log_err("Could not open logfile %s: %s", filename,
strerror(errno));
return;
@@ -134,11 +147,14 @@
setvbuf(f, NULL, (int)_IOLBF, 0);
#endif
logfile = f;
+ lock_quick_unlock(&log_lock);
}
void log_file(FILE *f)
{
+ lock_quick_lock(&log_lock);
logfile = f;
+ lock_quick_unlock(&log_lock);
}
void log_thread_set(int* num)
@@ -207,7 +223,11 @@
return;
}
#endif /* HAVE_SYSLOG_H */
- if(!logfile) return;
+ lock_quick_lock(&log_lock);
+ if(!logfile) {
+ lock_quick_unlock(&log_lock);
+ return;
+ }
if(log_now)
now = (time_t)*log_now;
else now = (time_t)time(NULL);
@@ -225,6 +245,7 @@
/* line buffering does not work on windows */
fflush(logfile);
#endif
+ lock_quick_unlock(&log_lock);
}
/**
