bugfix: "$ActionExecOnlyWhenPreviousIsSuspended on" was broken

Note that, as it looks, the directive was already broken in previous v5 versions.
So while I solved what looked like a (intentional) regression from the
performance tuning, I actually solved a previous regression as well ;)

I have also added new test cases to the testbench in order to capture such
problems in the future. This version does now look pretty good in shape.

16 files changed, 184 insertions, 31 deletions

diff --git a/ChangeLog b/ChangeLog
index f62ac6ad..6513fe79 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -14,6 +14,7 @@ Version 5.5.6  [DEVEL] (rgerhards), 2010-06-??
   * RSYSLOG_TraditionalForwardFormat
 - bugfix: mutexes used to similate atomic instructions were not destructed
 - bugfix: regression caused more locking action in msg.c than necessary
+- bugfix: "$ActionExecOnlyWhenPreviousIsSuspended on" was broken
 ---------------------------------------------------------------------------
 Version 5.5.5  [DEVEL] (rgerhards), 2010-05-20
 - added new cancel-reduced action thread termination method
diff --git a/action.c b/action.c
index 83929c2e..21a1ff01 100644
--- a/action.c
+++ b/action.c
@@ -832,6 +832,7 @@ finishBatch(action_t *pThis, batch_t *pBatch)
 				/* flag messages as committed */
 				for(i = 0 ; i < pBatch->nElem ; ++i) {
 					batchSetElemState(pBatch, i, BATCH_STATE_COMM);
+					pBatch->pElem[i].bPrevWasSuspended = 0; /* we had success! */
 				}
 				break;
 			case RS_RET_SUSPENDED:
@@ -885,12 +886,14 @@ tryDoAction(action_t *pAction, batch_t *pBatch, int *pnElem)
 	while(iElemProcessed <= *pnElem && i < pBatch->nElem) {
 		if(*(pBatch->pbShutdownImmediate))
 			ABORT_FINALIZE(RS_RET_FORCE_TERM);
-		if(pBatch->pElem[i].bFilterOK && pBatch->pElem[i].state != BATCH_STATE_DISC) {
+		if(   pBatch->pElem[i].bFilterOK
+		   && pBatch->pElem[i].state != BATCH_STATE_DISC
+		   && ((pAction->bExecWhenPrevSusp  == 0) || pBatch->pElem[i].bPrevWasSuspended) ) {
 			pMsg = (msg_t*) pBatch->pElem[i].pUsrp;
 			localRet = actionProcessMessage(pAction, pMsg, pBatch->pElem[i].staticActParams);
 			DBGPRINTF("action call returned %d\n", localRet);
 			/* Note: we directly modify the batch object state, because we know that
-			 * wo do not overwrite DISC indicators!
+			 * wo do not overwrite BATCH_STATE_DISC indicators!
 			 */
 			if(localRet == RS_RET_OK) {
 				/* mark messages as committed */
@@ -965,9 +968,13 @@ submitBatch(action_t *pAction, batch_t *pBatch, int nElem)
 		} else if(localRet == RS_RET_SUSPENDED) {
 			; /* do nothing, this will retry the full batch */
 		} else if(localRet == RS_RET_ACTION_FAILED) {
-			/* in this case, the whole batch can not be processed */
-			for(i = 0 ; i < nElem ; ++i) {
-				batchSetElemState(pBatch, i, BATCH_STATE_BAD);
+			/* in this case, everything not yet committed is BAD */
+			for(i = pBatch->iDoneUpTo ; i < nElem ; ++i) {
+				if(   pBatch->pElem[i].state != BATCH_STATE_DISC
+				   && pBatch->pElem[i].state != BATCH_STATE_COMM ) {
+					pBatch->pElem[i].state = BATCH_STATE_BAD;
+					pBatch->pElem[i].bPrevWasSuspended = 1;
+				}
 			}
 			bDone = 1;
 		} else {
diff --git a/runtime/batch.h b/runtime/batch.h
index 80621631..b555fc2a 100644
--- a/runtime/batch.h
+++ b/runtime/batch.h
@@ -174,4 +174,23 @@ batchInit(batch_t *pBatch, int maxElem) {
 finalize_it:
 	RETiRet;
 }
+
+
+/* primarily a helper for debug purposes, get human-readble name of state */
+static inline char *
+batchState2String(batch_state_t state) {
+	switch(state) {
+	case BATCH_STATE_RDY:
+		return "BATCH_STATE_RDY";
+	case BATCH_STATE_BAD:
+		return "BATCH_STATE_BAD";
+	case BATCH_STATE_SUB:
+		return "BATCH_STATE_SUB";
+	case BATCH_STATE_COMM:
+		return "BATCH_STATE_COMM";
+	case BATCH_STATE_DISC:
+		return "BATCH_STATE_DISC";
+	}
+	return "ERROR, batch state not known!";
+}
 #endif /* #ifndef BATCH_H_INCLUDED */
diff --git a/runtime/rsyslog.h b/runtime/rsyslog.h
index ab9fb738..2279856e 100644
--- a/runtime/rsyslog.h
+++ b/runtime/rsyslog.h
@@ -412,7 +412,7 @@ enum rsRetVal_				/** return value. All methods return this if not specified oth
 	RS_RET_RSCORE_TOO_OLD = -2120, /**< rsyslog core is too old for ... (eg this plugin) */
 	RS_RET_DEFER_COMMIT = -2121, /**< output plugin status: not yet committed (an OK state!) */
 	RS_RET_PREVIOUS_COMMITTED = -2122, /**< output plugin status: previous record was committed (an OK state!) */
-	RS_RET_ACTION_FAILED = -2123, /**< action failed and is now suspended (consider this permanent for the time being) */
+	RS_RET_ACTION_FAILED = -2123, /**< action failed and is now suspended */
 	RS_RET_NONFATAL_CONFIG_ERR = -2124, /**< non-fatal error during config processing */
 	RS_RET_NON_SIZELIMITCMD = -2125, /**< size limit for file defined, but no size limit command given */
 	RS_RET_SIZELIMITCMD_DIDNT_RESOLVE = -2126, /**< size limit command did not resolve situation */
diff --git a/runtime/rule.c b/runtime/rule.c
index c3c974bf..42773768 100644
--- a/runtime/rule.c
+++ b/runtime/rule.c
@@ -99,29 +99,9 @@ DEFFUNC_llExecFunc(processBatchDoActions)
 	action_t *pAction = (action_t*) pData;
 	batch_t *pBatch = (batch_t*) pParam;
 
-	assert(pAction != NULL);
-
-#warning execonly when prev suspended functionality missing!
-#if 0	// TODO: move this to the action object
-	if((pAction->bExecWhenPrevSusp  == 1) && (pDoActData->bPrevWasSuspended == 0)) {
-		dbgprintf("not calling action because the previous one is not suspended\n");
-		ABORT_FINALIZE(RS_RET_OK);
-	}
-#endif
-
+	DBGPRINTF("Processing next action\n");
 	iRetMod = pAction->submitToActQ(pAction, pBatch);
 
-#if 0 // TODO: this must be done inside the action as well!
-	if(iRetMod == RS_RET_DISCARDMSG) {
-		ABORT_FINALIZE(RS_RET_DISCARDMSG);
-	} else if(iRetMod == RS_RET_SUSPENDED) {
-		/* indicate suspension for next module to be called */
-		pDoActData->bPrevWasSuspended = 1;
-	} else {
-		pDoActData->bPrevWasSuspended = 0;
-	}
-#endif
-
 	RETiRet;
 }
 
@@ -291,11 +271,15 @@ processBatch(rule_t *pThis, batch_t *pBatch)
 	ISOBJ_TYPE_assert(pThis, rule);
 	assert(pBatch != NULL);
 
-	/* first check the filters... */
+	/* first check the filters and reset status variables */
 	for(i = 0 ; i < batchNumMsgs(pBatch) && !*(pBatch->pbShutdownImmediate) ; ++i) {
 		CHKiRet(shouldProcessThisMessage(pThis, (msg_t*)(pBatch->pElem[i].pUsrp),
 						 &(pBatch->pElem[i].bFilterOK)));
 		// TODO: really abort on error? 2010-06-10
+		if(pBatch->pElem[i].bFilterOK) {
+			/* re-init only when actually needed (cache write cost!) */
+			pBatch->pElem[i].bPrevWasSuspended = 0;
+		}
 	}
 	CHKiRet(llExecFunc(&pThis->llActList, processBatchDoActions, pBatch));
 
diff --git a/runtime/ruleset.c b/runtime/ruleset.c
index 8d6a1c2f..df7f8daa 100644
--- a/runtime/ruleset.c
+++ b/runtime/ruleset.c
@@ -146,6 +146,7 @@ DEFFUNC_llExecFunc(processBatchDoRules)
 {
 	rsRetVal iRet;
 	ISOBJ_TYPE_assert(pData, rule);
+	dbgprintf("Processing next rule\n");
 	iRet = rule.ProcessBatch((rule_t*) pData, (batch_t*) pParam);
 dbgprintf("ruleset: get iRet %d from rule.ProcessMsg()\n", iRet);
 	return iRet;
diff --git a/tests/Makefile.am b/tests/Makefile.am
index ba0bb7ba..a0cc8c7d 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -35,6 +35,10 @@ TESTS = $(TESTRUNS) cfg.sh \
 	queue-persist.sh \
 	pipeaction.sh \
 	execonlyonce.sh \
+	execonlywhenprevsuspended.sh \
+	execonlywhenprevsuspended2.sh \
+	execonlywhenprevsuspended3.sh \
+	execonlywhenprevsuspended4.sh \
 	pipe_noreader.sh \
 	dircreate_dflt.sh \
 	dircreate_off.sh \
@@ -269,6 +273,14 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \
 	   execonlyonce.sh \
 	   testsuites/execonlyonce.conf \
 	   testsuites/execonlyonce.data \
+	   execonlywhenprevsuspended.sh \
+	   testsuites/execonlywhenprevsuspended.sh \
+	   execonlywhenprevsuspended2.sh \
+	   testsuites/execonlywhenprevsuspended2.sh \
+	   execonlywhenprevsuspended3.sh \
+	   testsuites/execonlywhenprevsuspended3.sh \
+	   execonlywhenprevsuspended4.sh \
+	   testsuites/execonlywhenprevsuspended4.sh \
 	   tabescape_dflt.sh \
 	   testsuites/tabescape_dflt.conf \
 	   testsuites/1.tabescape_dflt \
diff --git a/tests/diag.sh b/tests/diag.sh
index 5b74a6dc..3d072880 100755
--- a/tests/diag.sh
+++ b/tests/diag.sh
@@ -19,7 +19,7 @@ case $1 in
 		rm -f rsyslog.action.*.include
 		rm -f rsyslogd.started work-*.conf rsyslog.random.data
 		rm -f rsyslogd2.started work-*.conf
-		rm -f work rsyslog.out.log rsyslog.out.log.save # common work files
+		rm -f work rsyslog.out.log rsyslog2.out.log rsyslog.out.log.save # common work files
 		rm -rf test-spool test-logdir
 		rm -f rsyslog.out.*.log work-presort rsyslog.pipe
 		rm -f core.* vgcore.*
@@ -27,7 +27,7 @@ case $1 in
 		;;
    'exit')	rm -f rsyslogd.started work-*.conf diag-common.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 work rsyslog.out.log rsyslog2.out.log rsyslog.out.log.save # common work files
 		rm -rf test-spool test-logdir 
 		rm -f rsyslog.out.*.log rsyslog.random.data work-presort rsyslog.pipe
 		echo  -------------------------------------------------------------------------------
@@ -115,7 +115,8 @@ case $1 in
 		rm -f work2
 		sort < rsyslog2.out.log > work2
 		# $4... are just to have the abilit to pass in more options...
-		./chkseq -fwork2 -v -s$2 -e$3 $4 $5 $6 $7
+		# add -v to chkseq if you need more verbose output
+		./chkseq -fwork2 -s$2 -e$3 $4 $5 $6 $7
 		if [ "$?" -ne "0" ]; then
 		  echo "sequence error detected"
 		  exit 1
diff --git a/tests/execonlywhenprevsuspended.sh b/tests/execonlywhenprevsuspended.sh
new file mode 100755
index 00000000..624f64af
--- /dev/null
+++ b/tests/execonlywhenprevsuspended.sh
@@ -0,0 +1,13 @@
+# we test the execonly if previous is suspended directive. This is the
+# most basic test which soley tests a singel case but no dependencies within
+# the ruleset.
+# rgerhards, 2010-06-23
+echo =====================================================================================
+echo \[execonlywhenprevsuspended.sh\]: test execonly...suspended functionality simple case
+source $srcdir/diag.sh init
+source $srcdir/diag.sh startup execonlywhenprevsuspended.conf
+source $srcdir/diag.sh injectmsg 0 1000
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown
+source $srcdir/diag.sh seq-check 1 999
+source $srcdir/diag.sh exit
diff --git a/tests/execonlywhenprevsuspended2.sh b/tests/execonlywhenprevsuspended2.sh
new file mode 100755
index 00000000..8af1b4d8
--- /dev/null
+++ b/tests/execonlywhenprevsuspended2.sh
@@ -0,0 +1,17 @@
+# we test the execonly if previous is suspended directive. For this,
+# we have an action that is suspended for all messages but the second.
+# we write two files: one only if the output is suspended and the other one
+# in all cases. This should thouroughly check the logic involved.
+# rgerhards, 2010-06-23
+echo ===============================================================================
+echo \[execonlywhenprevsuspended2.sh\]: test execonly...suspended functionality
+source $srcdir/diag.sh init
+source $srcdir/diag.sh startup execonlywhenprevsuspended2.conf
+source $srcdir/diag.sh injectmsg 0 1000
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown
+echo check file 1
+source $srcdir/diag.sh seq-check 1 999
+echo check file 2
+source $srcdir/diag.sh seq-check2 0 999
+source $srcdir/diag.sh exit
diff --git a/tests/execonlywhenprevsuspended3.sh b/tests/execonlywhenprevsuspended3.sh
new file mode 100755
index 00000000..408aeba4
--- /dev/null
+++ b/tests/execonlywhenprevsuspended3.sh
@@ -0,0 +1,17 @@
+# we test the execonly if previous is suspended directive.
+# This test checks if, within the same rule, one action can be set
+# to emit only if the previous was suspended while the next action
+# always sends data.
+# rgerhards, 2010-06-24
+echo ===============================================================================
+echo \[execonlywhenprevsuspended3.sh\]: test execonly...suspended functionality
+source $srcdir/diag.sh init
+source $srcdir/diag.sh startup execonlywhenprevsuspended3.conf
+source $srcdir/diag.sh injectmsg 0 1000
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown
+echo check file 1
+source $srcdir/diag.sh seq-check 1 999
+echo check file 2
+source $srcdir/diag.sh seq-check2 0 999
+source $srcdir/diag.sh exit
diff --git a/tests/execonlywhenprevsuspended4.sh b/tests/execonlywhenprevsuspended4.sh
new file mode 100755
index 00000000..87008b33
--- /dev/null
+++ b/tests/execonlywhenprevsuspended4.sh
@@ -0,0 +1,16 @@
+# we test the execonly if previous is suspended directive.
+# This test checks if multiple backup actions can be defined.
+# rgerhards, 2010-06-24
+echo ===============================================================================
+echo \[execonlywhenprevsuspended4.sh\]: test execonly..suspended multi backup action
+source $srcdir/diag.sh init
+source $srcdir/diag.sh startup execonlywhenprevsuspended4.conf
+source $srcdir/diag.sh injectmsg 0 1000
+source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages
+source $srcdir/diag.sh wait-shutdown
+source $srcdir/diag.sh seq-check 1 999
+if [[ -s rsyslog2.out.log ]] ; then
+   echo failure: second output file has data where it should be empty
+   exit 1
+fi ;
+source $srcdir/diag.sh exit
diff --git a/tests/testsuites/execonlywhenprevsuspended.conf b/tests/testsuites/execonlywhenprevsuspended.conf
new file mode 100644
index 00000000..04dc6b59
--- /dev/null
+++ b/tests/testsuites/execonlywhenprevsuspended.conf
@@ -0,0 +1,13 @@
+# See main .sh file for info
+# rgerhards, 2010-06-23
+$IncludeConfig diag-common.conf
+
+# omtesting provides the ability to cause "SUSPENDED" action state
+$ModLoad ../plugins/omtesting/.libs/omtesting
+
+$MainMsgQueueTimeoutShutdown 100000
+$template outfmt,"%msg:F,58:2%\n"
+
+:msg, contains, "msgnum:" :omtesting:fail 2 0
+$ActionExecOnlyWhenPreviousIsSuspended on
+&			   ./rsyslog.out.log;outfmt
diff --git a/tests/testsuites/execonlywhenprevsuspended2.conf b/tests/testsuites/execonlywhenprevsuspended2.conf
new file mode 100644
index 00000000..86aa8832
--- /dev/null
+++ b/tests/testsuites/execonlywhenprevsuspended2.conf
@@ -0,0 +1,19 @@
+# See main .sh file for info
+# rgerhards, 2010-06-23
+$IncludeConfig diag-common.conf
+
+# omtesting provides the ability to cause "SUSPENDED" action state
+$ModLoad ../plugins/omtesting/.libs/omtesting
+
+$MainMsgQueueTimeoutShutdown 100000
+$template outfmt,"%msg:F,58:2%\n"
+
+:msg, contains, "msgnum:" :omtesting:fail 2 0
+$ActionExecOnlyWhenPreviousIsSuspended on
+&			   ./rsyslog.out.log;outfmt
+# note that we MUST re-set PrevSusp, else it will remain active
+# for all other actions as well (this tells us how bad the current
+# config language is...). -- rgerhards, 2010-06-24
+$ActionExecOnlyWhenPreviousIsSuspended off
+
+:msg, contains, "msgnum:" ./rsyslog2.out.log;outfmt
diff --git a/tests/testsuites/execonlywhenprevsuspended3.conf b/tests/testsuites/execonlywhenprevsuspended3.conf
new file mode 100644
index 00000000..d2750e9a
--- /dev/null
+++ b/tests/testsuites/execonlywhenprevsuspended3.conf
@@ -0,0 +1,18 @@
+# See main .sh file for info
+# rgerhards, 2010-06-23
+$IncludeConfig diag-common.conf
+
+# omtesting provides the ability to cause "SUSPENDED" action state
+$ModLoad ../plugins/omtesting/.libs/omtesting
+
+$MainMsgQueueTimeoutShutdown 100000
+$template outfmt,"%msg:F,58:2%\n"
+
+:msg, contains, "msgnum:" :omtesting:fail 2 0
+$ActionExecOnlyWhenPreviousIsSuspended on
+&			   ./rsyslog.out.log;outfmt
+# note that we MUST re-set PrevSusp, else it will remain active
+# for all other actions as well (this tells us how bad the current
+# config language is...). -- rgerhards, 2010-06-24
+$ActionExecOnlyWhenPreviousIsSuspended off
+& ./rsyslog2.out.log;outfmt
diff --git a/tests/testsuites/execonlywhenprevsuspended4.conf b/tests/testsuites/execonlywhenprevsuspended4.conf
new file mode 100644
index 00000000..04bc3805
--- /dev/null
+++ b/tests/testsuites/execonlywhenprevsuspended4.conf
@@ -0,0 +1,15 @@
+# See main .sh file for info
+# rgerhards, 2010-06-23
+$IncludeConfig diag-common.conf
+
+# omtesting provides the ability to cause "SUSPENDED" action state
+$ModLoad ../plugins/omtesting/.libs/omtesting
+
+$MainMsgQueueTimeoutShutdown 100000
+$template outfmt,"%msg:F,58:2%\n"
+
+:msg, contains, "msgnum:" :omtesting:fail 2 0
+$ActionExecOnlyWhenPreviousIsSuspended on
+&			   ./rsyslog.out.log;outfmt
+# note that $ActionExecOnlyWhenPreviousIsSuspended on is still active!
+& ./rsyslog2.out.log;outfmt