- improved diagnostic information for abort cases

- some initial effort for malloc/free debugging support
- bugfix: using dynafile actions caused rsyslogd abort

6 files changed, 73 insertions, 19 deletions

diff --git a/ChangeLog b/ChangeLog
index fadf928c..411675da 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -19,6 +19,9 @@ Version 3.11.1 (rgerhards), 2008-02-12
 - bugfix: setting for $EscapeCopntrolCharactersOnReceive was not 
   properly initialized
 - clarified usage of space-cc property replacer option
+- improved abort diagnostic handler
+- some initial effort for malloc/free runtime debugging support
+- bugfix: using dynafile actions caused rsyslogd abort
 ---------------------------------------------------------------------------
 Version 3.11.0 (rgerhards), 2008-01-31
 - implemented queued actions
diff --git a/action.c b/action.c
index 5fab8ec6..f655fc0f 100644
--- a/action.c
+++ b/action.c
@@ -111,7 +111,7 @@ actionResetQueueParams(void)
 	glbliActionResumeRetryCount = 0;		/* I guess it is smart to reset this one, too */
 
 	if(pszActionQFName != NULL)
-		free(pszActionQFName);
+		d_free(pszActionQFName);
 	pszActionQFName = NULL;				/* prefix for the main message queue file */
 
 	RETiRet;
@@ -123,6 +123,7 @@ actionResetQueueParams(void)
  */
 rsRetVal actionDestruct(action_t *pThis)
 {
+	DEFiRet;
 	ASSERT(pThis != NULL);
 
 	queueDestruct(&pThis->pQueue);
@@ -136,10 +137,10 @@ rsRetVal actionDestruct(action_t *pThis)
 	SYNC_OBJ_TOOL_EXIT(pThis);
 	pthread_mutex_destroy(&pThis->mutActExec);
 	if(pThis->ppTpl != NULL)
-		free(pThis->ppTpl);
-	free(pThis);
+		d_free(pThis->ppTpl);
+	d_free(pThis);
 	
-	return RS_RET_OK;
+	RETiRet;
 }
 
 
@@ -366,6 +367,11 @@ actionCallDoAction(action_t *pAction, msg_t *pMsg)
 	for(i = 0 ; i < pAction->iNumTpls ; ++i) {
 		CHKiRet(tplToString(pAction->ppTpl[i], pMsg, &(ppMsgs[i])));
 	}
+for(i = 0 ; i < pAction->iNumTpls ; ++i) {
+RUNLOG_VAR("%d", i);
+RUNLOG_VAR("%s", ppMsgs[i]);
+RUNLOG_VAR("%p", &ppMsgs[i]);
+}
 	iRetries = 0;
 	/* We now must guard the output module against execution by multiple threads. The
 	 * plugin interface specifies that output modules must not be thread-safe (except
@@ -402,6 +408,11 @@ actionCallDoAction(action_t *pAction, msg_t *pMsg)
 				dbgprintf("Action requested to be suspended, done that.\n");
 				actionSuspend(pAction);
 			}
+for(i = 0 ; i < pAction->iNumTpls ; ++i) {
+RUNLOG_VAR("%d", i);
+RUNLOG_VAR("%s", ppMsgs[i]);
+RUNLOG_VAR("%p", &ppMsgs[i]);
+}
 		}
 
 	} while(iRet == RS_RET_SUSPENDED && (pAction->iResumeRetryCount == -1 || iRetries < pAction->iResumeRetryCount)); /* do...while! */
@@ -417,10 +428,10 @@ finalize_it:
 	/* cleanup */
 	for(i = 0 ; i < pAction->iNumTpls ; ++i) {
 		if(ppMsgs[i] != NULL) {
-			free(ppMsgs[i]);
+			d_free(ppMsgs[i]);
 		}
-		free(ppMsgs);
 	}
+	d_free(ppMsgs);
 	msgDestruct(&pMsg); /* we are now finished with the message */
 
 	RETiRet;
@@ -450,7 +461,7 @@ static rsRetVal setActionQueType(void __attribute__((unused)) *pVal, uchar *pszT
 		logerrorSz("unknown actionqueue parameter: %s", (char *) pszType);
 		iRet = RS_RET_INVALID_PARAMS;
 	}
-	free(pszType); /* no longer needed */
+	d_free(pszType); /* no longer needed */
 
 	RETiRet;
 }
diff --git a/debug.c b/debug.c
index b46c17b0..d634b247 100644
--- a/debug.c
+++ b/debug.c
@@ -547,6 +547,21 @@ int dbgCondTimedWait(pthread_cond_t *cond, pthread_mutex_t *pmut, const struct t
 
 /* ------------------------- end mutex tracking code ------------------------- */ 
 
+
+/* ------------------------- malloc/free tracking code ------------------------- */ 
+
+/* wrapper for free() */
+void dbgFree(void *pMem, dbgFuncDB_t *pFuncDB, int ln, int iStackPtr)
+{
+	dbgRecordExecLocation(iStackPtr, ln);
+	dbgprintf("%s:%d:%s: free %p\n", pFuncDB->file,
+		  ln, pFuncDB->func, (void*) pMem);
+	free(pMem);
+}
+
+
+/* ------------------------- end malloc/free tracking code ------------------------- */ 
+
 /* ------------------------- thread tracking code ------------------------- */ 
 
 /* get ptr to call stack - if none exists, create a new stack
@@ -670,17 +685,30 @@ void
 sigsegvHdlr(int signum)
 {
 	char *signame;
+	struct sigaction sigAct;
+
+	/* first, restore the default abort handler */
+	memset(&sigAct, 0, sizeof (sigAct));
+	sigemptyset(&sigAct.sa_mask);
+	sigAct.sa_handler = SIG_DFL;
+	sigaction(SIGABRT, &sigAct, NULL);
 
+	/* then do our actual processing */
 	if(signum == SIGSEGV) {
 		signame = " (SIGSEGV)";
+	} else if(signum == SIGABRT) {
+		signame = " (SIGABRT)";
 	} else {
 		signame = "";
 	}
 
-	dbgprintf("\n\n\n\nSignal %d%s occured, execution must be terminated %d.\n\n\n\n", signum, signame, SIGSEGV);
+	dbgprintf("\n\n\n\nSignal %d%s occured, execution must be terminated.\n\n\n\n", signum, signame);
 
 	dbgPrintAllDebugInfo();
 
+	dbgprintf("If the call trace is empty, you may want to ./configure --enable-rtinst\n");
+	dbgprintf("\n\nTo submit bug reports, visit http://www.rsyslog.com/bugs\n\n");
+
 	fflush(stddbg);
 
 	/* and finally abort... */
diff --git a/debug.h b/debug.h
index df8c3138..bcc0dda5 100644
--- a/debug.h
+++ b/debug.h
@@ -91,6 +91,7 @@ int dbgMutexLock(pthread_mutex_t *pmut, dbgFuncDB_t *pFuncD, int ln, int iStackP
 int dbgMutexUnlock(pthread_mutex_t *pmut, dbgFuncDB_t *pFuncD, int ln, int iStackPtr);
 int dbgCondWait(pthread_cond_t *cond, pthread_mutex_t *pmut, dbgFuncDB_t *pFuncD, int ln, int iStackPtr);
 int dbgCondTimedWait(pthread_cond_t *cond, pthread_mutex_t *pmut, const struct timespec *abstime, dbgFuncDB_t *pFuncD, int ln, int iStackPtr);
+void dbgFree(void *pMem, dbgFuncDB_t *pFuncDB, int ln, int iStackPtr);
 int dbgEntrFunc(dbgFuncDB_t *pFuncDB, int line);
 void dbgExitFunc(dbgFuncDB_t *pFuncDB, int iStackPtrRestore);
 void dbgSetExecLocation(int iStackPtr, int line);
@@ -131,10 +132,12 @@ void dbgPrintAllDebugInfo(void);
 #define d_pthread_mutex_unlock(x)    dbgMutexUnlock(x, &dbgFuncDB, __LINE__, dbgCALLStaCK_POP_POINT )
 #define d_pthread_cond_wait(cond, mut)   dbgCondWait(cond, mut, &dbgFuncDB, __LINE__, dbgCALLStaCK_POP_POINT )
 #define d_pthread_cond_timedwait(cond, mut, to)   dbgCondTimedWait(cond, mut, to, &dbgFuncDB, __LINE__, dbgCALLStaCK_POP_POINT )
+#define d_free(x)      dbgFree(x, &dbgFuncDB, __LINE__, dbgCALLStaCK_POP_POINT )
 #else
 #define d_pthread_mutex_lock(x)     pthread_mutex_lock(x)
 #define d_pthread_mutex_unlock(x)   pthread_mutex_unlock(x)
 #define d_pthread_cond_wait(cond, mut)   pthread_cond_wait(cond, mut)
 #define d_pthread_cond_timedwait(cond, mut, to)   pthread_cond_timedwait(cond, mut, to)
+#define d_free(x)      free(x)
 #endif
 #endif /* #ifndef DEBUG_H_INCLUDED */
diff --git a/omfile.c b/omfile.c
index 1fa96c6c..21569155 100644
--- a/omfile.c
+++ b/omfile.c
@@ -259,7 +259,7 @@ int resolveFileSizeLimit(instanceData *pData)
 	uchar *pCmd;
 	uchar *p;
 	off_t actualFileSize;
-	assert(pData != NULL);
+	ASSERT(pData != NULL);
 
 	if(pData->f_sizeLimitCmd == NULL)
 		return 1; /* nothing we can do in this case... */
@@ -309,14 +309,16 @@ int resolveFileSizeLimit(instanceData *pData)
  * as the index of the to-be-deleted entry. This index may
  * point to an unallocated entry, in whcih case the
  * function immediately returns. Parameter bFreeEntry is 1
- * if the entry should be free()ed and 0 if not.
+ * if the entry should be d_free()ed and 0 if not.
  */
 static void dynaFileDelCacheEntry(dynaFileCacheEntry **pCache, int iEntry, int bFreeEntry)
 {
-	assert(pCache != NULL);
+	ASSERT(pCache != NULL);
+
+	BEGINfunc;
 
 	if(pCache[iEntry] == NULL)
-		return;
+		FINALIZE;
 
 	dbgprintf("Removed entry %d for file '%s' from dynaCache.\n", iEntry,
 		pCache[iEntry]->pName == NULL ? "[OPEN FAILED]" : (char*)pCache[iEntry]->pName);
@@ -326,14 +328,17 @@ static void dynaFileDelCacheEntry(dynaFileCacheEntry **pCache, int iEntry, int b
 	 */
 	if(pCache[iEntry]->pName != NULL) {
 		close(pCache[iEntry]->fd);
-		free(pCache[iEntry]->pName);
+		d_free(pCache[iEntry]->pName);
 		pCache[iEntry]->pName = NULL;
 	}
 
 	if(bFreeEntry) {
-		free(pCache[iEntry]);
+		d_free(pCache[iEntry]);
 		pCache[iEntry] = NULL;
 	}
+
+finalize_it:
+	ENDfunc;
 }
 
 
@@ -342,13 +347,15 @@ static void dynaFileDelCacheEntry(dynaFileCacheEntry **pCache, int iEntry, int b
 static void dynaFileFreeCache(instanceData *pData)
 {
 	register int i;
-	assert(pData != NULL);
+	ASSERT(pData != NULL);
 
+	BEGINfunc;
 	for(i = 0 ; i < pData->iCurrCacheSize ; ++i) {
 		dynaFileDelCacheEntry(pData->dynCache, i, 1);
 	}
 
-	free(pData->dynCache);
+	d_free(pData->dynCache);
+	ENDfunc;
 }
 
 
@@ -413,8 +420,8 @@ static int prepareDynFile(instanceData *pData, uchar *newFileName, unsigned iMsg
 	int iFirstFree;
 	dynaFileCacheEntry **pCache;
 
-	assert(pData != NULL);
-	assert(newFileName != NULL);
+	ASSERT(pData != NULL);
+	ASSERT(newFileName != NULL);
 
 	pCache = pData->dynCache;
 
@@ -511,7 +518,7 @@ static rsRetVal writeFile(uchar **ppString, unsigned iMsgOpts, instanceData *pDa
 	off_t actualFileSize;
 	DEFiRet;
 
-	assert(pData != NULL);
+	ASSERT(pData != NULL);
 
 	/* first check if we have a dynamic file name and, if so,
 	 * check if it still is ok or a new file needs to be created
diff --git a/syslogd.c b/syslogd.c
index 6841a6a9..f42f48a9 100644
--- a/syslogd.c
+++ b/syslogd.c
@@ -4827,6 +4827,8 @@ int realMain(int argc, char **argv)
 
 	sigAct.sa_handler = sigsegvHdlr;
 	sigaction(SIGSEGV, &sigAct, NULL);
+sigAct.sa_handler = sigsegvHdlr;
+sigaction(SIGABRT, &sigAct, NULL);
 	sigAct.sa_handler = doDie;
 	sigaction(SIGTERM, &sigAct, NULL);
 	sigAct.sa_handler = Debug ? doDie : SIG_IGN;