new feature: $OMFileAsyncWriting directive added

it permits to specifiy if asynchronous writing should be done or not

20 files changed, 91 insertions, 35 deletions

diff --git a/ChangeLog b/ChangeLog
index 467196cd..0eed1cf8 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -2,6 +2,8 @@
 Version 4.6.2  [v4-stable] (rgerhards), 2010-03-??
 - new feature: "." action type added to support writing files to relative
   pathes (this is primarily meant as a debug aid)
+- new feature: $OMFileAsyncWriting directive added
+  it permits to specifiy if asynchronous writing should be done or not
 - bugfix(temporary): message-induced off-by-one error (potential segfault)
   Some types of malformed messages could trigger an off-by-one error
   (for example, \0 or \n as the last character, and generally control
diff --git a/doc/rsyslog_conf_global.html b/doc/rsyslog_conf_global.html
index e7897f90..d5a27541 100644
--- a/doc/rsyslog_conf_global.html
+++ b/doc/rsyslog_conf_global.html
@@ -207,6 +207,14 @@ supported in order to be compliant to the upcoming new syslog RFC series.
 <li><a href="rsconf1_maxopenfiles.html">$MaxOpenFiles</a></li>
 <li><a href="rsconf1_moddir.html">$ModDir</a></li>
 <li><a href="rsconf1_modload.html">$ModLoad</a></li>
+<li><b>$OMFileAsyncWriting</b> [on/<b>off</b>], if turned on, the files will be written
+in asynchronous mode via a separate thread. In that case, double buffers will be used so
+that one buffer can be filled while the other buffer is being written. Note that in order
+to enable $OMFileFlushInterval, $OMFileAsyncWriting must be set to "on". Otherwise, the flush
+interval will be ignored. Also note that when $OMFileFlushOnTXEnd is "on" but 
+$OMFileAsyncWriting is off, output will only be written when the buffer is full. This may take
+several hours, or even require a rsyslog shutdown. However, a buffer flush can be forced
+in that case by sending rsyslogd a HUP signal.
 <li><b>$OMFileZipLevel</b> 0..9  [default 0] - if greater 0, turns on gzip compression
 of the output file. The higher the number, the better the compression, but also the
 more CPU is required for zipping.</li>
diff --git a/tests/Makefile.am b/tests/Makefile.am
index 9e04ea1e..0b1ccb4b 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -13,13 +13,15 @@ TESTS = $(TESTRUNS) cfg.sh \
 	asynwr_timeout.sh \
 	asynwr_small.sh \
 	asynwr_tinybuf.sh \
-	asynwr_large.sh \
+	wr_large_async.sh \
+	wr_large_sync.sh \
 	asynwr_deadlock.sh \
 	asynwr_deadlock2.sh \
 	asynwr_deadlock4.sh \
 	gzipwr_large.sh \
 	gzipwr_large_dynfile.sh \
-	dynfile_invalid.sh \
+	dynfile_invld_async.sh \
+	dynfile_invld_sync.sh \
 	dynfile_invalid2.sh \
 	complex1.sh \
 	queue-persist.sh \
@@ -163,8 +165,10 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \
 	   testsuites/asynwr_small.conf \
 	   asynwr_tinybuf.sh \
 	   testsuites/asynwr_tinybuf.conf \
-	   asynwr_large.sh \
-	   testsuites/asynwr_large.conf \
+	   wr_large_async.sh \
+	   wr_large_sync.sh \
+	   wr_large.sh \
+	   testsuites/wr_large.conf \
 	   asynwr_deadlock.sh \
 	   testsuites/asynwr_deadlock.conf \
 	   asynwr_deadlock2.sh \
@@ -177,8 +181,10 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \
 	   testsuites/gzipwr_large_dynfile.conf \
 	   complex1.sh \
 	   testsuites/complex1.conf \
-	   dynfile_invalid.sh \
-	   testsuites/dynfile_invalid.conf \
+	   dynfile_invld_async.sh \
+	   dynfile_invld_sync.sh \
+	   dynfile_cachemiss.sh \
+	   testsuites/dynfile_cachemiss.conf \
 	   dynfile_invalid2.sh \
 	   testsuites/dynfile_invalid2.conf \
 	   proprepltest.sh \
diff --git a/tests/diag.sh b/tests/diag.sh
index 27b60582..8f268a5e 100755
--- a/tests/diag.sh
+++ b/tests/diag.sh
@@ -16,6 +16,7 @@ case $1 in
    'init')	$srcdir/killrsyslog.sh # kill rsyslogd if it runs for some reason
 		cp $srcdir/testsuites/diag-common.conf diag-common.conf
 		cp $srcdir/testsuites/diag-common2.conf diag-common2.conf
+		rm -f rsyslog.action.*.include
 		rm -f rsyslogd.started work-*.conf
 		rm -f rsyslogd2.started work-*.conf
 		rm -f work rsyslog.out.log rsyslog.out.log.save # common work files
@@ -25,7 +26,7 @@ case $1 in
 		mkdir test-spool
 		;;
    'exit')	rm -f rsyslogd.started work-*.conf diag-common.conf
-   		rm -f rsyslogd2.started diag-common2.conf
+   		rm -f rsyslogd2.started diag-common2.conf rsyslog.action.*.include
 		rm -f work rsyslog.out.log rsyslog.out.log.save # common work files
 		rm -f rsyslog.out.*.log
 		rm -rf test-spool
diff --git a/tests/dynfile_invalid.sh b/tests/dynfile_cachemiss.sh
index 6c792db1..6e2d9cca 100755
--- a/tests/dynfile_invalid.sh
+++ b/tests/dynfile_cachemiss.sh
@@ -6,12 +6,12 @@
 #
 # This file is part of the rsyslog project, released  under GPLv3
 echo ===============================================================================
-echo TEST: \[dynfile_invalid.sh\]: test open fail for dynafiles
+echo TEST: \[dynfile_cachemiss.sh\]: test open fail for dynafiles with `cat rsyslog.action.1.include`
 source $srcdir/diag.sh init
 # uncomment for debugging support:
 #export RSYSLOG_DEBUG="debug nostdout noprintmutexaction"
 #export RSYSLOG_DEBUGLOG="log"
-source $srcdir/diag.sh startup dynfile_invalid.conf
+source $srcdir/diag.sh startup dynfile_cachemiss.conf
 # we send handcrafted message. We have a dynafile cache of 4, and now send one message
 # each to fill up the cache.
 ./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.0.log:0"
diff --git a/tests/dynfile_invld_async.sh b/tests/dynfile_invld_async.sh
new file mode 100755
index 00000000..3c9b2045
--- /dev/null
+++ b/tests/dynfile_invld_async.sh
@@ -0,0 +1,2 @@
+echo "\$OMFileAsyncWriting on" > rsyslog.action.1.include
+source $srcdir/dynfile_cachemiss.sh
diff --git a/tests/dynfile_invld_sync.sh b/tests/dynfile_invld_sync.sh
new file mode 100755
index 00000000..cc6b6451
--- /dev/null
+++ b/tests/dynfile_invld_sync.sh
@@ -0,0 +1,2 @@
+echo "\$OMFileAsyncWriting off" > rsyslog.action.1.include
+source $srcdir/dynfile_cachemiss.sh
diff --git a/tests/testsuites/asynwr_deadlock.conf b/tests/testsuites/asynwr_deadlock.conf
index d703791a..dc4045b0 100644
--- a/tests/testsuites/asynwr_deadlock.conf
+++ b/tests/testsuites/asynwr_deadlock.conf
@@ -10,4 +10,5 @@ $template outfmt,"%msg:F,58:2%\n"
 $OMFileFlushOnTXEnd on
 $OMFileFlushInterval 10
 $OMFileFlushIOBufferSize 10k
+$OMFileAsyncWriting on
 :msg, contains, "msgnum:" ./rsyslog.out.log;outfmt
diff --git a/tests/testsuites/asynwr_deadlock2.conf b/tests/testsuites/asynwr_deadlock2.conf
index c3eecae3..07811613 100644
--- a/tests/testsuites/asynwr_deadlock2.conf
+++ b/tests/testsuites/asynwr_deadlock2.conf
@@ -11,5 +11,6 @@ $template dynfile,"rsyslog.out.%msg:F,58:2%.log" # use multiple dynafiles
 $OMFileFlushOnTXEnd on
 $OMFileFlushInterval 10
 $OMFileIOBufferSize 10k
+$OMFileAsyncWriting on
 $DynaFileCacheSize 4
 local0.* ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_deadlock4.conf b/tests/testsuites/asynwr_deadlock4.conf
index 23ce3cfc..f4308ff1 100644
--- a/tests/testsuites/asynwr_deadlock4.conf
+++ b/tests/testsuites/asynwr_deadlock4.conf
@@ -11,5 +11,6 @@ $template dynfile,"rsyslog.out.log" # use multiple dynafiles
 $OMFileFlushOnTXEnd on
 $OMFileFlushInterval 10
 $OMFileIOBufferSize 10k
+$OMFileAsyncWriting on
 $DynaFileCacheSize 4
 local0.* ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_simple.conf b/tests/testsuites/asynwr_simple.conf
index 68b85ff5..44b03f2b 100644
--- a/tests/testsuites/asynwr_simple.conf
+++ b/tests/testsuites/asynwr_simple.conf
@@ -11,4 +11,5 @@ $template dynfile,"rsyslog.out.log" # trick to use relative path names!
 $OMFileFlushOnTXEnd off
 $OMFileFlushInterval 2
 $OMFileFlushIOBufferSize 10k
+$OMFileAsyncWriting on
 :msg, contains, "msgnum:" ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_small.conf b/tests/testsuites/asynwr_small.conf
index d9724cec..f04ce962 100644
--- a/tests/testsuites/asynwr_small.conf
+++ b/tests/testsuites/asynwr_small.conf
@@ -10,4 +10,5 @@ $template outfmt,"%msg:F,58:2%\n"
 $template dynfile,"rsyslog.out.log" # trick to use relative path names!
 $OMFileFlushOnTXEnd off
 $OMFileFlushInterval 2
+$OMFileAsyncWriting on
 :msg, contains, "msgnum:" ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_timeout.conf b/tests/testsuites/asynwr_timeout.conf
index 68b85ff5..44b03f2b 100644
--- a/tests/testsuites/asynwr_timeout.conf
+++ b/tests/testsuites/asynwr_timeout.conf
@@ -11,4 +11,5 @@ $template dynfile,"rsyslog.out.log" # trick to use relative path names!
 $OMFileFlushOnTXEnd off
 $OMFileFlushInterval 2
 $OMFileFlushIOBufferSize 10k
+$OMFileAsyncWriting on
 :msg, contains, "msgnum:" ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_tinybuf.conf b/tests/testsuites/asynwr_tinybuf.conf
index 9818b139..01dec4d8 100644
--- a/tests/testsuites/asynwr_tinybuf.conf
+++ b/tests/testsuites/asynwr_tinybuf.conf
@@ -11,4 +11,5 @@ $template dynfile,"rsyslog.out.log" # trick to use relative path names!
 $OMFileFlushOnTXEnd off
 $OMFileFlushInterval 2
 $OMFileIOBufferSize 1
+$OMFileAsyncWriting on
 :msg, contains, "msgnum:" ?dynfile;outfmt
diff --git a/tests/testsuites/dynfile_invalid.conf b/tests/testsuites/dynfile_cachemiss.conf
index 458f199b..273ff176 100644
--- a/tests/testsuites/dynfile_invalid.conf
+++ b/tests/testsuites/dynfile_cachemiss.conf
@@ -10,5 +10,5 @@ $template outfmt,"%msg:F,58:3%\n"
 $template dynfile,"%msg:F,58:2%.log" # complete name is in message
 $OMFileFlushOnTXEnd on
 $DynaFileCacheSize 4
-$omfileFlushInterval 1
+$IncludeConfig rsyslog.action.1.include
 local0.* ?dynfile;outfmt
diff --git a/tests/testsuites/asynwr_large.conf b/tests/testsuites/wr_large.conf
index de41bc43..b64f132b 100644
--- a/tests/testsuites/asynwr_large.conf
+++ b/tests/testsuites/wr_large.conf
@@ -12,4 +12,5 @@ $template dynfile,"rsyslog.out.log" # trick to use relative path names!
 $OMFileFlushOnTXEnd off
 $OMFileFlushInterval 2
 $OMFileIOBufferSize 256k
+$IncludeConfig rsyslog.action.1.include
 local0.* ?dynfile;outfmt
diff --git a/tests/asynwr_large.sh b/tests/wr_large.sh
index 158fd80b..84f12989 100755
--- a/tests/asynwr_large.sh
+++ b/tests/wr_large.sh
@@ -4,13 +4,9 @@
 # added 2010-03-10 by Rgerhards
 #
 # This file is part of the rsyslog project, released  under GPLv3
-echo ===============================================================================
-echo TEST: \[asynwr_large.sh\]: test for async file writing for large message sets
+cat rsyslog.action.1.include
 source $srcdir/diag.sh init
-# uncomment for debugging support:
-#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction"
-#export RSYSLOG_DEBUGLOG="log"
-source $srcdir/diag.sh startup asynwr_large.conf
+source $srcdir/diag.sh startup wr_large.conf
 # send 4000 messages of 10.000bytes plus header max, randomized
 source $srcdir/diag.sh tcpflood -m4000 -r -d10000 -P129
 sleep 1 # due to large messages, we need this time for the tcp receiver to settle...
diff --git a/tests/wr_large_async.sh b/tests/wr_large_async.sh
new file mode 100755
index 00000000..88a1acf8
--- /dev/null
+++ b/tests/wr_large_async.sh
@@ -0,0 +1,14 @@
+# This tests async writing large data records. We use up to 10K
+# record size.
+
+# added 2010-03-10 by Rgerhards
+#
+# This file is part of the rsyslog project, released  under GPLv3
+echo ===============================================================================
+echo TEST: \[wr_large_async.sh\]: test for file writing for large message sets
+source $srcdir/diag.sh init
+# uncomment for debugging support:
+#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction"
+#export RSYSLOG_DEBUGLOG="log"
+echo "\$OMFileAsyncWriting on" > rsyslog.action.1.include
+source $srcdir/wr_large.sh
diff --git a/tests/wr_large_sync.sh b/tests/wr_large_sync.sh
new file mode 100755
index 00000000..a1c4fd77
--- /dev/null
+++ b/tests/wr_large_sync.sh
@@ -0,0 +1,14 @@
+# This tests async writing large data records. We use up to 10K
+# record size.
+
+# added 2010-03-10 by Rgerhards
+#
+# This file is part of the rsyslog project, released  under GPLv3
+echo ===============================================================================
+echo TEST: \[wr_large_sync.sh\]: test for file writing for large message sets
+source $srcdir/diag.sh init
+# uncomment for debugging support:
+#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction"
+#export RSYSLOG_DEBUGLOG="log"
+echo "\$OMFileAsyncWriting off" > rsyslog.action.1.include
+source $srcdir/wr_large.sh
diff --git a/tools/omfile.c b/tools/omfile.c
index 774f0b96..dd944946 100644
--- a/tools/omfile.c
+++ b/tools/omfile.c
@@ -86,6 +86,7 @@ typedef struct s_dynaFileCacheEntry dynaFileCacheEntry;
 
 #define IOBUF_DFLT_SIZE 1024	/* default size for io buffers */
 #define FLUSH_INTRVL_DFLT 1 	/* default buffer flush interval (in seconds) */
+#define USE_ASYNCWRITER_DFLT 0 	/* default buffer use async writer */
 
 /* globals for default values */
 static int iDynaFileCacheSize = 10; /* max cache for dynamic files */
@@ -102,6 +103,7 @@ static int	iZipLevel = 0;	/* zip compression mode (0..9 as usual) */
 static bool	bFlushOnTXEnd = 0;/* flush write buffers when transaction has ended? */
 static int64	iIOBufSize = IOBUF_DFLT_SIZE;	/* size of an io buffer */
 static int	iFlushInterval = FLUSH_INTRVL_DFLT; 	/* how often flush the output buffer on inactivity? */
+static int	bUseAsyncWriter = USE_ASYNCWRITER_DFLT;	/* should we enable asynchronous writing? */
 uchar	*pszFileDfltTplName = NULL; /* name of the default template to use */
 /* end globals for default values */
 
@@ -134,6 +136,7 @@ typedef struct _instanceData {
 	int	iIOBufSize;		/* size of associated io buffer */
 	int	iFlushInterval;		/* how fast flush buffer on inactivity? */
 	bool	bFlushOnTXEnd;		/* flush write buffers when transaction has ended? */
+	bool	bUseAsyncWriter;	/* use async stream writer? */
 } instanceData;
 
 
@@ -147,26 +150,23 @@ ENDisCompatibleWithFeature
 BEGINdbgPrintInstInfo
 CODESTARTdbgPrintInstInfo
 	if(pData->bDynamicName) {
-		dbgprintf("[dynamic]\n\ttemplate='%s'"
-		       "\tfile cache size=%d\n"
-		       "\tcreate directories: %s\n"
-		       "\tfile owner %d, group %d\n"
-		       "\tdirectory owner %d, group %d\n"
-		       "\tdir create mode 0%3.3o, file create mode 0%3.3o\n"
-		       "\tfail if owner/group can not be set: %s\n",
-		        pData->f_fname,
-			pData->iDynaFileCacheSize,
-			pData->bCreateDirs ? "yes" : "no",
-			pData->fileUID, pData->fileGID,
-			pData->dirUID, pData->dirGID,
-			pData->fDirCreateMode, pData->fCreateMode,
-			pData->bFailOnChown ? "yes" : "no"
-			);
+		dbgprintf("[dynamic]\n");
 	} else { /* regular file */
-		dbgprintf("%s", pData->f_fname);
-		if (pData->pStrm == NULL)
-			dbgprintf(" (unused)");
+		dbgprintf("%s%s\n", pData->f_fname,
+			  (pData->pStrm == NULL) ? " (unused)" : "");
 	}
+
+	dbgprintf("\ttemplate='%s'\n", pData->f_fname);
+	dbgprintf("\tuse async writer=%d\n", pData->bUseAsyncWriter);
+	dbgprintf("\tflush on TX end=%d\n", pData->bFlushOnTXEnd);
+	dbgprintf("\tflush interval=%d\n", pData->iFlushInterval);
+	dbgprintf("\tfile cache size=%d\n", pData->iDynaFileCacheSize);
+	dbgprintf("\tcreate directories: %s\n", pData->bCreateDirs ? "yes" : "no");
+	dbgprintf("\tfile owner %d, group %d\n", pData->fileUID, pData->fileGID);
+	dbgprintf("\tdirectory owner %d, group %d\n", pData->dirUID, pData->dirGID);
+	dbgprintf("\tdir create mode 0%3.3o, file create mode 0%3.3o\n",
+		  pData->fDirCreateMode, pData->fCreateMode);
+	dbgprintf("\tfail if owner/group can not be set: %s\n", pData->bFailOnChown ? "yes" : "no");
 ENDdbgPrintInstInfo
 
 
@@ -414,7 +414,7 @@ prepareFile(instanceData *pData, uchar *newFileName)
 	 * async processing, which is a real performance waste if we do not do buffered
 	 * writes! -- rgerhards, 2009-07-06
 	 */
-	if(!pData->bFlushOnTXEnd)
+	if(pData->bUseAsyncWriter)
 		CHKiRet(strm.SetiFlushInterval(pData->pStrm, pData->iFlushInterval));
 	if(pData->pszSizeLimitCmd != NULL)
 		CHKiRet(strm.SetpszSizeLimitCmd(pData->pStrm, ustrdup(pData->pszSizeLimitCmd)));
@@ -731,6 +731,7 @@ CODESTARTparseSelectorAct
 	pData->bFlushOnTXEnd = bFlushOnTXEnd;
 	pData->iIOBufSize = (int) iIOBufSize;
 	pData->iFlushInterval = iFlushInterval;
+	pData->bUseAsyncWriter = bUseAsyncWriter;
 
 	if(pData->bDynamicName == 0) {
 		/* try open and emit error message if not possible. At this stage, we ignore the
@@ -766,6 +767,7 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __a
 	bFlushOnTXEnd = 0;
 	iIOBufSize = IOBUF_DFLT_SIZE;
 	iFlushInterval = FLUSH_INTRVL_DFLT;
+	bUseAsyncWriter = USE_ASYNCWRITER_DFLT;
 	if(pszFileDfltTplName != NULL) {
 		free(pszFileDfltTplName);
 		pszFileDfltTplName = NULL;
@@ -812,6 +814,7 @@ CODEmodInit_QueryRegCFSLineHdlr
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"dynafilecachesize", 0, eCmdHdlrInt, (void*) setDynaFileCacheSize, NULL, STD_LOADABLE_MODULE_ID));
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileziplevel", 0, eCmdHdlrInt, NULL, &iZipLevel, STD_LOADABLE_MODULE_ID));
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileflushinterval", 0, eCmdHdlrInt, NULL, &iFlushInterval, STD_LOADABLE_MODULE_ID));
+	CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileasyncwriting", 0, eCmdHdlrInt, NULL, &bUseAsyncWriter, STD_LOADABLE_MODULE_ID));
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileflushontxend", 0, eCmdHdlrBinary, NULL, &bFlushOnTXEnd, STD_LOADABLE_MODULE_ID));
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileiobuffersize", 0, eCmdHdlrSize, NULL, &iIOBufSize, STD_LOADABLE_MODULE_ID));
 	CHKiRet(omsdRegCFSLineHdlr((uchar *)"dirowner", 0, eCmdHdlrUID, NULL, &dirUID, STD_LOADABLE_MODULE_ID));