summaryrefslogtreecommitdiffstats
path: root/runtime/debug.c
diff options
context:
space:
mode:
Diffstat (limited to 'runtime/debug.c')
-rw-r--r--runtime/debug.c236
1 files changed, 108 insertions, 128 deletions
diff --git a/runtime/debug.c b/runtime/debug.c
index 9d45c737..96004e47 100644
--- a/runtime/debug.c
+++ b/runtime/debug.c
@@ -1,3 +1,4 @@
+#include <sys/syscall.h>
/* debug.c
*
* This file proides debug and run time error analysis support. Some of the
@@ -43,6 +44,9 @@
#include <pthread.h>
#include <ctype.h>
#include <assert.h>
+#include <unistd.h>
+#include <fcntl.h>
+#include <sys/stat.h>
#include "rsyslog.h"
#include "debug.h"
@@ -62,8 +66,8 @@ static int bPrintTime = 1; /* print a timestamp together with debug message */
static int bPrintAllDebugOnExit = 0;
static int bAbortTrace = 1; /* print a trace after SIGABRT or SIGSEGV */
static char *pszAltDbgFileName = NULL; /* if set, debug output is *also* sent to here */
-static FILE *altdbg = NULL; /* and the handle for alternate debug output */
-static FILE *stddbg;
+static int altdbg = -1; /* and the handle for alternate debug output */
+static int stddbg;
/* list of files/objects that should be printed */
typedef struct dbgPrintName_s {
@@ -113,8 +117,7 @@ static dbgThrdInfo_t *dbgCallStackListRoot = NULL;
static dbgThrdInfo_t *dbgCallStackListLast = NULL;
static pthread_mutex_t mutCallStack;
-static pthread_mutex_t mutdbgprintf;
-static pthread_mutex_t mutdbgoprint;
+static pthread_mutex_t mutdbgprint;
static pthread_key_t keyCallStack;
@@ -529,7 +532,23 @@ static inline void dbgMutexUnlockLog(pthread_mutex_t *pmut, dbgFuncDB_t *pFuncDB
pthread_mutex_lock(&mutMutLog);
pLog = dbgMutLogFindSpecific(pmut, MUTOP_LOCK, NULL);
+#if 0 /* toggle for testing */
assert(pLog != NULL);
+#else
+/* the change below seems not to work - the problem seems to be a real race... I keep this code in just in case
+ * I need to re-use it. It should be removed once we are finished analyzing this problem. -- rgerhards, 2008-09-17
+ */
+if(pLog == NULL) {
+ /* this may happen due to some races. We do not try to avoid
+ * this, as it would complicate the "real" code. This is not justified
+ * just to keep the debug info system up. -- rgerhards, 2008-09-17
+ */
+ pthread_mutex_unlock(&mutMutLog);
+ dbgprintf("%s:%d:%s: mutex %p UNlocked [but we did not yet know this mutex!]\n",
+ pFuncDB->file, unlockLn, pFuncDB->func, (void*)pmut);
+ return; /* if we don't know it yet, we can not clean up... */
+}
+#endif
/* we found the last lock entry. We now need to see from which FuncDB we need to
* remove it. This is recorded inside the mutex log entry.
@@ -801,8 +820,6 @@ sigsegvHdlr(int signum)
}
dbgprintf("\n\nTo submit bug reports, visit http://www.rsyslog.com/bugs\n\n");
- if(stddbg != NULL) fflush(stddbg);
- if(altdbg != NULL) fflush(altdbg);
/* and finally abort... */
/* TODO: think about restarting rsyslog in this case: may be a good idea,
@@ -811,56 +828,47 @@ sigsegvHdlr(int signum)
abort();
}
-
+#if 1
#pragma GCC diagnostic ignored "-Wempty-body"
-/* print some debug output when an object is given
- * This is mostly a copy of dbgprintf, but I do not know how to combine it
- * into a single function as we have variable arguments and I don't know how to call
- * from one vararg function into another. I don't dig in this, it is OK for the
- * time being. -- rgerhards, 2008-01-29
+/* write the debug message. This is a helper to dbgprintf and dbgoprint which
+ * contains common code. added 2008-09-26 rgerhards
*/
-void
-dbgoprint(obj_t *pObj, char *fmt, ...)
+static void
+dbgprint(obj_t *pObj, char *pszMsg, size_t lenMsg)
{
static pthread_t ptLastThrdID = 0;
static int bWasNL = 0;
- va_list ap;
- static char pszThrdName[64]; /* 64 is to be on the safe side, anything over 20 is bad... */
- static char pszWriteBuf[1024];
+ char pszThrdName[64]; /* 64 is to be on the safe side, anything over 20 is bad... */
+ char pszWriteBuf[1024];
size_t lenWriteBuf;
struct timespec t;
+ uchar *pszObjName = NULL;
- if(!(Debug && debugging_on))
- return;
-
- /* a quick and very dirty hack to enable us to display just from those objects
- * that we are interested in. So far, this must be changed at compile time (and
- * chances are great it is commented out while you read it. Later, this shall
- * be selectable via the environment. -- rgerhards, 2008-02-20
+ /* we must get the object name before we lock the mutex, because the object
+ * potentially calls back into us. If we locked the mutex, we would deadlock
+ * ourselfs. On the other hand, the GetName call needs not to be protected, as
+ * this thread has a valid reference. If such an object is deleted by another
+ * thread, we are in much more trouble than just for dbgprint(). -- rgerhards, 2008-09-26
*/
-#if 0
- if(objGetObjID(pObj) != OBJexpr)
- return;
-#endif
-
+ if(pObj != NULL) {
+ pszObjName = obj.GetName(pObj);
+ }
- pthread_mutex_lock(&mutdbgoprint);
- pthread_cleanup_push(dbgMutexCancelCleanupHdlr, &mutdbgoprint);
+ pthread_mutex_lock(&mutdbgprint);
+ pthread_cleanup_push(dbgMutexCancelCleanupHdlr, &mutdbgprint);
/* The bWasNL handler does not really work. It works if no thread
* switching occurs during non-NL messages. Else, things are messed
* up. Anyhow, it works well enough to provide useful help during
* getting this up and running. It is questionable if the extra effort
- * is worth fixing it, giving the limited appliability.
- * rgerhards, 2005-10-25
+ * is worth fixing it, giving the limited appliability. -- rgerhards, 2005-10-25
* I have decided that it is not worth fixing it - especially as it works
- * pretty well.
- * rgerhards, 2007-06-15
+ * pretty well. -- rgerhards, 2007-06-15
*/
if(ptLastThrdID != pthread_self()) {
if(!bWasNL) {
- if(stddbg != NULL) fprintf(stddbg, "\n");
- if(altdbg != NULL) fprintf(altdbg, "\n");
+ if(stddbg != -1) write(stddbg, "\n", 1);
+ if(altdbg != -1) write(altdbg, "\n", 1);
bWasNL = 1;
}
ptLastThrdID = pthread_self();
@@ -874,113 +882,84 @@ dbgoprint(obj_t *pObj, char *fmt, ...)
if(bWasNL) {
if(bPrintTime) {
clock_gettime(CLOCK_REALTIME, &t);
- if(stddbg != NULL) fprintf(stddbg, "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
- if(altdbg != NULL) fprintf(altdbg, "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
+ lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf),
+ "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
+ if(stddbg != -1) write(stddbg, pszWriteBuf, lenWriteBuf);
+ if(altdbg != -1) write(altdbg, pszWriteBuf, lenWriteBuf);
}
- if(stddbg != NULL) fprintf(stddbg, "%s: ", pszThrdName);
- if(altdbg != NULL) fprintf(altdbg, "%s: ", pszThrdName);
+
+ lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf), "%s: ", pszThrdName);
+ // use for testing: lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf), "{%ld}%s: ", (long) syscall(SYS_gettid), pszThrdName);
+ if(stddbg != -1) write(stddbg, pszWriteBuf, lenWriteBuf);
+ if(altdbg != -1) write(altdbg, pszWriteBuf, lenWriteBuf);
/* print object name header if we have an object */
- if(pObj != NULL) {
- if(stddbg != NULL) fprintf(stddbg, "%s: ", obj.GetName(pObj));
- if(altdbg != NULL) fprintf(altdbg, "%s: ", obj.GetName(pObj));
+ if(pszObjName != NULL) {
+ lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf), "%s: ", pszObjName);
+ if(stddbg != -1) write(stddbg, pszWriteBuf, lenWriteBuf);
+ if(altdbg != -1) write(altdbg, pszWriteBuf, lenWriteBuf);
}
}
- bWasNL = (*(fmt + strlen(fmt) - 1) == '\n') ? 1 : 0;
+ if(stddbg != -1) write(stddbg, pszMsg, lenMsg);
+ if(altdbg != -1) write(altdbg, pszMsg, lenMsg);
+
+ bWasNL = (pszMsg[lenMsg - 1] == '\n') ? 1 : 0;
+
+ pthread_cleanup_pop(1);
+}
+#pragma GCC diagnostic warning "-Wempty-body"
+#endif
+
+/* print some debug output when an object is given
+ * This is mostly a copy of dbgprintf, but I do not know how to combine it
+ * into a single function as we have variable arguments and I don't know how to call
+ * from one vararg function into another. I don't dig in this, it is OK for the
+ * time being. -- rgerhards, 2008-01-29
+ */
+void
+dbgoprint(obj_t *pObj, char *fmt, ...)
+{
+ va_list ap;
+ char pszWriteBuf[1024];
+ size_t lenWriteBuf;
+
+ if(!(Debug && debugging_on))
+ return;
+
+ /* a quick and very dirty hack to enable us to display just from those objects
+ * that we are interested in. So far, this must be changed at compile time (and
+ * chances are great it is commented out while you read it. Later, this shall
+ * be selectable via the environment. -- rgerhards, 2008-02-20
+ */
+#if 0
+ if(objGetObjID(pObj) != OBJexpr)
+ return;
+#endif
+
va_start(ap, fmt);
lenWriteBuf = vsnprintf(pszWriteBuf, sizeof(pszWriteBuf), fmt, ap);
- if(lenWriteBuf >= sizeof(pszWriteBuf)) {
- /* if our buffer was too small, we simply truncate. TODO: maybe something better? */
- lenWriteBuf = sizeof(pszWriteBuf) - 1;
- }
va_end(ap);
- /*
- if(stddbg != NULL) fprintf(stddbg, "%s", pszWriteBuf);
- if(altdbg != NULL) fprintf(altdbg, "%s", pszWriteBuf);
- */
- if(stddbg != NULL) fwrite(pszWriteBuf, lenWriteBuf, 1, stddbg);
- if(altdbg != NULL) fwrite(pszWriteBuf, lenWriteBuf, 1, altdbg);
-
- if(stddbg != NULL) fflush(stddbg);
- if(altdbg != NULL) fflush(altdbg);
- pthread_cleanup_pop(1);
+ dbgprint(pObj, pszWriteBuf, lenWriteBuf);
}
-#pragma GCC diagnostic warning "-Wempty-body"
-#pragma GCC diagnostic ignored "-Wempty-body"
/* print some debug output when no object is given
* WARNING: duplicate code, see dbgoprin above!
*/
void
dbgprintf(char *fmt, ...)
{
- static pthread_t ptLastThrdID = 0;
- static int bWasNL = 0;
va_list ap;
- static char pszThrdName[64]; /* 64 is to be on the safe side, anything over 20 is bad... */
- static char pszWriteBuf[1024];
+ char pszWriteBuf[1024];
size_t lenWriteBuf;
- struct timespec t;
if(!(Debug && debugging_on))
return;
- pthread_mutex_lock(&mutdbgprintf);
- pthread_cleanup_push(dbgMutexCancelCleanupHdlr, &mutdbgprintf);
-
- /* The bWasNL handler does not really work. It works if no thread
- * switching occurs during non-NL messages. Else, things are messed
- * up. Anyhow, it works well enough to provide useful help during
- * getting this up and running. It is questionable if the extra effort
- * is worth fixing it, giving the limited appliability.
- * rgerhards, 2005-10-25
- * I have decided that it is not worth fixing it - especially as it works
- * pretty well.
- * rgerhards, 2007-06-15
- */
- if(ptLastThrdID != pthread_self()) {
- if(!bWasNL) {
- if(stddbg != NULL) fprintf(stddbg, "\n");
- if(altdbg != NULL) fprintf(altdbg, "\n");
- bWasNL = 1;
- }
- ptLastThrdID = pthread_self();
- }
-
- /* do not cache the thread name, as the caller might have changed it
- * TODO: optimized, invalidate cache when new name is set
- */
- dbgGetThrdName(pszThrdName, sizeof(pszThrdName), ptLastThrdID, 0);
-
- if(bWasNL) {
- if(bPrintTime) {
- clock_gettime(CLOCK_REALTIME, &t);
- if(stddbg != NULL) fprintf(stddbg, "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
- if(altdbg != NULL) fprintf(altdbg, "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
- }
- if(stddbg != NULL) fprintf(stddbg, "%s: ", pszThrdName);
- if(altdbg != NULL) fprintf(altdbg, "%s: ", pszThrdName);
- }
- bWasNL = (*(fmt + strlen(fmt) - 1) == '\n') ? 1 : 0;
va_start(ap, fmt);
lenWriteBuf = vsnprintf(pszWriteBuf, sizeof(pszWriteBuf), fmt, ap);
- if(lenWriteBuf >= sizeof(pszWriteBuf)) {
- /* if our buffer was too small, we simply truncate. TODO: maybe something better? */
- lenWriteBuf = sizeof(pszWriteBuf) - 1;
- }
va_end(ap);
- /*
- if(stddbg != NULL) fprintf(stddbg, "%s", pszWriteBuf);
- if(altdbg != NULL) fprintf(altdbg, "%s", pszWriteBuf);
- */
- if(stddbg != NULL) fwrite(pszWriteBuf, lenWriteBuf, 1, stddbg);
- if(altdbg != NULL) fwrite(pszWriteBuf, lenWriteBuf, 1, altdbg);
-
- if(stddbg != NULL) fflush(stddbg);
- if(altdbg != NULL) fflush(altdbg);
- pthread_cleanup_pop(1);
+ dbgprint(NULL, pszWriteBuf, lenWriteBuf);
}
-#pragma GCC diagnostic warning "-Wempty-body"
void tester(void)
{
@@ -994,7 +973,7 @@ ENDfunc
int dbgEntrFunc(dbgFuncDB_t **ppFuncDB, const char *file, const char *func, int line)
{
int iStackPtr = 0; /* TODO: find some better default, this one hurts the least, but it is not clean */
- dbgThrdInfo_t *pThrd = dbgGetThrdInfo();
+ dbgThrdInfo_t *pThrd;
dbgFuncDBListEntry_t *pFuncDBListEntry;
unsigned int i;
dbgFuncDB_t *pFuncDB;
@@ -1005,6 +984,8 @@ int dbgEntrFunc(dbgFuncDB_t **ppFuncDB, const char *file, const char *func, int
pFuncDB = *ppFuncDB;
assert((pFuncDB == NULL) || (pFuncDB->magic == dbgFUNCDB_MAGIC));
+ pThrd = dbgGetThrdInfo(); /* we must do this AFTER the mutexes are initialized! */
+
if(pFuncDB == NULL) {
/* we do not yet have a funcDB and need to create a new one. We also add it
* to the linked list of funcDBs. Please note that when a module is unloaded and
@@ -1259,7 +1240,7 @@ dbgGetRuntimeOptions(void)
uchar *optname;
/* set some defaults */
- stddbg = stdout;
+ stddbg = 1;
if((pszOpts = (uchar*) getenv("RSYSLOG_DEBUG")) != NULL) {
/* we have options set, so let's process them */
@@ -1301,7 +1282,7 @@ dbgGetRuntimeOptions(void)
} else if(!strcasecmp((char*)optname, "nologtimestamp")) {
bPrintTime = 0;
} else if(!strcasecmp((char*)optname, "nostdout")) {
- stddbg = NULL;
+ stddbg = -1;
} else if(!strcasecmp((char*)optname, "noaborttrace")) {
bAbortTrace = 0;
} else if(!strcasecmp((char*)optname, "filetrace")) {
@@ -1326,7 +1307,7 @@ dbgGetRuntimeOptions(void)
rsRetVal dbgClassInit(void)
{
- DEFiRet;
+ rsRetVal iRet; /* do not use DEFiRet, as this makes calls into the debug system! */
struct sigaction sigAct;
sigset_t sigSet;
@@ -1340,8 +1321,7 @@ rsRetVal dbgClassInit(void)
pthread_mutex_init(&mutFuncDBList, NULL);
pthread_mutex_init(&mutMutLog, NULL);
pthread_mutex_init(&mutCallStack, NULL);
- pthread_mutex_init(&mutdbgprintf, NULL);
- pthread_mutex_init(&mutdbgoprint, NULL);
+ pthread_mutex_init(&mutdbgprint, NULL);
/* while we try not to use any of the real rsyslog code (to avoid infinite loops), we
* need to have the ability to query object names. Thus, we need to obtain a pointer to
@@ -1363,7 +1343,7 @@ rsRetVal dbgClassInit(void)
if(pszAltDbgFileName != NULL) {
/* we have a secondary file, so let's open it) */
- if((altdbg = fopen(pszAltDbgFileName, "w")) == NULL) {
+ if((altdbg = open(pszAltDbgFileName, O_WRONLY|O_CREAT|O_TRUNC|O_NOCTTY, S_IRUSR|S_IWUSR)) == -1) {
fprintf(stderr, "alternate debug file could not be opened, ignoring. Error: %s\n", strerror(errno));
}
}
@@ -1371,7 +1351,7 @@ rsRetVal dbgClassInit(void)
dbgSetThrdName((uchar*)"main thread");
finalize_it:
- RETiRet;
+ return(iRet);
}
@@ -1383,8 +1363,8 @@ rsRetVal dbgClassExit(void)
if(bPrintAllDebugOnExit)
dbgPrintAllDebugInfo();
- if(altdbg != NULL)
- fclose(altdbg);
+ if(altdbg != -1)
+ close(altdbg);
/* now free all of our memory to make the memory debugger happy... */
pFuncDBListEtry = pFuncDBListRoot;