added more tests to testbench and improved testing tools

15 files changed, 200 insertions, 8 deletions

diff --git a/runtime/debug.c b/runtime/debug.c
index 20474a9a..4504aaad 100644
--- a/runtime/debug.c
+++ b/runtime/debug.c
@@ -952,7 +952,7 @@ void
 dbgprintf(char *fmt, ...)
 {
 	va_list ap;
-	char pszWriteBuf[1024];
+	char pszWriteBuf[20480];
 	size_t lenWriteBuf;
 
 	if(!(Debug && debugging_on))
diff --git a/tests/Makefile.am b/tests/Makefile.am
index 92d3764b..13443f63 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -13,6 +13,9 @@ TESTS = $(TESTRUNS) cfg.sh \
 	asynwr_timeout.sh \
 	asynwr_small.sh \
 	asynwr_tinybuf.sh \
+	asynwr_large.sh \
+	gzipwr_large.sh \
+	gzipwr_large_dynfile.sh \
 	queue-persist.sh \
 	pipeaction.sh
 	execonlyonce.sh \
@@ -147,6 +150,12 @@ 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 \
+	   gzipwr_large.sh \
+	   testsuites/gzipwr_large.conf \
+	   gzipwr_large_dynfile.sh \
+	   testsuites/gzipwr_large_dynfile.conf \
 	   testsuites/small.conf \
 	   proprepltest.sh \
 	   testsuites/rfctag.conf \
diff --git a/tests/asynwr_large.sh b/tests/asynwr_large.sh
new file mode 100755
index 00000000..158fd80b
--- /dev/null
+++ b/tests/asynwr_large.sh
@@ -0,0 +1,20 @@
+# 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: \[asynwr_large.sh\]: test for async 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"
+source $srcdir/diag.sh startup asynwr_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...
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
+source $srcdir/diag.sh seq-check 0 3999 -E
+source $srcdir/diag.sh exit
diff --git a/tests/asynwr_simple.sh b/tests/asynwr_simple.sh
index c21f7893..eb87443c 100755
--- a/tests/asynwr_simple.sh
+++ b/tests/asynwr_simple.sh
@@ -13,5 +13,6 @@ source $srcdir/diag.sh startup asynwr_simple.conf
 # 10K, the buffer size!
 source $srcdir/diag.sh tcpflood -m35555
 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
 source $srcdir/diag.sh seq-check 0 35554
 source $srcdir/diag.sh exit
diff --git a/tests/asynwr_small.sh b/tests/asynwr_small.sh
index ee091935..97818f6e 100755
--- a/tests/asynwr_small.sh
+++ b/tests/asynwr_small.sh
@@ -21,5 +21,6 @@ source $srcdir/diag.sh startup asynwr_small.conf
 # send 4000 messages
 source $srcdir/diag.sh tcpflood -m2
 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
 source $srcdir/diag.sh seq-check 0 1
 source $srcdir/diag.sh exit
diff --git a/tests/asynwr_timeout.sh b/tests/asynwr_timeout.sh
index 41b76ede..b0bc5c28 100755
--- a/tests/asynwr_timeout.sh
+++ b/tests/asynwr_timeout.sh
@@ -16,5 +16,6 @@ source $srcdir/diag.sh startup asynwr_timeout.conf
 source $srcdir/diag.sh tcpflood -m 35555
 sleep 4 # wait for output writer to write and empty buffer
 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
 source $srcdir/diag.sh seq-check 0 35554
 source $srcdir/diag.sh exit
diff --git a/tests/chkseq.c b/tests/chkseq.c
index b8088cd5..b22c8992 100644
--- a/tests/chkseq.c
+++ b/tests/chkseq.c
@@ -134,5 +134,10 @@ int main(int argc, char *argv[])
 		exit(1);
 	}
 
+	if(!feof(fp)) {
+		printf("end of processing, but NOT end of file!\n");
+		exit(1);
+	}
+
 	exit(ret);
 }
diff --git a/tests/diag.sh b/tests/diag.sh
index f3d75a15..b3154c44 100755
--- a/tests/diag.sh
+++ b/tests/diag.sh
@@ -18,6 +18,7 @@ case $1 in
 		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
+		rm -f rsyslog.out.*.log
 		rm -rf test-spool
 		rm -f core.* vgcore.*
 		mkdir test-spool
@@ -25,6 +26,7 @@ case $1 in
    'exit')	rm -f rsyslogd.started work-*.conf diag-common.conf
    		rm -f rsyslogd2.started diag-common2.conf
 		rm -f work rsyslog.out.log rsyslog.out.log.save # common work files
+		rm -f rsyslog.out.*.log
 		rm -rf test-spool
 		;;
    'startup')   # start rsyslogd with default params. $2 is the config file name to use
@@ -34,14 +36,16 @@ case $1 in
 		;;
    'wait-startup') # wait for rsyslogd startup ($2 is the instance)
 		while test ! -f rsyslogd$2.started; do
-			true
+			#true
+			sleep 0.1 # if this is not supported by all platforms, use above!
 		done
 		echo "rsyslogd$2 started with pid " `cat rsyslog$2.pid`
 		;;
    'wait-shutdown')  # actually, we wait for rsyslog.pid to be deleted. $2 is the
    		# instance
 		while test -f rsyslog$2.pid; do
-			true
+			#true
+			sleep 0.1 # if this is not supported by all platforms, use above!
 		done
 		;;
    'wait-queueempty') # wait for main message queue to be empty. $2 is the instance.
@@ -85,6 +89,7 @@ case $1 in
 		;;
    'seq-check') # do the usual sequence check to see if everything was properly received. $2 is the instance.
 		rm -f work
+		cp rsyslog.out.log work-presort
 		sort < rsyslog.out.log > work
 		# $4... are just to have the abilit to pass in more options...
 		./chkseq -fwork -v -s$2 -e$3 $4 $5 $6 $7
@@ -105,6 +110,18 @@ case $1 in
 		  exit 1
 		fi
 		;;
+   'gzip-seq-check') # do the usual sequence check, but for gzip files
+		rm -f work
+		ls -l rsyslog.out.log
+		gunzip < rsyslog.out.log | sort > work
+		ls -l work
+		# $4... are just to have the abilit to pass in more options...
+		./chkseq -fwork -v -s$2 -e$3 $4 $5 $6 $7
+		if [ "$?" -ne "0" ]; then
+		  echo "sequence error detected"
+		  exit 1
+		fi
+		;;
    'nettester') # perform nettester-based tests
    		# use -v for verbose output!
 		./nettester -t$2 -i$3
diff --git a/tests/gzipwr_large.sh b/tests/gzipwr_large.sh
new file mode 100755
index 00000000..ffce06f6
--- /dev/null
+++ b/tests/gzipwr_large.sh
@@ -0,0 +1,20 @@
+# This tests writing large data records in gzip mode. 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: \[gzipwr_large.sh\]: test for gzip 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"
+source $srcdir/diag.sh startup gzipwr_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...
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
+source $srcdir/diag.sh gzip-seq-check 0 3999 -E
+source $srcdir/diag.sh exit
diff --git a/tests/gzipwr_large_dynfile.sh b/tests/gzipwr_large_dynfile.sh
new file mode 100755
index 00000000..ebd4c558
--- /dev/null
+++ b/tests/gzipwr_large_dynfile.sh
@@ -0,0 +1,36 @@
+# This tests writing large data records in gzip mode. We also write it to
+# 5 different dynafiles, with a dynafile cache size set to 4. So this stresses
+# both the input side, as well as zip writing, async writing and the dynafile
+# cache logic.
+#
+# This test is a bit timing-dependent on the tcp reception side, so if it fails
+# one may look into the timing first. The main issue is that the testbench
+# currently has no good way to know if the tcp receiver is finished. This is NOT
+# a problem in rsyslogd, but only of the testbench.
+#
+# Note that we do not yet have sufficient support for dynafiles in diag.sh,
+# so we mangle some files here manually.
+#
+# added 2010-03-10 by Rgerhards
+#
+# This file is part of the rsyslog project, released  under GPLv3
+echo ====================================================================================
+echo TEST: \[gzipwr_large_dynfile.sh\]: test for gzip file writing for large message sets
+source $srcdir/diag.sh init
+# uncomment for debugging support:
+export RSYSLOG_DEBUG="debug nostdout"
+export RSYSLOG_DEBUGLOG="log"
+source $srcdir/diag.sh startup gzipwr_large_dynfile.conf
+# send 4000 messages of 10.000bytes plus header max, randomized
+source $srcdir/diag.sh tcpflood -m4000 -r -d10000 -P129 -f5
+sleep 2 # due to large messages, we need this time for the tcp receiver to settle...
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown       # and wait for it to terminate
+gunzip < rsyslog.out.0.log > rsyslog.out.log
+gunzip < rsyslog.out.1.log >> rsyslog.out.log
+gunzip < rsyslog.out.2.log >> rsyslog.out.log
+gunzip < rsyslog.out.3.log >> rsyslog.out.log
+gunzip < rsyslog.out.4.log >> rsyslog.out.log
+#cat rsyslog.out.* > rsyslog.out.log
+source $srcdir/diag.sh seq-check 0 3999 -E
+source $srcdir/diag.sh exit
diff --git a/tests/longrun.sh b/tests/longrun.sh
new file mode 100755
index 00000000..09bddc58
--- /dev/null
+++ b/tests/longrun.sh
@@ -0,0 +1,22 @@
+# This is a test-aid script to try running some tests through many iterations.
+# It is not yet used in the automated testbench, but I keep this file so that
+# I can use it whenever there is need to. As such, it currently does not have
+# parameters but is expected to be edited as needed. -- rgerhards, 2010-03-10
+MAXRUNS=10
+DISPLAYALIVE=100
+LOGFILE=runlog
+
+date > $LOGFILE
+
+for (( i=0; $i < 10000; i++ ))
+  do
+    if [ $(( i % DISPLAYALIVE )) -eq 0 ]; then
+      echo "$i iterations done"
+    fi
+    ./gzipwr_large_dynfile.sh >> $LOGFILE
+    if [ "$?" -ne "0" ]; then
+      echo "Test failed in iteration $i!"
+      exit 1
+    fi
+  done
+echo "No failure in $i iterations."
diff --git a/tests/tcpflood.c b/tests/tcpflood.c
index fcfc30a7..0f9f21f2 100644
--- a/tests/tcpflood.c
+++ b/tests/tcpflood.c
@@ -14,6 +14,9 @@
  *      bytes as forth. Add -r to randomize the amount of extra
  *      data included in the range 1..(value of -d).
  * -r	randomize amount of extra data added (-d must be > 0)
+ * -f	support for testing dynafiles. If given, include a dynafile ID
+ *      in the range 0..(f-1) as the SECOND field, shifting all field values
+ *      one field to the right. Zero (default) disables this functionality.
  *
  * Part of the testbench for rsyslog.
  *
@@ -59,6 +62,7 @@
 static char *targetIP = "127.0.0.1";
 static char *msgPRI = "167";
 static int targetPort = 13514;
+static int dynFileIDs = 0;
 static int extraDataLen = 0; /* amount of extra data to add to message */
 static int bRandomizeExtraData = 0; /* randomize amount of extra data added */
 static int numMsgsToSend; /* number of messages to send */
@@ -177,6 +181,7 @@ int sendMessages(void)
 	int lenBuf;
 	int lenSend;
 	int edLen; /* actual extra data length to use */
+	char dynFileIDBuf[128] = "";
 	char buf[MAX_EXTRADATA_LEN + 1024];
 	char extraData[MAX_EXTRADATA_LEN + 1];
 
@@ -191,9 +196,12 @@ int sendMessages(void)
 			socknum = i - (numMsgsToSend - numConnections);
 		else
 			socknum = rand() % numConnections;
+		if(dynFileIDs > 0) {
+			sprintf(dynFileIDBuf, "%d:", rand() % dynFileIDs);
+		}
 		if(extraDataLen == 0) {
-			lenBuf = sprintf(buf, "<%s>Mar  1 01:00:00 172.20.245.8 tag msgnum:%8.8d:\n",
-					       msgPRI, msgNum);
+			lenBuf = sprintf(buf, "<%s>Mar  1 01:00:00 172.20.245.8 tag msgnum:%s%8.8d:\n",
+					       msgPRI, dynFileIDBuf, msgNum);
 		} else {
 			if(bRandomizeExtraData)
 				edLen = ((long) rand() + extraDataLen) % extraDataLen + 1;
@@ -201,8 +209,8 @@ int sendMessages(void)
 				edLen = extraDataLen;
 			memset(extraData, 'X', edLen);
 			extraData[edLen] = '\0';
-			lenBuf = sprintf(buf, "<%s>Mar  1 01:00:00 172.20.245.8 tag msgnum:%8.8d:%d:%s\n",
-					       msgPRI, msgNum, edLen, extraData);
+			lenBuf = sprintf(buf, "<%s>Mar  1 01:00:00 172.20.245.8 tag msgnum:%s%8.8d:%d:%s\n",
+					       msgPRI, dynFileIDBuf, msgNum, edLen, extraData);
 		}
 		lenSend = send(sockArray[socknum], buf, lenBuf, 0);
 		if(lenSend != lenBuf) {
@@ -297,7 +305,7 @@ int main(int argc, char *argv[])
 
 	setvbuf(stdout, buf, _IONBF, 48);
 
-	while((opt = getopt(argc, argv, "t:p:c:m:i:P:d:r")) != -1) {
+	while((opt = getopt(argc, argv, "f:t:p:c:m:i:P:d:r")) != -1) {
 		switch (opt) {
 		case 't':	targetIP = optarg;
 				break;
@@ -320,6 +328,11 @@ int main(int argc, char *argv[])
 				break;
 		case 'r':	bRandomizeExtraData = 1;
 				break;
+		case 'f':	dynFileIDs = atoi(optarg);
+				break;
+		default:	printf("invalid option '%c' or value missing - terminating...\n", opt);
+				exit (1);
+				break;
 		}
 	}
 
diff --git a/tests/testsuites/asynwr_large.conf b/tests/testsuites/asynwr_large.conf
new file mode 100644
index 00000000..de41bc43
--- /dev/null
+++ b/tests/testsuites/asynwr_large.conf
@@ -0,0 +1,15 @@
+# simple async writing test
+# rgerhards, 2010-03-09
+$MaxMessageSize 10k
+$IncludeConfig diag-common.conf
+
+$ModLoad ../plugins/imtcp/.libs/imtcp
+$MainMsgQueueTimeoutShutdown 10000
+$InputTCPServerRun 13514
+
+$template outfmt,"%msg:F,58:2%,%msg:F,58:3%,%msg:F,58:4%\n"
+$template dynfile,"rsyslog.out.log" # trick to use relative path names!
+$OMFileFlushOnTXEnd off
+$OMFileFlushInterval 2
+$OMFileIOBufferSize 256k
+local0.* ?dynfile;outfmt
diff --git a/tests/testsuites/gzipwr_large.conf b/tests/testsuites/gzipwr_large.conf
new file mode 100644
index 00000000..54ad3bb3
--- /dev/null
+++ b/tests/testsuites/gzipwr_large.conf
@@ -0,0 +1,15 @@
+# simple async writing test
+# rgerhards, 2010-03-09
+$MaxMessageSize 10k
+$IncludeConfig diag-common.conf
+
+$ModLoad ../plugins/imtcp/.libs/imtcp
+$MainMsgQueueTimeoutShutdown 10000
+$InputTCPServerRun 13514
+
+$template outfmt,"%msg:F,58:2%,%msg:F,58:3%,%msg:F,58:4%\n"
+$template dynfile,"rsyslog.out.log" # trick to use relative path names!
+$OMFileFlushOnTXEnd off
+$OMFileZipLevel 6
+$OMFileIOBufferSize 256k
+local0.* ?dynfile;outfmt
diff --git a/tests/testsuites/gzipwr_large_dynfile.conf b/tests/testsuites/gzipwr_large_dynfile.conf
new file mode 100644
index 00000000..31bcb978
--- /dev/null
+++ b/tests/testsuites/gzipwr_large_dynfile.conf
@@ -0,0 +1,17 @@
+# simple async writing test
+# rgerhards, 2010-03-09
+$MaxMessageSize 10k
+$IncludeConfig diag-common.conf
+
+$ModLoad ../plugins/imtcp/.libs/imtcp
+$MainMsgQueueTimeoutShutdown 10000
+$InputTCPServerRun 13514
+
+$template outfmt,"%msg:F,58:3%,%msg:F,58:4%,%msg:F,58:5%\n"
+$template dynfile,"rsyslog.out.%msg:F,58:2%.log" # trick to use relative path names!
+$OMFileFlushOnTXEnd off
+$OMFileZipLevel 6
+$OMFileIOBufferSize 256k
+$DynaFileCacheSize 4
+$omfileFlushInterval 1
+local0.* ?dynfile;outfmt