| Subject: | Buffered output for log channels |
| Date: | Mon, 14 Nov 2011 16:57:40 +0100 |
| To: | bind-suggest@isc.org |
| From: | Alexander Gall <gall@switch.ch> |
Hi
I've been using permanent query logging to plain files on moderately
busy systems (1000-2000 qps, authoritative-only server) for a long
time to have a short backlog of incoming queries. In a recent change
of our setup, we started writing the query log to an NFS file system.
The unbuffered output mode of named for logging to a file together
with a (rather weird) behaviour of the standard Linux nfs Client led
to massive iowait times which created significant jitter in query
response times.
I found that I could get rid of this jitter completely by using
buffered I/O for the query log. The attached simple-minded patch adds
the boolean option "buffered" to the "channel" configuration phrase,
e.g.
channel my_queries {
file "/var/log/bind/queries" versions 15 size 2m;
severity info;
print-time yes;
buffered yes;
};
The patch simply skips the fflush() call in lib/isc/log.c and should
have no effect on channels that do not log to a file. This works fine
on a busy system but needs some polishing to make it robust (like
flushing regularly). I also don't know if it has any side-effects.
Can you please consider to add this functionality to BIND9?
Regards,
Alex
--- a/bin/named/logconf.c
+++ b/bin/named/logconf.c
@@ -181,10 +181,12 @@
const cfg_obj_t *printcat = NULL;
const cfg_obj_t *printsev = NULL;
const cfg_obj_t *printtime = NULL;
+ const cfg_obj_t *buffered = NULL;
(void)cfg_map_get(channel, "print-category", &printcat);
(void)cfg_map_get(channel, "print-severity", &printsev);
(void)cfg_map_get(channel, "print-time", &printtime);
+ (void)cfg_map_get(channel, "buffered", &buffered);
if (printcat != NULL && cfg_obj_asboolean(printcat))
flags |= ISC_LOG_PRINTCATEGORY;
@@ -192,6 +194,8 @@
flags |= ISC_LOG_PRINTTIME;
if (printsev != NULL && cfg_obj_asboolean(printsev))
flags |= ISC_LOG_PRINTLEVEL;
+ if (buffered != NULL && cfg_obj_asboolean(buffered))
+ flags |= ISC_LOG_BUFFERED;
}
level = ISC_LOG_INFO;
--- a/lib/isc/include/isc/log.h
+++ b/lib/isc/include/isc/log.h
@@ -69,6 +69,7 @@
#define ISC_LOG_PRINTMODULE 0x0008
#define ISC_LOG_PRINTTAG 0x0010
#define ISC_LOG_PRINTALL 0x001F
+#define ISC_LOG_BUFFERED 0x0020
#define ISC_LOG_DEBUGONLY 0x1000
#define ISC_LOG_OPENERR 0x8000 /* internal */
/*@}*/
--- a/lib/isc/log.c
+++ b/lib/isc/log.c
@@ -714,7 +714,8 @@
REQUIRE(destination != NULL || type == ISC_LOG_TONULL);
REQUIRE(level >= ISC_LOG_CRITICAL);
REQUIRE((flags &
- (unsigned int)~(ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY)) == 0);
+ (unsigned int)~(ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY
+ | ISC_LOG_BUFFERED)) == 0);
/* XXXDCL find duplicate names? */
@@ -1413,7 +1414,7 @@
struct stat statbuf;
isc_boolean_t matched = ISC_FALSE;
isc_boolean_t printtime, printtag;
- isc_boolean_t printcategory, printmodule, printlevel;
+ isc_boolean_t printcategory, printmodule, printlevel, buffered;
isc_logconfig_t *lcfg;
isc_logchannel_t *channel;
isc_logchannellist_t *category_channels;
@@ -1648,6 +1649,8 @@
!= 0);
printlevel = ISC_TF((channel->flags & ISC_LOG_PRINTLEVEL)
!= 0);
+ buffered = ISC_TF((channel->flags & ISC_LOG_BUFFERED)
+ != 0);
switch (channel->type) {
case ISC_LOG_TOFILE:
@@ -1708,7 +1711,9 @@
printlevel ? level_string : "",
lctx->buffer);
- fflush(FILE_STREAM(channel));
+ if (buffered != ISC_TRUE) {
+ fflush(FILE_STREAM(channel));
+ }
/*
* If the file now exceeds its maximum size
--- a/lib/isccfg/namedconf.c
+++ b/lib/isccfg/namedconf.c
@@ -1594,6 +1594,7 @@
{ "print-time", &cfg_type_boolean, 0 },
{ "print-severity", &cfg_type_boolean, 0 },
{ "print-category", &cfg_type_boolean, 0 },
+ { "buffered", &cfg_type_boolean, 0 },
{ NULL, NULL, 0 }
};
static cfg_clausedef_t *