From eb704286810bfd558b5fe43c1a50837c1b61f62c Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 10 Sep 2009 13:56:08 +0200 Subject: minor: optimized dbgprintf() use --- action.c | 34 +++++++++++++++++----------------- 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/action.c b/action.c index bcb23659..80ed1a61 100644 --- a/action.c +++ b/action.c @@ -324,7 +324,7 @@ actionConstructFinalize(action_t *pThis) CHKiRet(qqueueStart(pThis->pQueue)); - dbgprintf("Action %p: queue %p created\n", pThis, pThis->pQueue); + DBGPRINTF("Action %p: queue %p created\n", pThis, pThis->pQueue); /* and now reset the queue params (see comment in its function header!) */ actionResetQueueParams(); @@ -412,7 +412,7 @@ static rsRetVal actionTryResume(action_t *pThis) if(iRet == RS_RET_OK) actionResume(pThis); - dbgprintf("actionTryResume: iRet: %d, next retry (if applicable): %u [now %u]\n", + DBGPRINTF("actionTryResume: iRet: %d, next retry (if applicable): %u [now %u]\n", iRet, (unsigned) pThis->ttResumeRtry, (unsigned) ttNow); RETiRet; @@ -511,7 +511,7 @@ actionCallDoAction(action_t *pAction, msg_t *pMsg) /* call configured action */ iRet = pAction->pMod->mod.om.doAction(pAction->ppMsgs, pMsg->msgFlags, pAction->pModData); if(iRet == RS_RET_SUSPENDED) { - dbgprintf("Action requested to be suspended, done that.\n"); + DBGPRINTF("Action requested to be suspended, done that.\n"); actionSuspend(pAction, getActNow(pAction)); } } @@ -519,7 +519,7 @@ actionCallDoAction(action_t *pAction, msg_t *pMsg) } while(iRet == RS_RET_SUSPENDED && (pAction->iResumeRetryCount == -1 || iRetries < pAction->iResumeRetryCount)); /* do...while! */ if(iRet == RS_RET_DISABLE_ACTION) { - dbgprintf("Action requested to be disabled, done that.\n"); + DBGPRINTF("Action requested to be disabled, done that.\n"); pAction->bEnabled = 0; /* that's it... */ } @@ -595,16 +595,16 @@ static rsRetVal setActionQueType(void __attribute__((unused)) *pVal, uchar *pszT if (!strcasecmp((char *) pszType, "fixedarray")) { ActionQueType = QUEUETYPE_FIXED_ARRAY; - dbgprintf("action queue type set to FIXED_ARRAY\n"); + DBGPRINTF("action queue type set to FIXED_ARRAY\n"); } else if (!strcasecmp((char *) pszType, "linkedlist")) { ActionQueType = QUEUETYPE_LINKEDLIST; - dbgprintf("action queue type set to LINKEDLIST\n"); + DBGPRINTF("action queue type set to LINKEDLIST\n"); } else if (!strcasecmp((char *) pszType, "disk")) { ActionQueType = QUEUETYPE_DISK; - dbgprintf("action queue type set to DISK\n"); + DBGPRINTF("action queue type set to DISK\n"); } else if (!strcasecmp((char *) pszType, "direct")) { ActionQueType = QUEUETYPE_DIRECT; - dbgprintf("action queue type set to DIRECT (no queueing at all)\n"); + DBGPRINTF("action queue type set to DIRECT (no queueing at all)\n"); } else { errmsg.LogError(0, RS_RET_INVALID_PARAMS, "unknown actionqueue parameter: %s", (char *) pszType); iRet = RS_RET_INVALID_PARAMS; @@ -650,14 +650,14 @@ actionWriteToAction(action_t *pAction) /* we need to care about multiple occurences */ if( pAction->iExecEveryNthOccurTO > 0 && (getActNow(pAction) - pAction->tLastOccur) > pAction->iExecEveryNthOccurTO) { - dbgprintf("n-th occurence handling timed out (%d sec), restarting from 0\n", + DBGPRINTF("n-th occurence handling timed out (%d sec), restarting from 0\n", (int) (getActNow(pAction) - pAction->tLastOccur)); pAction->iNbrNoExec = 0; pAction->tLastOccur = getActNow(pAction); } if(pAction->iNbrNoExec < pAction->iExecEveryNthOccur - 1) { ++pAction->iNbrNoExec; - dbgprintf("action %p passed %d times to execution - less than neded - discarding\n", + DBGPRINTF("action %p passed %d times to execution - less than neded - discarding\n", pAction, pAction->iNbrNoExec); FINALIZE; } else { @@ -680,7 +680,7 @@ actionWriteToAction(action_t *pAction) if((pMsg = MsgDup(pAction->f_pMsg)) == NULL) { /* it failed - nothing we can do against it... */ - dbgprintf("Message duplication failed, dropping repeat message.\n"); + DBGPRINTF("Message duplication failed, dropping repeat message.\n"); ABORT_FINALIZE(RS_RET_ERR); } @@ -702,7 +702,7 @@ actionWriteToAction(action_t *pAction) pAction->f_pMsg = pMsg; /* use the new msg (pointer will be restored below) */ } - dbgprintf("Called action, logging to %s\n", module.GetStateName(pAction->pMod)); + DBGPRINTF("Called action, logging to %s\n", module.GetStateName(pAction->pMod)); /* now check if we need to drop the message because otherwise the action would be too * frequently called. -- rgerhards, 2008-04-08 @@ -713,7 +713,7 @@ actionWriteToAction(action_t *pAction) 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", + DBGPRINTF("action not yet ready again to be executed, onceInterval %d, tCurr %d, tNext %d\n", (int) pAction->iSecsExecOnceInterval, (int) getActNow(pAction), (int) (pAction->iSecsExecOnceInterval + pAction->tLastExec)); pAction->tLastExec = getActNow(pAction); /* re-init time flags */ @@ -786,7 +786,7 @@ doActionCallAction(action_t *pAction, msg_t *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", + 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) */ @@ -909,7 +909,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques assert(ppAction != NULL); assert(pMod != NULL); assert(pOMSR != NULL); - dbgprintf("Module %s processed this config line.\n", module.GetName(pMod)); + DBGPRINTF("Module %s processed this config line.\n", module.GetName(pMod)); CHKiRet(actionConstruct(&pAction)); /* create action object first */ pAction->pMod = pMod; @@ -968,7 +968,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques pAction->eParamPassing = ACT_STRING_PASSING; } - dbgprintf("template: '%s' assigned\n", pTplName); + DBGPRINTF("template: '%s' assigned\n", pTplName); } pAction->pMod = pMod; @@ -977,7 +977,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques if(pMod->isCompatibleWithFeature(sFEATURERepeatedMsgReduction) == RS_RET_OK) pAction->f_ReduceRepeated = bReduceRepeatMsgs; else { - dbgprintf("module is incompatible with RepeatedMsgReduction - turned off\n"); + DBGPRINTF("module is incompatible with RepeatedMsgReduction - turned off\n"); pAction->f_ReduceRepeated = 0; } pAction->bEnabled = 1; /* action is enabled */ -- cgit v1.2.3 From 78e9c7c4d2c4ec09cce403066f09a5a7e08e994e Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 10 Sep 2009 15:04:08 +0200 Subject: bugfix: repeated messages were incorrectly processed this could lead to loss of the repeated message content. As a side- effect, it could probably also be possible that some segfault occurs (quite unlikely). The root cause was that some counters introduced during the malloc optimizations were not properly duplicated in MsgDup(). Note that repeated message processing is not enabled by default. --- ChangeLog | 7 +++++++ runtime/msg.c | 11 ++++++++--- 2 files changed, 15 insertions(+), 3 deletions(-) diff --git a/ChangeLog b/ChangeLog index fb4bb2d9..1a8cb598 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,12 @@ --------------------------------------------------------------------------- Version 4.5.3 [v4-beta] (rgerhards), 2009-08-?? +- bugfix: repeated messages were incorrectly processed + this could lead to loss of the repeated message content. As a side- + effect, it could probably also be possible that some segfault occurs + (quite unlikely). The root cause was that some counters introduced + during the malloc optimizations were not properly duplicated in + MsgDup(). Note that repeated message processing is not enabled + by default. - bugfix: message sanitation had some issues: - control character DEL was not properly escaped - NUL and LF characters were not properly stripped if no control diff --git a/runtime/msg.c b/runtime/msg.c index de298871..2a370618 100644 --- a/runtime/msg.c +++ b/runtime/msg.c @@ -864,13 +864,17 @@ msg_t* MsgDup(msg_t* pOld) pNew->iProtocolVersion = pOld->iProtocolVersion; pNew->ttGenTime = pOld->ttGenTime; pNew->offMSG = pOld->offMSG; + pNew->iLenRawMsg = pOld->iLenRawMsg; + pNew->iLenMSG = pOld->iLenMSG; + pNew->iLenTAG = pOld->iLenTAG; + pNew->iLenHOSTNAME = pOld->iLenHOSTNAME; if(pOld->pRcvFrom != NULL) { pNew->pRcvFrom = pOld->pRcvFrom; prop.AddRef(pNew->pRcvFrom); } if(pOld->pRcvFromIP != NULL) { pNew->pRcvFromIP = pOld->pRcvFromIP; - prop.AddRef(pNew->pRcvFromIP); /* XXX */ + prop.AddRef(pNew->pRcvFromIP); } if(pOld->pInputName != NULL) { pNew->pInputName = pOld->pInputName; @@ -1972,10 +1976,11 @@ rsRetVal MsgReplaceMSG(msg_t *pThis, uchar* pszMSG, int lenMSG) lenNew = pThis->iLenRawMsg + lenMSG - pThis->iLenMSG; if(lenMSG > pThis->iLenMSG && lenNew >= CONF_RAWMSG_BUFSIZE) { - /* we have lost and need to alloc a new buffer ;) */ + /* we have lost our "bet" and need to alloc a new buffer ;) */ CHKmalloc(bufNew = malloc(lenNew + 1)); memcpy(bufNew, pThis->pszRawMsg, pThis->offMSG); - free(pThis->pszRawMsg); + if(pThis->pszRawMsg != pThis->szRawMsg) + free(pThis->pszRawMsg); pThis->pszRawMsg = bufNew; } -- cgit v1.2.3 From 6e1f0d4f70073b4a52f94d7bfe7afa82a3b5075e Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 10 Sep 2009 15:29:22 +0200 Subject: minor: optimized dbgprintf() calling sequence --- action.c | 34 +++++++++++++++++----------------- 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/action.c b/action.c index d8ccafb6..d22d6d6d 100644 --- a/action.c +++ b/action.c @@ -333,7 +333,7 @@ actionConstructFinalize(action_t *pThis) CHKiRet(qqueueStart(pThis->pQueue)); - dbgprintf("Action %p: queue %p created\n", pThis, pThis->pQueue); + DBGPRINTF("Action %p: queue %p created\n", pThis, pThis->pQueue); /* and now reset the queue params (see comment in its function header!) */ actionResetQueueParams(); @@ -547,7 +547,7 @@ static rsRetVal actionTryResume(action_t *pThis) } if(Debug && (pThis->eState == ACT_STATE_RTRY ||pThis->eState == ACT_STATE_SUSP)) { - dbgprintf("actionTryResume: action state: %s, next retry (if applicable): %u [now %u]\n", + DBGPRINTF("actionTryResume: action state: %s, next retry (if applicable): %u [now %u]\n", getActStateName(pThis), (unsigned) pThis->ttResumeRtry, (unsigned) ttNow); } @@ -815,10 +815,10 @@ tryDoAction(action_t *pAction, batch_t *pBatch, int *pnElem) iCommittedUpTo = i; while(iElemProcessed <= *pnElem && i < pBatch->nElem) { pMsg = (msg_t*) pBatch->pElem[i].pUsrp; - dbgprintf("submitBatch: i:%d, batch size %d, to process %d, pMsg: %p, state %d\n", i, pBatch->nElem, *pnElem, pMsg, pBatch->pElem[i].state);//remove later! + DBGPRINTF("submitBatch: i:%d, batch size %d, to process %d, pMsg: %p, state %d\n", i, pBatch->nElem, *pnElem, pMsg, pBatch->pElem[i].state);//remove later! if(pBatch->pElem[i].state != BATCH_STATE_DISC) { localRet = actionProcessMessage(pAction, pMsg); - dbgprintf("action call returned %d\n", localRet); + DBGPRINTF("action call returned %d\n", localRet); if(localRet == RS_RET_OK) { /* mark messages as committed */ while(iCommittedUpTo < i) { @@ -1012,16 +1012,16 @@ static rsRetVal setActionQueType(void __attribute__((unused)) *pVal, uchar *pszT if (!strcasecmp((char *) pszType, "fixedarray")) { ActionQueType = QUEUETYPE_FIXED_ARRAY; - dbgprintf("action queue type set to FIXED_ARRAY\n"); + DBGPRINTF("action queue type set to FIXED_ARRAY\n"); } else if (!strcasecmp((char *) pszType, "linkedlist")) { ActionQueType = QUEUETYPE_LINKEDLIST; - dbgprintf("action queue type set to LINKEDLIST\n"); + DBGPRINTF("action queue type set to LINKEDLIST\n"); } else if (!strcasecmp((char *) pszType, "disk")) { ActionQueType = QUEUETYPE_DISK; - dbgprintf("action queue type set to DISK\n"); + DBGPRINTF("action queue type set to DISK\n"); } else if (!strcasecmp((char *) pszType, "direct")) { ActionQueType = QUEUETYPE_DIRECT; - dbgprintf("action queue type set to DIRECT (no queueing at all)\n"); + DBGPRINTF("action queue type set to DIRECT (no queueing at all)\n"); } else { errmsg.LogError(0, RS_RET_INVALID_PARAMS, "unknown actionqueue parameter: %s", (char *) pszType); iRet = RS_RET_INVALID_PARAMS; @@ -1067,14 +1067,14 @@ actionWriteToAction(action_t *pAction) /* we need to care about multiple occurences */ if( pAction->iExecEveryNthOccurTO > 0 && (getActNow(pAction) - pAction->tLastOccur) > pAction->iExecEveryNthOccurTO) { - dbgprintf("n-th occurence handling timed out (%d sec), restarting from 0\n", + DBGPRINTF("n-th occurence handling timed out (%d sec), restarting from 0\n", (int) (getActNow(pAction) - pAction->tLastOccur)); pAction->iNbrNoExec = 0; pAction->tLastOccur = getActNow(pAction); } if(pAction->iNbrNoExec < pAction->iExecEveryNthOccur - 1) { ++pAction->iNbrNoExec; - dbgprintf("action %p passed %d times to execution - less than neded - discarding\n", + DBGPRINTF("action %p passed %d times to execution - less than neded - discarding\n", pAction, pAction->iNbrNoExec); FINALIZE; } else { @@ -1097,7 +1097,7 @@ actionWriteToAction(action_t *pAction) if((pMsg = MsgDup(pAction->f_pMsg)) == NULL) { /* it failed - nothing we can do against it... */ - dbgprintf("Message duplication failed, dropping repeat message.\n"); + DBGPRINTF("Message duplication failed, dropping repeat message.\n"); ABORT_FINALIZE(RS_RET_ERR); } @@ -1119,7 +1119,7 @@ actionWriteToAction(action_t *pAction) pAction->f_pMsg = pMsg; /* use the new msg (pointer will be restored below) */ } - dbgprintf("Called action, logging to %s\n", module.GetStateName(pAction->pMod)); + DBGPRINTF("Called action, logging to %s\n", module.GetStateName(pAction->pMod)); /* now check if we need to drop the message because otherwise the action would be too * frequently called. -- rgerhards, 2008-04-08 @@ -1130,7 +1130,7 @@ actionWriteToAction(action_t *pAction) 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", + DBGPRINTF("action not yet ready again to be executed, onceInterval %d, tCurr %d, tNext %d\n", (int) pAction->iSecsExecOnceInterval, (int) getActNow(pAction), (int) (pAction->iSecsExecOnceInterval + pAction->tLastExec)); pAction->tLastExec = getActNow(pAction); /* re-init time flags */ @@ -1191,7 +1191,7 @@ doActionCallAction(action_t *pAction, msg_t *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", + 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) */ @@ -1319,7 +1319,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques assert(ppAction != NULL); assert(pMod != NULL); assert(pOMSR != NULL); - dbgprintf("Module %s processed this config line.\n", module.GetName(pMod)); + DBGPRINTF("Module %s processed this config line.\n", module.GetName(pMod)); CHKiRet(actionConstruct(&pAction)); /* create action object first */ pAction->pMod = pMod; @@ -1380,7 +1380,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques pAction->eParamPassing = ACT_STRING_PASSING; } - dbgprintf("template: '%s' assigned\n", pTplName); + DBGPRINTF("template: '%s' assigned\n", pTplName); } pAction->pMod = pMod; @@ -1389,7 +1389,7 @@ addAction(action_t **ppAction, modInfo_t *pMod, void *pModData, omodStringReques if(pMod->isCompatibleWithFeature(sFEATURERepeatedMsgReduction) == RS_RET_OK) pAction->f_ReduceRepeated = bReduceRepeatMsgs; else { - dbgprintf("module is incompatible with RepeatedMsgReduction - turned off\n"); + DBGPRINTF("module is incompatible with RepeatedMsgReduction - turned off\n"); pAction->f_ReduceRepeated = 0; } pAction->eState = ACT_STATE_RDY; /* action is enabled */ -- cgit v1.2.3