summaryrefslogtreecommitdiffstats
path: root/action.c
diff options
context:
space:
mode:
Diffstat (limited to 'action.c')
-rw-r--r--action.c101
1 files changed, 72 insertions, 29 deletions
diff --git a/action.c b/action.c
index 4cfe5f07..5c5bdbe9 100644
--- a/action.c
+++ b/action.c
@@ -91,6 +91,44 @@ static int iActionNbr = 0;
/* ------------------------------ methods ------------------------------ */
+/* This function returns the "current" time for this action. Current time
+ * is not necessarily real-time. In order to enhance performance, current
+ * system time is obtained the first time an action needs to know the time
+ * and then kept cached inside the action structure. Later requests will
+ * always return that very same time. Wile not totally accurate, it is far
+ * accurate in most cases and considered "acurate enough" for all cases.
+ * When changing the threading model, please keep in mind that this
+ * logic needs to be changed should we once allow more than one parallel
+ * call into the same action (object). As this is currently not supported,
+ * we simply cache the time inside the action object itself, after it
+ * is under mutex protection.
+ * Side-note: the value -1 is used as tActNow, because it also is the
+ * error return value of time(). So we would do a retry with the next
+ * invocation if time() failed. Then, of course, we would probably already
+ * be in trouble, but for the sake of performance we accept this very,
+ * very slight risk.
+ * This logic has been added as part of an overall performance improvment
+ * effort inspired by David Lang. -- rgerhards, 2008-09-16
+ * Note: this function does not use the usual iRet call conventions
+ * because that would provide little to no benefit but complicate things
+ * a lot. So we simply return the system time.
+ */
+static inline time_t
+getActNow(action_t *pThis)
+{
+ assert(pThis != NULL);
+ if(pThis->tActNow == -1) {
+ pThis->tActNow = time(NULL); /* good time call - the only one done */
+ if(pThis->tLastExec > pThis->tActNow) {
+ /* if we are traveling back in time, reset tLastExec */
+ pThis->tLastExec = (time_t) 0;
+ }
+ }
+
+ return pThis->tActNow;
+}
+
+
/* resets action queue parameters to their default values. This happens
* after each action has been created in order to prevent any wild defaults
* to be used. It is somewhat against the original spirit of the config file
@@ -176,7 +214,7 @@ rsRetVal actionConstruct(action_t **ppThis)
pThis->iResumeInterval = glbliActionResumeInterval;
pThis->iResumeRetryCount = glbliActionResumeRetryCount;
- pThis->tLastOccur = time(NULL);
+ pThis->tLastOccur = time(NULL); /* done once per action on startup only */
pthread_mutex_init(&pThis->mutActExec, NULL);
SYNC_OBJ_TOOL_INIT(pThis);
@@ -290,30 +328,31 @@ rsRetVal actionSetGlobalResumeInterval(int iNewVal)
/* suspend an action -- rgerhards, 2007-08-02
*/
-rsRetVal actionSuspend(action_t *pThis)
+static rsRetVal actionSuspend(action_t *pThis, time_t tNow)
{
DEFiRet;
ASSERT(pThis != NULL);
pThis->bSuspended = 1;
- pThis->ttResumeRtry = time(NULL) + pThis->iResumeInterval;
+ pThis->ttResumeRtry = tNow + pThis->iResumeInterval;
pThis->iNbrResRtry = 0; /* tell that we did not yet retry to resume */
RETiRet;
}
+
/* try to resume an action -- rgerhards, 2007-08-02
* returns RS_RET_OK if resumption worked, RS_RET_SUSPEND if the
* action is still suspended.
*/
-rsRetVal actionTryResume(action_t *pThis)
+static rsRetVal actionTryResume(action_t *pThis)
{
DEFiRet;
time_t ttNow;
ASSERT(pThis != NULL);
- ttNow = time(NULL); /* do the system call just once */
+ ttNow = getActNow(pThis); /* cache "now" */
/* first check if it is time for a re-try */
if(ttNow > pThis->ttResumeRtry) {
@@ -432,7 +471,7 @@ actionCallDoAction(action_t *pAction, msg_t *pMsg)
iRet = pAction->pMod->mod.om.doAction(ppMsgs, pMsg->msgFlags, pAction->pModData);
if(iRet == RS_RET_SUSPENDED) {
dbgprintf("Action requested to be suspended, done that.\n");
- actionSuspend(pAction);
+ actionSuspend(pAction, getActNow(pAction));
}
}
@@ -509,15 +548,9 @@ actionWriteToAction(action_t *pAction)
{
msg_t *pMsgSave; /* to save current message pointer, necessary to restore
it in case it needs to be updated (e.g. repeated msgs) */
- time_t now;
DEFiRet;
pMsgSave = NULL; /* indicate message poiner not saved */
- time(&now); /* we need this for several use cases, but obtain it once for performance reasons */
- if(pAction->tLastExec > now) {
- /* if we are traveling back in time, reset tLastExec */
- pAction->tLastExec = (time_t) 0;
- }
/* first, we check if the action should actually be called. The action-specific
* $ActionExecOnlyEveryNthTime permits us to execute an action only every Nth
@@ -529,11 +562,11 @@ actionWriteToAction(action_t *pAction)
if(pAction->iExecEveryNthOccur > 1) {
/* we need to care about multiple occurences */
if( pAction->iExecEveryNthOccurTO > 0
- && (now - pAction->tLastOccur) > pAction->iExecEveryNthOccurTO) {
+ && (getActNow(pAction) - pAction->tLastOccur) > pAction->iExecEveryNthOccurTO) {
dbgprintf("n-th occurence handling timed out (%d sec), restarting from 0\n",
- (int) (now - pAction->tLastOccur));
+ (int) (getActNow(pAction) - pAction->tLastOccur));
pAction->iNbrNoExec = 0;
- pAction->tLastOccur = now;
+ pAction->tLastOccur = getActNow(pAction);
}
if(pAction->iNbrNoExec < pAction->iExecEveryNthOccur - 1) {
++pAction->iNbrNoExec;
@@ -570,7 +603,7 @@ actionWriteToAction(action_t *pAction)
* signatures inside the message are also invalidated.
*/
datetime.getCurrTime(&(pMsg->tRcvdAt));
- datetime.getCurrTime(&(pMsg->tTIMESTAMP));
+ memcpy(&pMsg->tTIMESTAMP, &pMsg->tRcvdAt, sizeof(struct syslogTime));
MsgSetMSG(pMsg, (char*)szRepMsg);
MsgSetRawMsg(pMsg, (char*)szRepMsg);
@@ -582,17 +615,23 @@ actionWriteToAction(action_t *pAction)
/* now check if we need to drop the message because otherwise the action would be too
* frequently called. -- rgerhards, 2008-04-08
+ * Note that the check for "pAction->iSecsExecOnceInterval > 0" is not necessary from
+ * a purely logical point of view. However, if safes us to check the system time in
+ * (those common) cases where ExecOnceInterval is not used. -- rgerhards, 2008-09-16
*/
- if(pAction->f_time != 0 && pAction->iSecsExecOnceInterval + pAction->tLastExec > now) {
+ if(pAction->f_time != 0 && pAction->iSecsExecOnceInterval > 0 &&
+ pAction->iSecsExecOnceInterval + pAction->tLastExec > getActNow(pAction)) {
/* in this case we need to discard the message - its not yet time to exec the action */
dbgprintf("action not yet ready again to be executed, onceInterval %d, tCurr %d, tNext %d\n",
- (int) pAction->iSecsExecOnceInterval, (int) now,
+ (int) pAction->iSecsExecOnceInterval, (int) getActNow(pAction),
(int) (pAction->iSecsExecOnceInterval + pAction->tLastExec));
FINALIZE;
}
- pAction->tLastExec = now; /* we need this OnceInterval */
- pAction->f_time = now; /* we need this for message repeation processing */
+ pAction->f_time = pAction->tLastExec = getActNow(pAction); /* re-init time flags */
+ /* Note: tLastExec could be set in the if block above, but f_time causes us a hard time
+ * so far, I do not see a solution to getting rid of it. -- rgerhards, 2008-09-16
+ */
/* When we reach this point, we have a valid, non-disabled action.
* So let's enqueue our message for execution. -- rgerhards, 2007-07-24
@@ -623,6 +662,10 @@ finalize_it:
/* call the configured action. Does all necessary housekeeping.
* rgerhards, 2007-08-01
+ * FYI: currently, this function is only called from the queue
+ * consumer. So we (conceptually) run detached from the input
+ * threads (which also means we may run much later than when the
+ * message was generated).
*/
#pragma GCC diagnostic ignored "-Wempty-body"
rsRetVal
@@ -657,13 +700,14 @@ actionCallAction(action_t *pAction, msg_t *pMsg)
ABORT_FINALIZE(RS_RET_OK);
}
- /* don't output marks to recently written files */
- if ((pMsg->msgFlags & MARK) && (time(NULL) - pAction->f_time) < MarkInterval / 2) {
+ pAction->tActNow = -1; /* we do not yet know our current time (clear prev. value) */
+
+ /* don't output marks to recently written outputs */
+ if((pMsg->msgFlags & MARK) && (getActNow(pAction) - pAction->f_time) < MarkInterval / 2) {
ABORT_FINALIZE(RS_RET_OK);
}
- /* suppress duplicate messages
- */
+ /* suppress duplicate messages */
if ((pAction->f_ReduceRepeated == 1) && pAction->f_pMsg != NULL &&
(pMsg->msgFlags & MARK) == 0 && getMSGLen(pMsg) == getMSGLen(pAction->f_pMsg) &&
!strcmp(getMSG(pMsg), getMSG(pAction->f_pMsg)) &&
@@ -672,7 +716,7 @@ actionCallAction(action_t *pAction, msg_t *pMsg)
!strcmp(getAPPNAME(pMsg), getAPPNAME(pAction->f_pMsg))) {
pAction->f_prevcount++;
dbgprintf("msg repeated %d times, %ld sec of %d.\n",
- pAction->f_prevcount, (long) time(NULL) - pAction->f_time,
+ 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);
@@ -680,12 +724,11 @@ actionCallAction(action_t *pAction, msg_t *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(time(NULL) > REPEATTIME(pAction)) {
+ if(getActNow(pAction) > REPEATTIME(pAction)) {
iRet = actionWriteToAction(pAction);
BACKOFF(pAction);
}
- } else {
- /* new message, save it */
+ } else {/* new message, save it */
/* first check if we have a previous message stored
* if so, emit and then discard it first
*/
@@ -830,7 +873,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques
pAction->bEnabled = 1; /* action is enabled */
if(bSuspended)
- actionSuspend(pAction);
+ actionSuspend(pAction, time(NULL)); /* "good" time call, only during init and unavoidable */
CHKiRet(actionConstructFinalize(pAction));
generated by cgit (git 2.34.1) at 2024-11-11 02:31:39 +0000