diff options
-rw-r--r-- | action.c | 142 | ||||
-rw-r--r-- | action.h | 11 | ||||
-rw-r--r-- | dirty.h | 11 | ||||
-rw-r--r-- | runtime/conf.c | 9 | ||||
-rwxr-xr-x | tests/diag.sh | 6 | ||||
-rw-r--r-- | tests/runtime-dummy.c | 1 | ||||
-rw-r--r-- | tools/syslogd.c | 78 |
7 files changed, 26 insertions, 232 deletions
@@ -12,11 +12,11 @@ * necessary to triple-check that everything works well in *all* modes. * The different modes (and calling sequence) are: * - * if set iExecEveryNthOccur > 1 || f_ReduceRepeated || iSecsExecOnceInterval + * if set iExecEveryNthOccur > 1 || iSecsExecOnceInterval * - doSubmitToActionQComplexBatch * - helperSubmitToActionQComplexBatch * - doActionCallAction - * handles duplicate message processing, but in essence calls + * handles mark message reduction, but in essence calls * - actionWriteToAction * - qqueueEnqObj * (now queue engine processing) @@ -307,9 +307,6 @@ rsRetVal actionDestruct(action_t *pThis) if(pThis->pMod != NULL) pThis->pMod->freeInstance(pThis->pModData); - if(pThis->f_pMsg != NULL) - msgDestruct(&pThis->f_pMsg); - pthread_mutex_destroy(&pThis->mutAction); pthread_mutex_destroy(&pThis->mutActExec); d_free(pThis->pszName); @@ -410,16 +407,11 @@ actionConstructFinalize(action_t *pThis, struct cnfparamvals *queueParams) * mode is much faster processing (and simpler code) -- rgerhards, 2010-06-08 */ if( pThis->iExecEveryNthOccur > 1 - || pThis->f_ReduceRepeated || pThis->iSecsExecOnceInterval ) { DBGPRINTF("info: firehose mode disabled for action because " - "iExecEveryNthOccur=%d, " - "ReduceRepeated=%d, " - "iSecsExecOnceInterval=%d\n", - pThis->iExecEveryNthOccur, pThis->f_ReduceRepeated, - pThis->iSecsExecOnceInterval - ); + "iExecEveryNthOccur=%d, iSecsExecOnceInterval=%d\n", + pThis->iExecEveryNthOccur, pThis->iSecsExecOnceInterval); pThis->submitToActQ = doSubmitToActionQComplexBatch; } else if(pThis->bWriteAllMarkMsgs == RSFALSE) { /* nearly full-speed submission mode, default case */ @@ -782,7 +774,6 @@ rsRetVal actionDbgPrint(action_t *pThis) pThis->pMod->dbgPrintInstInfo(pThis->pModData); dbgprintf("\n"); dbgprintf("\tInstance data: 0x%lx\n", (unsigned long) pThis->pModData); - dbgprintf("\tRepeatedMsgReduction: %d\n", pThis->f_ReduceRepeated); dbgprintf("\tResume Interval: %d\n", pThis->iResumeInterval); if(pThis->eState == ACT_STATE_SUSP) { dbgprintf("\tresume next retry: %u, number retries: %d", @@ -1418,14 +1409,10 @@ finalize_it: * be filtered out before calling us (what is done currently!). */ rsRetVal -actionWriteToAction(action_t *pAction) +actionWriteToAction(action_t *pAction, msg_t *pMsg) { - msg_t *pMsgSave; /* to save current message pointer, necessary to restore - it in case it needs to be updated (e.g. repeated msgs) */ DEFiRet; - pMsgSave = NULL; /* indicate message poiner not saved */ - /* first, we check if the action should actually be called. The action-specific * $ActionExecOnlyEveryNthTime permits us to execute an action only every Nth * time. So we need to check if we need to drop the (otherwise perfectly executable) @@ -1452,43 +1439,6 @@ actionWriteToAction(action_t *pAction) } } - /* then check if this is a regular message or the repeation of - * a previous message. If so, we need to change the message text - * to "last message repeated n times" and then go ahead and write - * it. Please note that we can not modify the message object, because - * that would update it in other selectors as well. As such, we first - * need to create a local copy of the message, which we than can update. - * rgerhards, 2007-07-10 - */ - if(pAction->f_prevcount > 1) { - msg_t *pMsg; - size_t lenRepMsg; - uchar szRepMsg[1024]; - - if((pMsg = MsgDup(pAction->f_pMsg)) == NULL) { - /* it failed - nothing we can do against it... */ - DBGPRINTF("Message duplication failed, dropping repeat message.\n"); - ABORT_FINALIZE(RS_RET_ERR); - } - - if(pAction->bRepMsgHasMsg == 0) { /* old format repeat message? */ - lenRepMsg = snprintf((char*)szRepMsg, sizeof(szRepMsg), " last message repeated %d times", - pAction->f_prevcount); - } else { - lenRepMsg = snprintf((char*)szRepMsg, sizeof(szRepMsg), " message repeated %d times: [%.800s]", - pAction->f_prevcount, getMSG(pAction->f_pMsg)); - } - - /* We now need to update the other message properties. Please note that digital - * signatures inside the message are also invalidated. - */ - datetime.getCurrTime(&(pMsg->tRcvdAt), &(pMsg->ttGenTime)); - memcpy(&pMsg->tTIMESTAMP, &pMsg->tRcvdAt, sizeof(struct syslogTime)); - MsgReplaceMSG(pMsg, szRepMsg, lenRepMsg); - pMsgSave = pAction->f_pMsg; /* save message pointer for later restoration */ - pAction->f_pMsg = pMsg; /* use the new msg (pointer will be restored below) */ - } - DBGPRINTF("Called action(complex case), logging to %s\n", module.GetStateName(pAction->pMod)); /* now check if we need to drop the message because otherwise the action would be too @@ -1509,31 +1459,14 @@ actionWriteToAction(action_t *pAction) /* we use reception time, not dequeue time - this is considered more appropriate and also faster ;) * rgerhards, 2008-09-17 */ pAction->tLastExec = getActNow(pAction); /* re-init time flags */ - pAction->f_time = pAction->f_pMsg->ttGenTime; + pAction->f_time = pMsg->ttGenTime; /* When we reach this point, we have a valid, non-disabled action. * So let's enqueue our message for execution. -- rgerhards, 2007-07-24 */ - iRet = doSubmitToActionQ(pAction, pAction->f_pMsg); - - if(iRet == RS_RET_OK) - pAction->f_prevcount = 0; /* message processed, so we start a new cycle */ + iRet = doSubmitToActionQ(pAction, pMsg); finalize_it: - if(pMsgSave != NULL) { - /* we had saved the original message pointer. That was - * done because we needed to create a temporary one - * (most often for "message repeated n time" handling). If so, - * we need to restore the original one now, so that procesing - * can continue as normal. We also need to discard the temporary - * one, as we do not like memory leaks ;) Please note that the original - * message object will be discarded by our callers, so this is nothing - * of our business. rgerhards, 2007-07-10 - */ - msgDestruct(&pAction->f_pMsg); - pAction->f_pMsg = pMsgSave; /* restore it */ - } - RETiRet; } @@ -1556,43 +1489,8 @@ doActionCallAction(action_t *pAction, batch_t *pBatch, int idxBtch) ABORT_FINALIZE(RS_RET_OK); } - /* suppress duplicate messages */ - if ((pAction->f_ReduceRepeated == 1) && pAction->f_pMsg != NULL && - (pMsg->msgFlags & MARK) == 0 && getMSGLen(pMsg) == getMSGLen(pAction->f_pMsg) && - !ustrcmp(getMSG(pMsg), getMSG(pAction->f_pMsg)) && - !strcmp(getHOSTNAME(pMsg), getHOSTNAME(pAction->f_pMsg)) && - !strcmp(getPROCID(pMsg, LOCK_MUTEX), getPROCID(pAction->f_pMsg, LOCK_MUTEX)) && - !strcmp(getAPPNAME(pMsg, LOCK_MUTEX), getAPPNAME(pAction->f_pMsg, LOCK_MUTEX))) { - pAction->f_prevcount++; - DBGPRINTF("msg repeated %d times, %ld sec of %d.\n", - pAction->f_prevcount, (long) getActNow(pAction) - pAction->f_time, - repeatinterval[pAction->f_repeatcount]); - /* use current message, so we have the new timestamp (means we need to discard previous one) */ - msgDestruct(&pAction->f_pMsg); - pAction->f_pMsg = MsgAddRef(pMsg); - /* If domark would have logged this by now, flush it now (so we don't hold - * isolated messages), but back off so we'll flush less often in the future. - */ - if(getActNow(pAction) > REPEATTIME(pAction)) { - iRet = actionWriteToAction(pAction); - BACKOFF(pAction); - } - } else {/* new message, save it */ - /* first check if we have a previous message stored - * if so, emit and then discard it first - */ - if(pAction->f_pMsg != NULL) { - if(pAction->f_prevcount > 0) - actionWriteToAction(pAction); - /* we do not care about iRet above - I think it's right but if we have - * some troubles, you know where to look at ;) -- rgerhards, 2007-08-01 - */ - msgDestruct(&pAction->f_pMsg); - } - pAction->f_pMsg = MsgAddRef(pMsg); - /* call the output driver */ - iRet = actionWriteToAction(pAction); - } + /* call the output driver */ + iRet = actionWriteToAction(pAction, pMsg); finalize_it: /* we need to update the batch to handle failover processing correctly */ @@ -1890,13 +1788,16 @@ actionRequiresDateCall(action_t *pAction) int i; int r = 0; + if(pAction->eParamPassing == ACT_MSG_PASSING) + /* in msg passing mode, we have NO templates! */ + goto done; for(i = 0 ; i < pAction->iNumTpls ; ++i) { if(tplRequiresDateCall(pAction->ppTpl[i])) { r = 1; break; } } - return r; +done: return r; } @@ -1995,13 +1896,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, pAction->pMod = pMod; pAction->pModData = pModData; - /* now check if the module is compatible with select features */ - if(pMod->isCompatibleWithFeature(sFEATURERepeatedMsgReduction) == RS_RET_OK) { - pAction->f_ReduceRepeated = loadConf->globals.bReduceRepeatMsgs; - } else { - DBGPRINTF("module is incompatible with RepeatedMsgReduction - turned off\n"); - pAction->f_ReduceRepeated = 0; - } + /* check if the module is compatible with select features (currently no such features exist) */ pAction->eState = ACT_STATE_RDY; /* action is enabled */ pAction->requiresDateCall = actionRequiresDateCall(pAction); @@ -2102,13 +1997,8 @@ actionNewInst(struct nvlst *lst, action_t **ppAction) if((iRet = addAction(&pAction, pMod, pModData, pOMSR, paramvals, queueParams, (iRet == RS_RET_SUSPENDED)? 1 : 0)) == RS_RET_OK) { - /* now check if the module is compatible with select features */ - if(pMod->isCompatibleWithFeature(sFEATURERepeatedMsgReduction) == RS_RET_OK) - pAction->f_ReduceRepeated = loadConf->globals.bReduceRepeatMsgs; - else { - DBGPRINTF("module is incompatible with RepeatedMsgReduction - turned off\n"); - pAction->f_ReduceRepeated = 0; - } + /* check if the module is compatible with select features + * (currently no such features exist) */ pAction->eState = ACT_STATE_RDY; /* action is enabled */ loadConf->actions.nbrActions++; /* one more active action! */ } @@ -48,7 +48,7 @@ typedef enum { */ typedef struct action_s action_t; struct action_s { - time_t f_time; /* used for "message repeated n times" - be careful, old, old code */ + time_t f_time; /* used for "max. n messages in m seconds" processing */ time_t tActNow; /* the current time for an action execution. Initially set to -1 and populated on an as-needed basis. This is a performance optimization. */ time_t tLastExec; /* time this action was last executed */ @@ -69,10 +69,7 @@ struct action_s { struct modInfo_s *pMod;/* pointer to output module handling this selector */ void *pModData; /* pointer to module data - content is module-specific */ sbool bRepMsgHasMsg; /* "message repeated..." has msg fragment in it (0-no, 1-yes) */ - short f_ReduceRepeated;/* reduce repeated lines 0 - no, 1 - yes */ sbool requiresDateCall;/* do we need to do a date call before creating templates? */ - int f_prevcount; /* repetition cnt of prevline */ - int f_repeatcount; /* number of "repeated" msgs */ rsRetVal (*submitToActQ)(action_t *, batch_t *);/* function submit message to action queue */ rsRetVal (*qConstruct)(struct queue_s *pThis); enum { ACT_STRING_PASSING = 0, ACT_ARRAY_PASSING = 1, ACT_MSG_PASSING = 2, @@ -81,10 +78,6 @@ struct action_s { int iNumTpls; /* number of array entries for template element below */ struct template **ppTpl;/* array of template to use - strings must be passed to doAction * in this order. */ - msg_t *f_pMsg; /* pointer to the message (this will replace the other vars with msg - * content later). This is preserved after the message has been - * processed - it is also used to detect duplicates. - */ qqueue_t *pQueue; /* action queue */ pthread_mutex_t mutAction; /* primary action mutex */ pthread_mutex_t mutActExec; /* mutex to guard actual execution of doAction for single-threaded modules */ @@ -105,7 +98,7 @@ rsRetVal actionDestruct(action_t *pThis); rsRetVal actionDbgPrint(action_t *pThis); rsRetVal actionSetGlobalResumeInterval(int iNewVal); rsRetVal actionDoAction(action_t *pAction); -rsRetVal actionWriteToAction(action_t *pAction); +rsRetVal actionWriteToAction(action_t *pAction, msg_t *pMsg); rsRetVal actionCallHUPHdlr(action_t *pAction); rsRetVal actionClassInit(void); rsRetVal addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringRequest_t *pOMSR, struct cnfparamvals *actParams, struct cnfparamvals *queueParams, int bSuspended); @@ -37,19 +37,8 @@ rsRetVal __attribute__((deprecated)) parseAndSubmitMessage(uchar *hname, uchar * rsRetVal diagGetMainMsgQSize(int *piSize); /* for imdiag */ rsRetVal createMainQueue(qqueue_t **ppQueue, uchar *pszQueueName); -/* Intervals at which we flush out "message repeated" messages, - * in seconds after previous message is logged. After each flush, - * we move to the next interval until we reach the largest. - * TODO: move this to action object! Only action.c and syslogd.c use it. - */ extern int MarkInterval; -extern int repeatinterval[2]; extern qqueue_t *pMsgQueue; /* the main message queue */ extern int iConfigVerify; /* is this just a config verify run? */ extern int bHaveMainQueue; -#define MAXREPEAT ((int)((sizeof(repeatinterval) / sizeof(repeatinterval[0])) - 1)) -#define REPEATTIME(f) ((f)->f_time + repeatinterval[(f)->f_repeatcount]) -#define BACKOFF(f) { if (++(f)->f_repeatcount > MAXREPEAT) \ - (f)->f_repeatcount = MAXREPEAT; \ - } #endif /* #ifndef DIRTY_H_INCLUDED */ diff --git a/runtime/conf.c b/runtime/conf.c index 23fb6bbd..c97391c6 100644 --- a/runtime/conf.c +++ b/runtime/conf.c @@ -607,13 +607,8 @@ rsRetVal cflineDoAction(rsconf_t *conf, uchar **p, action_t **ppAction) if(iRet == RS_RET_OK || iRet == RS_RET_SUSPENDED) { if((iRet = addAction(&pAction, pMod, pModData, pOMSR, NULL, NULL, (iRet == RS_RET_SUSPENDED)? 1 : 0)) == RS_RET_OK) { - /* now check if the module is compatible with select features */ - if(pMod->isCompatibleWithFeature(sFEATURERepeatedMsgReduction) == RS_RET_OK) - pAction->f_ReduceRepeated = loadConf->globals.bReduceRepeatMsgs; - else { - dbgprintf("module is incompatible with RepeatedMsgReduction - turned off\n"); - pAction->f_ReduceRepeated = 0; - } + /* here check if the module is compatible with select features + * (currently, we have no such features!) */ pAction->eState = ACT_STATE_RDY; /* action is enabled */ conf->actions.nbrActions++; /* one more active action! */ } diff --git a/tests/diag.sh b/tests/diag.sh index b278d2c5..0cbf7abb 100755 --- a/tests/diag.sh +++ b/tests/diag.sh @@ -5,13 +5,13 @@ # not always able to convey back states to the upper-level test driver # begun 2009-05-27 by rgerhards # This file is part of the rsyslog project, released under GPLv3 -#valgrind="valgrind --malloc-fill=ff --free-fill=fe --log-fd=1" +valgrind="valgrind --malloc-fill=ff --free-fill=fe --log-fd=1" #valgrind="valgrind --tool=drd --log-fd=1" #valgrind="valgrind --tool=helgrind --log-fd=1" #valgrind="valgrind --tool=exp-ptrcheck --log-fd=1" #set -o xtrace -#export RSYSLOG_DEBUG="debug nologfuncflow noprintmutexaction nostdout" -#export RSYSLOG_DEBUGLOG="log" +export RSYSLOG_DEBUG="debug nologfuncflow noprintmutexaction nostdout" +export RSYSLOG_DEBUGLOG="log" case $1 in 'init') $srcdir/killrsyslog.sh # kill rsyslogd if it runs for some reason cp $srcdir/testsuites/diag-common.conf diag-common.conf diff --git a/tests/runtime-dummy.c b/tests/runtime-dummy.c index 5a9039bf..f6f2d07f 100644 --- a/tests/runtime-dummy.c +++ b/tests/runtime-dummy.c @@ -30,7 +30,6 @@ #include "rsyslog.h" int bReduceRepeatMsgs = 0; -int repeatinterval = 30; int bActExecWhenPrevSusp = 0; int iActExecOnceInterval = 1; int MarkInterval = 30; diff --git a/tools/syslogd.c b/tools/syslogd.c index cb6a47cd..3e85108f 100644 --- a/tools/syslogd.c +++ b/tools/syslogd.c @@ -44,7 +44,6 @@ #include "rsyslog.h" #define DEFUPRI (LOG_USER|LOG_NOTICE) -#define TIMERINTVL 30 /* interval for checking flush, mark */ #include <unistd.h> #include <stdlib.h> @@ -204,13 +203,6 @@ static int bFinished = 0; /* used by termination signal handler, read-only excep */ int iConfigVerify = 0; /* is this just a config verify run? */ -/* Intervals at which we flush out "message repeated" messages, - * in seconds after previous message is logged. After each flush, - * we move to the next interval until we reach the largest. - * TODO: this shall go into action object! -- rgerhards, 2008-01-29 - */ -int repeatinterval[2] = { 30, 60 }; /* # of secs before flush */ - #define LIST_DELIMITER ':' /* delimiter between two hosts */ static pid_t ppid; /* This is a quick and dirty hack used for spliting main/startup thread */ @@ -691,43 +683,6 @@ reapchild() } -/* helper to doFlushRptdMsgs() to flush the individual action links via llExecFunc - * rgerhards, 2007-08-02 - */ -DEFFUNC_llExecFunc(flushRptdMsgsActions) -{ - action_t *pAction = (action_t*) pData; - assert(pAction != NULL); - - BEGINfunc - d_pthread_mutex_lock(&pAction->mutAction); - /* TODO: time() performance: the call below could be moved to - * the beginn of the llExec(). This makes it slightly less correct, but - * in an acceptable way. -- rgerhards, 2008-09-16 - */ - if (pAction->f_prevcount && datetime.GetTime(NULL) >= REPEATTIME(pAction)) { - DBGPRINTF("flush %s: repeated %d times, %d sec.\n", - module.GetStateName(pAction->pMod), pAction->f_prevcount, - repeatinterval[pAction->f_repeatcount]); - actionWriteToAction(pAction); - BACKOFF(pAction); - } - d_pthread_mutex_unlock(&pAction->mutAction); - - ENDfunc - return RS_RET_OK; /* we ignore errors, we can not do anything either way */ -} - - -/* This method flushes repeat messages. - */ -static void -doFlushRptdMsgs(void) -{ - ruleset.IterateAllActions(runConf, flushRptdMsgsActions, NULL); -} - - static void debug_switch() { time_t tTime; @@ -1320,49 +1275,22 @@ mainloop(void) while(!bFinished){ /* this is now just a wait - please note that we do use a near-"eternal" - * timeout of 1 day if we do not have repeated message reduction turned on - * (which it is not by default). This enables us to help safe the environment + * timeout of 1 day. This enables us to help safe the environment * by not unnecessarily awaking rsyslog on a regular tick (just think * powertop, for example). In that case, we primarily wait for a signal, * but a once-a-day wakeup should be quite acceptable. -- rgerhards, 2008-06-09 */ - tvSelectTimeout.tv_sec = (runConf->globals.bReduceRepeatMsgs == 1) ? TIMERINTVL : 86400 /*1 day*/; - //tvSelectTimeout.tv_sec = TIMERINTVL; /* TODO: change this back to the above code when we have a better solution for apc */ + tvSelectTimeout.tv_sec = 86400 /*1 day*/; tvSelectTimeout.tv_usec = 0; select(1, NULL, NULL, NULL, &tvSelectTimeout); if(bFinished) - break; /* exit as quickly as possible - see long comment below */ - - /* If we received a HUP signal, we call doFlushRptdMsgs() a bit early. This - * doesn't matter, because doFlushRptdMsgs() checks timestamps. What may happen, - * however, is that the too-early call may lead to a bit too-late output - * of "last message repeated n times" messages. But that is quite acceptable. - * rgerhards, 2007-12-21 - * ... and just to explain, we flush here because that is exactly what the mainloop - * shall do - provide a periodic interval in which not-yet-flushed messages will - * be flushed. Be careful, there is a potential race condition: doFlushRptdMsgs() - * needs to aquire a lock on the action objects. If, however, long-running consumers - * cause the main queue worker threads to lock them for a long time, we may receive - * a starvation condition, resulting in the mainloop being held on lock for an extended - * period of time. That, in turn, could lead to unresponsiveness to termination - * requests. It is especially important that the bFinished flag is checked before - * doFlushRptdMsgs() is called (I know because I ran into that situation). I am - * not yet sure if the remaining probability window of a termination-related - * problem is large enough to justify changing the code - I would consider it - * extremely unlikely that the problem ever occurs in practice. Fixing it would - * require not only a lot of effort but would cost considerable performance. So - * for the time being, I think the remaining risk can be accepted. - * rgerhards, 2008-01-10 - */ - if(runConf->globals.bReduceRepeatMsgs == 1) - doFlushRptdMsgs(); + break; /* exit as quickly as possible */ if(bHadHUP) { doHUP(); bHadHUP = 0; continue; } - // TODO: remove execScheduled(); /* handle Apc calls (if any) */ } ENDfunc } |