From 5af5b1e42868d00dfbc5fa47028768d0a03f8e32 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 25 Jun 2009 12:59:13 +0200 Subject: improvements/fixes in queue termination timeout handling - bugfix: subtle (and usually irrelevant) issue in timout processing timeout could be one second too early if nanoseconds wrapped - set a more sensible timeout for shutdow, now 1.5 seconds to complete processing (this also removes those cases where the shutdown message was not written because the termination happened before it) --- ChangeLog | 5 +++++ runtime/srutils.c | 4 +++- runtime/wti.c | 6 ++++-- tools/syslogd.c | 4 ++-- 4 files changed, 14 insertions(+), 5 deletions(-) diff --git a/ChangeLog b/ChangeLog index e7de1c4d..d7c6e408 100644 --- a/ChangeLog +++ b/ChangeLog @@ -24,6 +24,11 @@ Version 4.5.0 [DEVEL] (rgerhards), 2009-??-?? * $MainMsgQueueSyncQueueFiles * $ActionQueueSyncQueueFiles - done some memory accesses explicitely atomic +- bugfix: subtle (and usually irrelevant) issue in timout processing + timeout could be one second too early if nanoseconds wrapped +- set a more sensible timeout for shutdow, now 1.5 seconds to complete + processing (this also removes those cases where the shutdown message + was not written because the termination happened before it) --------------------------------------------------------------------------- Version 4.3.2 [beta] (rgerhards), 2009-06-24 - removed long-obsoleted property UxTradMsg diff --git a/runtime/srutils.c b/runtime/srutils.c index 5407531f..c403b312 100644 --- a/runtime/srutils.c +++ b/runtime/srutils.c @@ -366,6 +366,7 @@ int getNumberDigits(long lNum) /* compute an absolute time timeout suitable for calls to pthread_cond_timedwait() + * iTimeout is in milliseconds * rgerhards, 2008-01-14 */ rsRetVal @@ -375,11 +376,12 @@ timeoutComp(struct timespec *pt, long iTimeout) assert(pt != NULL); /* compute timeout */ clock_gettime(CLOCK_REALTIME, pt); + pt->tv_sec += iTimeout / 1000; pt->tv_nsec += (iTimeout % 1000) * 1000000; /* think INTEGER arithmetic! */ if(pt->tv_nsec > 999999999) { /* overrun? */ pt->tv_nsec -= 1000000000; + ++pt->tv_sec; } - pt->tv_sec += iTimeout / 1000; ENDfunc return RS_RET_OK; /* so far, this is static... */ } diff --git a/runtime/wti.c b/runtime/wti.c index 9de7c365..156d8116 100644 --- a/runtime/wti.c +++ b/runtime/wti.c @@ -159,7 +159,7 @@ wtiSetState(wti_t *pThis, qWrkCmd_t tCmd, int bActiveOnly, int bLockMutex) } -/* Cancel the thread. If the thread is already cancelled or termination, +/* Cancel the thread. If the thread is already cancelled or terminated, * we do not again cancel it. But it is save and legal to call wtiCancelThrd() in * such situations. * rgerhards, 2008-02-26 @@ -173,8 +173,10 @@ wtiCancelThrd(wti_t *pThis) d_pthread_mutex_lock(&pThis->mut); + wtiProcessThrdChanges(pThis, MUTEX_ALREADY_LOCKED); /* process state change, so that we have current state vars */ + if(pThis->tCurrCmd >= eWRKTHRD_TERMINATING) { - dbgoprint((obj_t*) pThis, "canceling worker thread\n"); + dbgoprint((obj_t*) pThis, "canceling worker thread, curr stat %d\n", pThis->tCurrCmd); pthread_cancel(pThis->thrdID); wtiSetState(pThis, eWRKTHRD_TERMINATING, 0, MUTEX_ALREADY_LOCKED); ATOMIC_STORE_1_TO_INT(pThis->pWtp->bThrdStateChanged); /* indicate change, so harverster will be called */ diff --git a/tools/syslogd.c b/tools/syslogd.c index 6f264e5e..0fdaf5ba 100644 --- a/tools/syslogd.c +++ b/tools/syslogd.c @@ -299,7 +299,7 @@ static uchar *pszMainMsgQFName = NULL; /* prefix for the main message queue f static int64 iMainMsgQueMaxFileSize = 1024*1024; static int iMainMsgQPersistUpdCnt = 0; /* persist queue info every n updates */ static int bMainMsgQSyncQeueFiles = 0; /* sync queue files on every write? */ -static int iMainMsgQtoQShutdown = 0; /* queue shutdown */ +static int iMainMsgQtoQShutdown = 1500; /* queue shutdown (ms) */ static int iMainMsgQtoActShutdown = 1000; /* action shutdown (in phase 2) */ static int iMainMsgQtoEnq = 2000; /* timeout for queue enque */ static int iMainMsgQtoWrkShutdown = 60000; /* timeout for worker thread shutdown */ @@ -363,7 +363,7 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __a iMainMsgQueueNumWorkers = 1; iMainMsgQPersistUpdCnt = 0; bMainMsgQSyncQeueFiles = 0; - iMainMsgQtoQShutdown = 0; + iMainMsgQtoQShutdown = 1500; iMainMsgQtoActShutdown = 1000; iMainMsgQtoEnq = 2000; iMainMsgQtoWrkShutdown = 60000; -- cgit From b82f9ae304b8cdfada55d7dce93daf50cf7f8578 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 25 Jun 2009 15:29:09 +0200 Subject: bugfix: subtle potential issue during queue shutdown ... this one could cause trouble, but I really don't think it caused any actual harm. --- runtime/queue.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/runtime/queue.c b/runtime/queue.c index 1e3b761f..13e7007a 100644 --- a/runtime/queue.c +++ b/runtime/queue.c @@ -110,7 +110,7 @@ static inline void queueDrain(qqueue_t *pThis) ASSERT(pThis != NULL); /* iQueueSize is not decremented by qDel(), so we need to do it ourselves */ - while(pThis->iQueueSize-- > 0) { + while(ATOMIC_DEC_AND_FETCH(pThis->iQueueSize) > 0) { pThis->qDel(pThis, &pUsr); if(pUsr != NULL) { objDestruct(pUsr); -- cgit From 46435e2c3b2ca31aca641aba290173142fae540c Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 25 Jun 2009 15:33:49 +0200 Subject: cleanup (removed now-unused parameters) --- runtime/datetime.c | 8 ++++---- runtime/datetime.h | 8 ++++---- runtime/msg.c | 18 +++++++++--------- 3 files changed, 17 insertions(+), 17 deletions(-) diff --git a/runtime/datetime.c b/runtime/datetime.c index c0e145af..e0f3f5fa 100644 --- a/runtime/datetime.c +++ b/runtime/datetime.c @@ -546,7 +546,7 @@ finalize_it: * returns the size of the timestamp written in bytes (without * the string terminator). If 0 is returend, an error occured. */ -int formatTimestampToMySQL(struct syslogTime *ts, char* pBuf, size_t iLenDst) +int formatTimestampToMySQL(struct syslogTime *ts, char* pBuf) { /* currently we do not consider localtime/utc. This may later be * added. If so, I recommend using a property replacer option @@ -577,7 +577,7 @@ int formatTimestampToMySQL(struct syslogTime *ts, char* pBuf, size_t iLenDst) } -int formatTimestampToPgSQL(struct syslogTime *ts, char *pBuf, size_t iLenDst) +int formatTimestampToPgSQL(struct syslogTime *ts, char *pBuf) { /* see note in formatTimestampToMySQL, applies here as well */ assert(ts != NULL); @@ -655,7 +655,7 @@ int formatTimestampSecFrac(struct syslogTime *ts, char* pBuf) * returns the size of the timestamp written in bytes (without * the string terminator). If 0 is returend, an error occured. */ -int formatTimestamp3339(struct syslogTime *ts, char* pBuf, size_t iLenBuf) +int formatTimestamp3339(struct syslogTime *ts, char* pBuf) { int iBuf; int power; @@ -732,7 +732,7 @@ int formatTimestamp3339(struct syslogTime *ts, char* pBuf, size_t iLenBuf) * returns the size of the timestamp written in bytes (without * the string termnator). If 0 is returend, an error occured. */ -int formatTimestamp3164(struct syslogTime *ts, char* pBuf, size_t iLenBuf) +int formatTimestamp3164(struct syslogTime *ts, char* pBuf) { static char* monthNames[12] = { "Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec" }; diff --git a/runtime/datetime.h b/runtime/datetime.h index 1ea99aba..79a86d05 100644 --- a/runtime/datetime.h +++ b/runtime/datetime.h @@ -38,10 +38,10 @@ BEGINinterface(datetime) /* name must also be changed in ENDinterface macro! */ void (*getCurrTime)(struct syslogTime *t, time_t *ttSeconds); rsRetVal (*ParseTIMESTAMP3339)(struct syslogTime *pTime, uchar** ppszTS); rsRetVal (*ParseTIMESTAMP3164)(struct syslogTime *pTime, uchar** pszTS); - int (*formatTimestampToMySQL)(struct syslogTime *ts, char* pDst, size_t iLenDst); - int (*formatTimestampToPgSQL)(struct syslogTime *ts, char *pDst, size_t iLenDst); - int (*formatTimestamp3339)(struct syslogTime *ts, char* pBuf, size_t iLenBuf); - int (*formatTimestamp3164)(struct syslogTime *ts, char* pBuf, size_t iLenBuf); + int (*formatTimestampToMySQL)(struct syslogTime *ts, char* pDst); + int (*formatTimestampToPgSQL)(struct syslogTime *ts, char *pDst); + int (*formatTimestamp3339)(struct syslogTime *ts, char* pBuf); + int (*formatTimestamp3164)(struct syslogTime *ts, char* pBuf); int (*formatTimestampSecFrac)(struct syslogTime *ts, char* pBuf); ENDinterface(datetime) #define datetimeCURR_IF_VERSION 2 /* increment whenever you change the interface structure! */ diff --git a/runtime/msg.c b/runtime/msg.c index 8aab5317..cbdfff78 100644 --- a/runtime/msg.c +++ b/runtime/msg.c @@ -1007,7 +1007,7 @@ static inline char *getTimeReported(msg_t *pM, enum tplFormatTypes eFmt) MsgLock(pM); if(pM->pszTIMESTAMP3164 == NULL) { pM->pszTIMESTAMP3164 = pM->pszTimestamp3164; - datetime.formatTimestamp3164(&pM->tTIMESTAMP, pM->pszTIMESTAMP3164, 16); + datetime.formatTimestamp3164(&pM->tTIMESTAMP, pM->pszTIMESTAMP3164); } MsgUnlock(pM); return(pM->pszTIMESTAMP3164); @@ -1018,7 +1018,7 @@ static inline char *getTimeReported(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestampToMySQL(&pM->tTIMESTAMP, pM->pszTIMESTAMP_MySQL, 15); + datetime.formatTimestampToMySQL(&pM->tTIMESTAMP, pM->pszTIMESTAMP_MySQL); } MsgUnlock(pM); return(pM->pszTIMESTAMP_MySQL); @@ -1029,7 +1029,7 @@ static inline char *getTimeReported(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestampToPgSQL(&pM->tTIMESTAMP, pM->pszTIMESTAMP_PgSQL, 21); + datetime.formatTimestampToPgSQL(&pM->tTIMESTAMP, pM->pszTIMESTAMP_PgSQL); } MsgUnlock(pM); return(pM->pszTIMESTAMP_PgSQL); @@ -1037,7 +1037,7 @@ static inline char *getTimeReported(msg_t *pM, enum tplFormatTypes eFmt) MsgLock(pM); if(pM->pszTIMESTAMP3339 == NULL) { pM->pszTIMESTAMP3339 = pM->pszTimestamp3339; - datetime.formatTimestamp3339(&pM->tTIMESTAMP, pM->pszTIMESTAMP3339, 33); + datetime.formatTimestamp3339(&pM->tTIMESTAMP, pM->pszTIMESTAMP3339); } MsgUnlock(pM); return(pM->pszTIMESTAMP3339); @@ -1070,7 +1070,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164, 16); + datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164); } MsgUnlock(pM); return(pM->pszRcvdAt3164); @@ -1081,7 +1081,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestampToMySQL(&pM->tRcvdAt, pM->pszRcvdAt_MySQL, 15); + datetime.formatTimestampToMySQL(&pM->tRcvdAt, pM->pszRcvdAt_MySQL); } MsgUnlock(pM); return(pM->pszRcvdAt_MySQL); @@ -1092,7 +1092,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestampToPgSQL(&pM->tRcvdAt, pM->pszRcvdAt_PgSQL, 21); + datetime.formatTimestampToPgSQL(&pM->tRcvdAt, pM->pszRcvdAt_PgSQL); } MsgUnlock(pM); return(pM->pszRcvdAt_PgSQL); @@ -1103,7 +1103,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164, 16); + datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164); } MsgUnlock(pM); return(pM->pszRcvdAt3164); @@ -1114,7 +1114,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestamp3339(&pM->tRcvdAt, pM->pszRcvdAt3339, 33); + datetime.formatTimestamp3339(&pM->tRcvdAt, pM->pszRcvdAt3339); } MsgUnlock(pM); return(pM->pszRcvdAt3339); -- cgit From 1f79c785975261e4158c9b85f6451d5bd00b2495 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Thu, 25 Jun 2009 16:03:28 +0200 Subject: named queue worker threads ... but I don't see the name anywhere...? --- runtime/wtp.c | 6 ++++++ tools/syslogd.c | 2 +- 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/runtime/wtp.c b/runtime/wtp.c index 218a5db6..02662cde 100644 --- a/runtime/wtp.c +++ b/runtime/wtp.c @@ -40,6 +40,7 @@ #include #include #include +#include #ifdef OS_SOLARIS # include @@ -433,6 +434,11 @@ wtpWorker(void *arg) /* the arg is actually a wti object, even though we are in sigfillset(&sigSet); pthread_sigmask(SIG_BLOCK, &sigSet, NULL); + /* set thread name - we ignore if the call fails, has no harsh consequences... */ + if(prctl(PR_SET_NAME, wtpGetDbgHdr(pThis), 0, 0, 0) != 0) { + DBGPRINTF("prctl failed, not setting thread name for '%s'\n", wtpGetDbgHdr(pThis)); + } + BEGIN_MTX_PROTECTED_OPERATIONS(&pThis->mut, LOCK_MUTEX); /* do some late initialization */ diff --git a/tools/syslogd.c b/tools/syslogd.c index 0fdaf5ba..8bc4939f 100644 --- a/tools/syslogd.c +++ b/tools/syslogd.c @@ -2272,7 +2272,7 @@ init(void) exit(1); } /* name our main queue object (it's not fatal if it fails...) */ - obj.SetName((obj_t*) pMsgQueue, (uchar*) "main queue"); + obj.SetName((obj_t*) pMsgQueue, (uchar*) "main Q"); /* ... set some properties ... */ # define setQPROP(func, directive, data) \ -- cgit