diff options
-rw-r--r-- | ChangeLog | 2 | ||||
-rw-r--r-- | runtime/atomic.h | 1 | ||||
-rw-r--r-- | runtime/debug.c | 211 | ||||
-rw-r--r-- | runtime/msg.c | 14 | ||||
-rw-r--r-- | runtime/wtp.c | 2 | ||||
-rw-r--r-- | tools/syslogd.c | 10 |
6 files changed, 103 insertions, 137 deletions
@@ -20,6 +20,8 @@ Version 3.21.5 [DEVEL] (rgerhards), 2008-09-?? believe that really caused problems, but in theory it could and with threading we often see that theory becomes practice if something is only used long enough on a fast enough machine with enough CPUs ;) +- cleaned up internal debug system code and made it behave better + in regard to multi-threading --------------------------------------------------------------------------- Version 3.21.4 [DEVEL] (rgerhards), 2008-09-04 - removed compile time fixed message size limit (was 2K), limit can now diff --git a/runtime/atomic.h b/runtime/atomic.h index d15f78ee..2dbe7f52 100644 --- a/runtime/atomic.h +++ b/runtime/atomic.h @@ -48,6 +48,7 @@ #else # warning "atomic builtins not available, using nul operations" # define ATOMIC_INC(data) (++(data)) +# define ATOMIC_DEC_AND_FETCH(data) (--(data)) # define ATOMIC_FETCH_32BIT(data) (data) # define ATOMIC_STORE_1_TO_32BIT(data) (data) = 1 #endif diff --git a/runtime/debug.c b/runtime/debug.c index 8d7b0084..987a648a 100644 --- a/runtime/debug.c +++ b/runtime/debug.c @@ -44,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" @@ -63,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 { @@ -114,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; @@ -749,8 +751,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, @@ -759,56 +759,36 @@ 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; - 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 - - - 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(); @@ -822,114 +802,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); + + // old, reenable TODO lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf), "%s: ", pszThrdName); + 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)); + lenWriteBuf = snprintf(pszWriteBuf, sizeof(pszWriteBuf), "%s: ", obj.GetName(pObj)); + 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: optimize, 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, "{%ld}%s: ", (long) syscall(SYS_gettid), pszThrdName); - /*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) { @@ -943,7 +893,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; @@ -954,6 +904,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 @@ -1208,7 +1160,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 */ @@ -1250,7 +1202,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")) { @@ -1275,7 +1227,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; @@ -1289,8 +1241,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 @@ -1312,7 +1263,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)); } } @@ -1320,7 +1271,7 @@ rsRetVal dbgClassInit(void) dbgSetThrdName((uchar*)"main thread"); finalize_it: - RETiRet; + return(iRet); } @@ -1332,8 +1283,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; diff --git a/runtime/msg.c b/runtime/msg.c index 164c3517..8e3749ef 100644 --- a/runtime/msg.c +++ b/runtime/msg.c @@ -273,11 +273,13 @@ BEGINobjDestruct(msg) /* be sure to specify the object type also in END and CODE int currRefCount; CODESTARTobjDestruct(msg) /* DEV Debugging only ! dbgprintf("msgDestruct\t0x%lx, Ref now: %d\n", (unsigned long)pM, pM->iRefCount - 1); */ -# ifdef DO_HAVE_ATOMICS - currRefCount = ATOMIC_DEC_AND_FETCH(pThis->iRefCount); -# else +//# ifdef DO_HAVE_ATOMICS +// currRefCount = ATOMIC_DEC_AND_FETCH(pThis->iRefCount); +//# else + MsgLock(pThis); currRefCount = --pThis->iRefCount; -# endif +//# endif +// we need a mutex, because we may be suspended after getting the refcount but before if(currRefCount == 0) { /* DEV Debugging Only! dbgprintf("msgDestruct\t0x%lx, RefCount now 0, doing DESTROY\n", (unsigned long)pThis); */ @@ -337,9 +339,11 @@ CODESTARTobjDestruct(msg) rsCStrDestruct(&pThis->pCSPROCID); if(pThis->pCSMSGID != NULL) rsCStrDestruct(&pThis->pCSMSGID); + MsgUnlock(pThis); funcDeleteMutex(pThis); } else { pThis = NULL; /* tell framework not to destructing the object! */ + MsgUnlock(pThis); } ENDobjDestruct(msg) @@ -483,7 +487,7 @@ finalize_it: msg_t *MsgAddRef(msg_t *pM) { assert(pM != NULL); -# ifdef DO_HAVE_ATOMICS +# ifdef HAVE_ATOMIC_BUILTINS ATOMIC_INC(pM->iRefCount); # else MsgLock(pM); diff --git a/runtime/wtp.c b/runtime/wtp.c index ee9fc765..c28efc51 100644 --- a/runtime/wtp.c +++ b/runtime/wtp.c @@ -169,7 +169,9 @@ wtpWakeupAllWrkr(wtp_t *pThis) DEFiRet; ISOBJ_TYPE_assert(pThis, wtp); + d_pthread_mutex_lock(pThis->pmutUsr); pthread_cond_broadcast(pThis->pcondBusy); + d_pthread_mutex_unlock(pThis->pmutUsr); RETiRet; } diff --git a/tools/syslogd.c b/tools/syslogd.c index e95d02c2..0f6a4bd1 100644 --- a/tools/syslogd.c +++ b/tools/syslogd.c @@ -1871,16 +1871,22 @@ void legacyOptsParseTCP(char ch, char *arg) * a minimal delay, but it is much cleaner than the approach of doing everything * inside the signal handler. * rgerhards, 2005-10-26 + * Note: we do not call dbgprintf() as this may cause us to block in case something + * with the threading is wrong. */ static void doDie(int sig) { +# define MSG1 "DoDie called.\n" +# define MSG2 "DoDie called 5 times - unconditional exit\n" static int iRetries = 0; /* debug aid */ - printf("DoDie called.\n"); + write(1, MSG1, sizeof(MSG1)); if(iRetries++ == 4) { - printf("DoDie called 5 times - unconditional exit\n"); + write(1, MSG2, sizeof(MSG2)); abort(); } bFinished = sig; +# undef MSG1 +# undef MSG2 } |