From d4539663f685910db1e8d7816508298b940c8590 Mon Sep 17 00:00:00 2001 From: Corey Smith Date: Thu, 24 Mar 2011 17:16:59 +0100 Subject: bugfix: PRI was invalid on Solaris for message from local log socket Signed-off-by: root --- ChangeLog | 1 + runtime/parser.c | 6 +++--- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/ChangeLog b/ChangeLog index caa53b8c..0fb8334d 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,6 @@ --------------------------------------------------------------------------- Version 4.7.4 [v4-???] (rgerhards), 2010-11-?? +- bugfix: PRI was invalid on Solaris for message from local log socket - added $LocalHostName config directive - bugfix: local hostname was pulled too-early, so that some config directives (namely FQDN settings) did not have any effect diff --git a/runtime/parser.c b/runtime/parser.c index fdda9546..be9304d7 100644 --- a/runtime/parser.c +++ b/runtime/parser.c @@ -303,10 +303,10 @@ rsRetVal parseMsg(msg_t *pMsg) if(pri & ~(LOG_FACMASK|LOG_PRIMASK)) pri = DEFUPRI; } + pMsg->iFacility = LOG_FAC(pri); + pMsg->iSeverity = LOG_PRI(pri); + MsgSetAfterPRIOffs(pMsg, msg - pMsg->pszRawMsg); } - pMsg->iFacility = LOG_FAC(pri); - pMsg->iSeverity = LOG_PRI(pri); - MsgSetAfterPRIOffs(pMsg, msg - pMsg->pszRawMsg); /* rger 2005-11-24 (happy thanksgiving!): we now need to check if we have * a traditional syslog message or one formatted according to syslog-protocol. -- cgit From 579c61e579d9452682da51ec5e4b547684573807 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Mon, 2 May 2011 11:57:29 +0200 Subject: bugfix: a slightly more informative error message when a TCP connections is aborted --- ChangeLog | 2 ++ runtime/strmsrv.c | 6 ++++-- tcpsrv.c | 8 +++++--- 3 files changed, 11 insertions(+), 5 deletions(-) diff --git a/ChangeLog b/ChangeLog index 0fb8334d..c838f6d6 100644 --- a/ChangeLog +++ b/ChangeLog @@ -6,6 +6,8 @@ Version 4.7.4 [v4-???] (rgerhards), 2010-11-?? directives (namely FQDN settings) did not have any effect - bugfix: atomic increment for msg object may not work correct on all platforms. Thanks to Chris Metcalf for the patch +- bugfix: a slightly more informative error message when a TCP + connections is aborted --------------------------------------------------------------------------- Version 4.7.3 [v4-devel] (rgerhards), 2010-11-25 - bugfix(important): problem in TLS handling could cause rsyslog to loop diff --git a/runtime/strmsrv.c b/runtime/strmsrv.c index 3dc53a97..8cebf810 100644 --- a/runtime/strmsrv.c +++ b/runtime/strmsrv.c @@ -520,6 +520,7 @@ Run(strmsrv_t *pThis) strms_sess_t *pNewSess; nssel_t *pSel; ssize_t iRcvd; + rsRetVal localRet; ISOBJ_TYPE_assert(pThis, strmsrv); @@ -579,11 +580,12 @@ Run(strmsrv_t *pThis) break; case RS_RET_OK: /* valid data received, process it! */ - if(strms_sess.DataRcvd(pThis->pSessions[iSTRMSess], buf, iRcvd) != RS_RET_OK) { + localRet = strms_sess.DataRcvd(pThis->pSessions[iSTRMSess], buf, iRcvd); + if(localRet != RS_RET_OK) { /* in this case, something went awfully wrong. * We are instructed to terminate the session. */ - errmsg.LogError(0, NO_ERRCODE, "Tearing down STRM Session %d - see " + errmsg.LogError(0, localRet, "Tearing down STRM Session %d - see " "previous messages for reason(s)\n", iSTRMSess); pThis->pOnErrClose(pThis->pSessions[iSTRMSess]); strms_sess.Destruct(&pThis->pSessions[iSTRMSess]); diff --git a/tcpsrv.c b/tcpsrv.c index 0102bee7..5de805b2 100644 --- a/tcpsrv.c +++ b/tcpsrv.c @@ -471,6 +471,7 @@ static rsRetVal Run(tcpsrv_t *pThis) { DEFiRet; + rsRetVal localRet; int nfds; int i; int iTCPSess; @@ -545,12 +546,13 @@ Run(tcpsrv_t *pThis) break; case RS_RET_OK: /* valid data received, process it! */ - if(tcps_sess.DataRcvd(pThis->pSessions[iTCPSess], buf, iRcvd) != RS_RET_OK) { + localRet = tcps_sess.DataRcvd(pThis->pSessions[iTCPSess], buf, iRcvd); + if(localRet != RS_RET_OK) { /* in this case, something went awfully wrong. * We are instructed to terminate the session. */ - errmsg.LogError(0, NO_ERRCODE, "Tearing down TCP Session %d - see " - "previous messages for reason(s)\n", iTCPSess); + errmsg.LogError(0, localRet, "Tearing down TCP Session %d - see " + "previous messages for reason(s)", iTCPSess); pThis->pOnErrClose(pThis->pSessions[iTCPSess]); tcps_sess.Destruct(&pThis->pSessions[iTCPSess]); } -- cgit From 1bfaf4ac06e82c0e4008a2b851043a09aee1a2e3 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Tue, 3 May 2011 12:27:49 +0200 Subject: better handling of queue i/o errors in disk queues. This is kind of a bugfix, but a very intrusive one, thus it goes into the devel version first. Right now, "file not found" is handled and leads to the new emergency mode, in which disk action is stopped and the queue run in direct mode. An error message is emited if this happens. --- ChangeLog | 5 +++++ runtime/queue.c | 65 ++++++++++++++++++++++++++++++++++++++++++++++++++----- runtime/rsyslog.h | 1 + runtime/wti.c | 5 ++++- 4 files changed, 69 insertions(+), 7 deletions(-) diff --git a/ChangeLog b/ChangeLog index d4fe37a6..dde6f77a 100644 --- a/ChangeLog +++ b/ChangeLog @@ -8,6 +8,11 @@ Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? nobody still depends on it (and, if so, they lost...). - bugfix: pipes not opened in full priv mode when privs are to be dropped - this begins a new devel branch for v5 +- better handling of queue i/o errors in disk queues. This is kind of a + bugfix, but a very intrusive one, this it goes into the devel version + first. Right now, "file not found" is handled and leads to the new + emergency mode, in which disk action is stopped and the queue run + in direct mode. An error message is emited if this happens. - added support for user-level PRI provided via systemd - added new config directive $InputTCPFlowControl to select if tcp received messages shall be flagged as light delayable or not. diff --git a/runtime/queue.c b/runtime/queue.c index 50ae307c..70f0ba0c 100644 --- a/runtime/queue.c +++ b/runtime/queue.c @@ -83,6 +83,11 @@ static rsRetVal ConsumerDA(qqueue_t *pThis, wti_t *pWti); static rsRetVal batchProcessed(qqueue_t *pThis, wti_t *pWti); static rsRetVal qqueueMultiEnqObjNonDirect(qqueue_t *pThis, multi_submit_t *pMultiSub); static rsRetVal qqueueMultiEnqObjDirect(qqueue_t *pThis, multi_submit_t *pMultiSub); +static rsRetVal qAddDirect(qqueue_t *pThis, void* pUsr); +static rsRetVal qDestructDirect(qqueue_t __attribute__((unused)) *pThis); +static rsRetVal qConstructDirect(qqueue_t __attribute__((unused)) *pThis); +static rsRetVal qDelDirect(qqueue_t __attribute__((unused)) *pThis); +static rsRetVal qDestructDisk(qqueue_t *pThis); /* some constants for queuePersist () */ #define QUEUE_CHECKPOINT 1 @@ -583,6 +588,47 @@ static rsRetVal qDelLinkedList(qqueue_t *pThis) /* -------------------- disk -------------------- */ +/* The following function is used to "save" ourself from being killed by + * a fatally failed disk queue. A fatal failure is, for example, if no + * data can be read or written. In that case, the disk support is disabled, + * with all on-disk structures kept as-is as much as possible. Instead, the + * queue is switched to direct mode, so that at least + * some processing can happen. Of course, this may still have lots of + * undesired side-effects, but is probably better than aborting the + * syslogd. Note that this function *must* succeed in one way or another, as + * we can not recover from failure here. But it may emit different return + * states, which can trigger different processing in the higher layers. + * rgerhards, 2011-05-03 + */ +static inline rsRetVal +queueSwitchToEmergencyMode(qqueue_t *pThis, rsRetVal initiatingError) +{ + pThis->iQueueSize = 0; + pThis->nLogDeq = 0; + qDestructDisk(pThis); /* free disk structures */ + + pThis->qType = QUEUETYPE_DIRECT; + pThis->qConstruct = qConstructDirect; + pThis->qDestruct = qDestructDirect; + pThis->qAdd = qAddDirect; + pThis->qDel = qDelDirect; + pThis->MultiEnq = qqueueMultiEnqObjDirect; + if(pThis->pqParent != NULL) { + DBGOPRINT((obj_t*) pThis, "DA queue is in emergency mode, disabling DA in parent\n"); + pThis->pqParent->bIsDA = 0; + pThis->pqParent->pqDA = NULL; + /* This may have undesired side effects, not sure if I really evaluated + * all. So you know where to look at if you come to this point during + * troubleshooting ;) -- rgerhards, 2011-05-03 + */ + } + + errmsg.LogError(0, initiatingError, "fatal error on disk queue '%s', emergency switch to direct mode", + obj.GetName((obj_t*) pThis)); + return RS_RET_ERR_QUEUE_EMERGENCY; +} + + static rsRetVal qqueueLoadPersStrmInfoFixup(strm_t *pStrm, qqueue_t __attribute__((unused)) *pThis) { @@ -785,10 +831,7 @@ finalize_it: static rsRetVal qDeqDisk(qqueue_t *pThis, void **ppUsr) { DEFiRet; - - CHKiRet(obj.Deserialize(ppUsr, (uchar*) "msg", pThis->tVars.disk.pReadDeq, NULL, NULL)); - -finalize_it: + iRet = obj.Deserialize(ppUsr, (uchar*) "msg", pThis->tVars.disk.pReadDeq, NULL, NULL); RETiRet; } @@ -1683,7 +1726,18 @@ ConsumerReg(qqueue_t *pThis, wti_t *pWti) ISOBJ_TYPE_assert(pThis, qqueue); ISOBJ_TYPE_assert(pWti, wti); - CHKiRet(DequeueForConsumer(pThis, pWti)); + iRet = DequeueForConsumer(pThis, pWti); + if(iRet == RS_RET_FILE_NOT_FOUND) { + /* This is a fatal condition and means the queue is almost unusable */ + d_pthread_mutex_unlock(pThis->mut); + DBGOPRINT((obj_t*) pThis, "got 'file not found' error %d, queue defunct\n", iRet); + iRet = queueSwitchToEmergencyMode(pThis, iRet); + // TODO: think about what to return as iRet -- keep RS_RET_FILE_NOT_FOUND? + d_pthread_mutex_lock(pThis->mut); + } + if (iRet != RS_RET_OK) { + FINALIZE; + } /* we now have a non-idle batch of work, so we can release the queue mutex and process it */ d_pthread_mutex_unlock(pThis->mut); @@ -1774,7 +1828,6 @@ qqueueChkStopWrkrDA(qqueue_t *pThis) { DEFiRet; -//DBGPRINTF("XXXX: chkStopWrkrDA called, low watermark %d, phys Size %d\n", pThis->iLowWtrMrk, getPhysicalQueueSize(pThis)); if(pThis->bEnqOnly) { iRet = RS_RET_TERMINATE_WHEN_IDLE; } diff --git a/runtime/rsyslog.h b/runtime/rsyslog.h index d63dbe4f..d7f785f2 100644 --- a/runtime/rsyslog.h +++ b/runtime/rsyslog.h @@ -342,6 +342,7 @@ enum rsRetVal_ /** return value. All methods return this if not specified oth RS_RET_ERR_HDFS_OPEN = -2179, /**< error during hdfsOpen (e.g. file does not exist) */ RS_RET_FILE_NOT_SPECIFIED = -2180, /**< file name not configured where this was required */ RS_RET_ERR_WRKDIR = -2181, /**< problems with the rsyslog working directory */ + RS_RET_ERR_QUEUE_EMERGENCY = -2182, /**< some fatal error caused queue to switch to emergency mode */ /* RainerScript error messages (range 1000.. 1999) */ RS_RET_SYSVAR_NOT_FOUND = 1001, /**< system variable could not be found (maybe misspelled) */ diff --git a/runtime/wti.c b/runtime/wti.c index 9343f5c5..ec56c2d5 100644 --- a/runtime/wti.c +++ b/runtime/wti.c @@ -314,7 +314,10 @@ wtiWorker(wti_t *pThis) */ localRet = pWtp->pfDoWork(pWtp->pUsr, pThis); - if(localRet == RS_RET_IDLE) { + if(localRet == RS_RET_ERR_QUEUE_EMERGENCY) { + d_pthread_mutex_unlock(pWtp->pmutUsr); + break; /* end of loop */ + } else if(localRet == RS_RET_IDLE) { if(terminateRet == RS_RET_TERMINATE_WHEN_IDLE || bInactivityTOOccured) { d_pthread_mutex_unlock(pWtp->pmutUsr); break; /* end of loop */ -- cgit From 6625a8790d3e89b3ecc0612cf08fc917b9631398 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Mon, 9 May 2011 10:07:23 +0200 Subject: added capability for imtcp to activate keep-alive packets at the socket layer. reference: http://kb.monitorware.com/post20791.html --- ChangeLog | 3 +++ doc/imtcp.html | 3 +++ plugins/imtcp/imtcp.c | 5 +++++ runtime/strmsrv.c | 2 +- tcpsrv.c | 14 ++++++++++++++ tcpsrv.h | 5 ++++- 6 files changed, 30 insertions(+), 2 deletions(-) diff --git a/ChangeLog b/ChangeLog index 1a0634d9..f4303d8d 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,8 @@ --------------------------------------------------------------------------- Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? +- added capability for imtcp to activate keep-alive packets at the + socket layer. + reference: http://kb.monitorware.com/post20791.html - bugfix: do not open files with full privileges, if privs will be dropped This make the privilege drop code more bulletproof, but breaks Ubuntu's work-around for log files created by external programs with the wrong diff --git a/doc/imtcp.html b/doc/imtcp.html index b0aaa3c1..7653f601 100644 --- a/doc/imtcp.html +++ b/doc/imtcp.html @@ -55,6 +55,9 @@ so be prepared to wrangle with that! instructs imtcp to emit a message if the remote peer closes a connection.
Important: This directive is global to all listeners and must be given right after loading imtcp, otherwise it may have no effect. +
  • $InputTCPServerKeepAlive <on/off>
    +enable of disable keep-alive packets at the tcp socket layer. The default is +to disable them.
  • $InputTCPServerRun <port>
    Starts a TCP server on selected port
  • $InputTCPFlowControl <on/off>
    diff --git a/plugins/imtcp/imtcp.c b/plugins/imtcp/imtcp.c index 1a62d82e..c939e1d6 100644 --- a/plugins/imtcp/imtcp.c +++ b/plugins/imtcp/imtcp.c @@ -82,6 +82,7 @@ static permittedPeers_t *pPermPeersRoot = NULL; /* config settings */ +static int bKeepAlive = 0; /* support keep-alive packets */ static int iTCPSessMax = 200; /* max number of sessions */ static int iTCPLstnMax = 20; /* max number of sessions */ static int iStrmDrvrMode = 0; /* mode for stream driver, driver-dependent (0 mostly means plain tcp) */ @@ -192,6 +193,7 @@ static rsRetVal addTCPListener(void __attribute__((unused)) *pVal, uchar *pNewVa if(pOurTcpsrv == NULL) { CHKiRet(tcpsrv.Construct(&pOurTcpsrv)); + CHKiRet(tcpsrv.SetKeepAlive(pOurTcpsrv, bKeepAlive)); CHKiRet(tcpsrv.SetSessMax(pOurTcpsrv, iTCPSessMax)); CHKiRet(tcpsrv.SetLstnMax(pOurTcpsrv, iTCPLstnMax)); CHKiRet(tcpsrv.SetCBIsPermittedHost(pOurTcpsrv, isPermittedHost)); @@ -289,6 +291,7 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __attribute__((unused)) *pVal) { iTCPSessMax = 200; + bKeepAlive = 0; iTCPLstnMax = 20; iStrmDrvrMode = 0; bUseFlowControl = 0; @@ -327,6 +330,8 @@ CODEmodInit_QueryRegCFSLineHdlr /* register config file handlers */ CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputtcpserverrun"), 0, eCmdHdlrGetWord, addTCPListener, NULL, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputtcpserverkeepalive"), 0, eCmdHdlrBinary, + NULL, &bKeepAlive, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputtcpmaxsessions"), 0, eCmdHdlrInt, NULL, &iTCPSessMax, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputtcpmaxlisteners"), 0, eCmdHdlrInt, diff --git a/runtime/strmsrv.c b/runtime/strmsrv.c index f448cd4f..03691de6 100644 --- a/runtime/strmsrv.c +++ b/runtime/strmsrv.c @@ -767,7 +767,7 @@ static rsRetVal SetKeepAlive(strmsrv_t *pThis, int iVal) { DEFiRet; - dbgprintf("keep-alive set to %d\n", iVal); + dbgprintf("strmsrv: keep-alive set to %d\n", iVal); pThis->bUseKeepAlive = iVal; RETiRet; } diff --git a/tcpsrv.c b/tcpsrv.c index fde6044d..4658555f 100644 --- a/tcpsrv.c +++ b/tcpsrv.c @@ -396,6 +396,10 @@ SessAccept(tcpsrv_t *pThis, tcpLstnPortList_t *pLstnInfo, tcps_sess_t **ppSess, ABORT_FINALIZE(RS_RET_MAX_SESS_REACHED); } + if(pThis->bUseKeepAlive) { + CHKiRet(netstrm.EnableKeepAlive(pNewStrm)); + } + /* we found a free spot and can construct our session object */ CHKiRet(tcps_sess.Construct(&pSess)); CHKiRet(tcps_sess.SetTcpsrv(pSess, pThis)); @@ -863,6 +867,15 @@ SetUsrP(tcpsrv_t *pThis, void *pUsr) RETiRet; } +static rsRetVal +SetKeepAlive(tcpsrv_t *pThis, int iVal) +{ + DEFiRet; + dbgprintf("tcpsrv: keep-alive set to %d\n", iVal); + pThis->bUseKeepAlive = iVal; + RETiRet; +} + static rsRetVal SetOnMsgReceive(tcpsrv_t *pThis, rsRetVal (*OnMsgReceive)(tcps_sess_t*, uchar*, int)) { @@ -1042,6 +1055,7 @@ CODESTARTobjQueryInterface(tcpsrv) pIf->create_tcp_socket = create_tcp_socket; pIf->Run = Run; + pIf->SetKeepAlive = SetKeepAlive; pIf->SetUsrP = SetUsrP; pIf->SetInputName = SetInputName; pIf->SetAddtlFrameDelim = SetAddtlFrameDelim; diff --git a/tcpsrv.h b/tcpsrv.h index 6c2bad45..9dc06e3e 100644 --- a/tcpsrv.h +++ b/tcpsrv.h @@ -48,6 +48,7 @@ struct tcpLstnPortList_s { /* the tcpsrv object */ struct tcpsrv_s { BEGINobjInstance; /**< Data to implement generic object - MUST be the first data element! */ + int bUseKeepAlive; /**< use socket layer KEEPALIVE handling? */ netstrms_t *pNS; /**< pointer to network stream subsystem */ int iDrvrMode; /**< mode of the stream driver to use */ uchar *pszDrvrAuthMode; /**< auth mode of the stream driver to use */ @@ -124,8 +125,10 @@ BEGINinterface(tcpsrv) /* name must also be changed in ENDinterface macro! */ rsRetVal (*SetbDisableLFDelim)(tcpsrv_t*, int); /* added v10 -- rgerhards, 2011-04-01 */ rsRetVal (*SetUseFlowControl)(tcpsrv_t*, int); + /* added v11 -- rgerhards, 2011-05-09 */ + rsRetVal (*SetKeepAlive)(tcpsrv_t*, int); ENDinterface(tcpsrv) -#define tcpsrvCURR_IF_VERSION 10 /* increment whenever you change the interface structure! */ +#define tcpsrvCURR_IF_VERSION 11 /* increment whenever you change the interface structure! */ /* change for v4: * - SetAddtlFrameDelim() added -- rgerhards, 2008-12-10 * - SetInputName() added -- rgerhards, 2008-12-10 -- cgit From 1d39d21c62efacb39862d89755ae49ecf0cb7e23 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Wed, 11 May 2011 12:24:40 +0200 Subject: imptcp: added capability to activate keep-alive at socket layer --- ChangeLog | 5 +++-- doc/imptcp.html | 5 ++++- plugins/imptcp/imptcp.c | 41 +++++++++++++++++++++++++++++++++++++---- 3 files changed, 44 insertions(+), 7 deletions(-) diff --git a/ChangeLog b/ChangeLog index ca076bae..69a91ce0 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,7 +1,8 @@ --------------------------------------------------------------------------- Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? -- added capability for imtcp to activate keep-alive packets at the - socket layer. +- added capability for imtcp and imptcp to activate keep-alive packets + at the socket layer. This has not been added to imttcp, as the latter is + only an experimental module, and one which did not prove to be useful. reference: http://kb.monitorware.com/post20791.html - bugfix: do not open files with full privileges, if privs will be dropped This make the privilege drop code more bulletproof, but breaks Ubuntu's diff --git a/doc/imptcp.html b/doc/imptcp.html index d4228185..8784391e 100644 --- a/doc/imptcp.html +++ b/doc/imptcp.html @@ -45,7 +45,10 @@ can be found at the Cisco tcp page.
  • $InputPTCPServerNotifyOnConnectionClose [on/off]
    instructs imptcp to emit a message if the remote peer closes a connection.
    -
  • $InputPTCPServerRun <port>
    +
  • $InputPTCPServerKeepAlive <on/off>
    +enable of disable keep-alive packets at the tcp socket layer. The default is +to disable them.
    • +
  • $InputPTCPServerRun <port>
    Starts a TCP server on selected port
  • $InputPTCPServerInputName <name>
    Sets a name for the inputname property. If no name is set "imptcp" is used by default. Setting a diff --git a/plugins/imptcp/imptcp.c b/plugins/imptcp/imptcp.c index e8cffbb0..8333e050 100644 --- a/plugins/imptcp/imptcp.c +++ b/plugins/imptcp/imptcp.c @@ -88,6 +88,7 @@ DEFobjCurrIf(ruleset) /* config settings */ typedef struct configSettings_s { + int bKeepAlive; /* support keep-alive packets */ int bEmitMsgOnClose; /* emit an informational message on close by remote peer */ int iAddtlFrameDelim; /* addtl frame delimiter, e.g. for netscreen, default none */ uchar *pszInputName; /* value for inputname property, NULL is OK and handled by core engine */ @@ -111,13 +112,14 @@ struct ptcpsrv_s { ptcpsrv_t *pNext; /* linked list maintenance */ uchar *port; /* Port to listen to */ uchar *lstnIP; /* which IP we should listen on? */ - int bEmitMsgOnClose; int iAddtlFrameDelim; uchar *pszInputName; prop_t *pInputName; /* InputName in (fast to process) property format */ ruleset_t *pRuleset; ptcplstn_t *pLstn; /* root of our listeners */ ptcpsess_t *pSess; /* root of our sessions */ + sbool bKeepAlive; /* support keep-alive packets */ + sbool bEmitMsgOnClose; }; /* the ptcp session object. Describes a single active session. @@ -429,12 +431,35 @@ finalize_it: } +/* Enable KEEPALIVE handling on the socket. */ +static inline rsRetVal +EnableKeepAlive(int sock) +{ + int ret; + int optval; + socklen_t optlen; + DEFiRet; + + optval = 1; + optlen = sizeof(optval); + ret = setsockopt(sock, SOL_SOCKET, SO_KEEPALIVE, &optval, optlen); + if(ret < 0) { + dbgprintf("EnableKeepAlive socket call returns error %d\n", ret); + ABORT_FINALIZE(RS_RET_ERR); + } + + dbgprintf("KEEPALIVE enabled for socket %d\n", sock); + +finalize_it: + RETiRet; +} + /* accept an incoming connection request * rgerhards, 2008-04-22 */ static rsRetVal -AcceptConnReq(int sock, int *newSock, prop_t **peerName, prop_t **peerIP) +AcceptConnReq(ptcplstn_t *pLstn, int *newSock, prop_t **peerName, prop_t **peerIP) { int sockflags; struct sockaddr_storage addr; @@ -443,13 +468,17 @@ AcceptConnReq(int sock, int *newSock, prop_t **peerName, prop_t **peerIP) DEFiRet; - iNewSock = accept(sock, (struct sockaddr*) &addr, &addrlen); + iNewSock = accept(pLstn->sock, (struct sockaddr*) &addr, &addrlen); if(iNewSock < 0) { if(errno == EAGAIN || errno == EWOULDBLOCK) ABORT_FINALIZE(RS_RET_NO_MORE_DATA); ABORT_FINALIZE(RS_RET_ACCEPT_ERR); } + if(pLstn->pSrv->bKeepAlive) + EnableKeepAlive(iNewSock); /* we ignore errors, best to do! */ + + CHKiRet(getPeerNames(peerName, peerIP, (struct sockaddr*) &addr)); /* set the new socket to non-blocking IO */ @@ -883,6 +912,7 @@ static rsRetVal addTCPListener(void __attribute__((unused)) *pVal, uchar *pNewVa CHKmalloc(pSrv = malloc(sizeof(ptcpsrv_t))); pSrv->pSess = NULL; pSrv->pLstn = NULL; + pSrv->bKeepAlive = cs.bKeepAlive; pSrv->bEmitMsgOnClose = cs.bEmitMsgOnClose; pSrv->port = pNewVal; pSrv->iAddtlFrameDelim = cs.iAddtlFrameDelim; @@ -946,7 +976,7 @@ lstnActivity(ptcplstn_t *pLstn) DBGPRINTF("imptcp: new connection on listen socket %d\n", pLstn->sock); while(1) { - localRet = AcceptConnReq(pLstn->sock, &newSock, &peerName, &peerIP); + localRet = AcceptConnReq(pLstn, &newSock, &peerName, &peerIP); if(localRet == RS_RET_NO_MORE_DATA) break; CHKiRet(localRet); @@ -1145,6 +1175,7 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __attribute__((unused)) *pVal) { cs.bEmitMsgOnClose = 0; + cs.bKeepAlive = 0; cs.iAddtlFrameDelim = TCPSRV_NO_ADDTL_DELIMITER; free(cs.pszInputName); cs.pszInputName = NULL; @@ -1177,6 +1208,8 @@ CODEmodInit_QueryRegCFSLineHdlr /* register config file handlers */ CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverrun"), 0, eCmdHdlrGetWord, addTCPListener, NULL, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverkeepalive"), 0, eCmdHdlrBinary, + NULL, &cs.bKeepAlive, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpservernotifyonconnectionclose"), 0, eCmdHdlrBinary, NULL, &cs.bEmitMsgOnClose, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserveraddtlframedelimiter"), 0, eCmdHdlrInt, -- cgit From 0f5186ad01d1c429c9ed78a2a3ed3e28e1e67d00 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 13 May 2011 11:07:20 +0200 Subject: added support to control KEEPALIVE settings in imptcp this has not yet been added to imtcp, but could be done on request --- ChangeLog | 2 ++ doc/imptcp.html | 15 +++++++++++ plugins/imptcp/imptcp.c | 68 +++++++++++++++++++++++++++++++++++++++++++++++-- 3 files changed, 83 insertions(+), 2 deletions(-) diff --git a/ChangeLog b/ChangeLog index 69a91ce0..a9084201 100644 --- a/ChangeLog +++ b/ChangeLog @@ -4,6 +4,8 @@ Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? at the socket layer. This has not been added to imttcp, as the latter is only an experimental module, and one which did not prove to be useful. reference: http://kb.monitorware.com/post20791.html +- added support to control KEEPALIVE settings in imptcp + this has not yet been added to imtcp, but could be done on request. - bugfix: do not open files with full privileges, if privs will be dropped This make the privilege drop code more bulletproof, but breaks Ubuntu's work-around for log files created by external programs with the wrong diff --git a/doc/imptcp.html b/doc/imptcp.html index 8784391e..386e691a 100644 --- a/doc/imptcp.html +++ b/doc/imptcp.html @@ -48,6 +48,21 @@ instructs imptcp to emit a message if the remote peer closes a connection.
  • $InputPTCPServerKeepAlive <on/off>
    enable of disable keep-alive packets at the tcp socket layer. The default is to disable them.
    • +
  • $InputPTCPServerKeepAlive_probes <number>
    +The number of unacknowledged probes to send before considering the connection dead and notifying the application layer. +The default, 0, means that the operating system defaults are used. This has only +effect if keep-alive is enabled. The functionality may not be available on +all platforms. +
  • $InputPTCPServerKeepAlive_intvl <number>
    +The interval between subsequential keepalive probes, regardless of what the connection has exchanged in the meantime. +The default, 0, means that the operating system defaults are used. This has only +effect if keep-alive is enabled. The functionality may not be available on +all platforms. +
  • $InputPTCPServerKeepAlive_time <number>
    +The interval between the last data packet sent (simple ACKs are not considered data) and the first keepalive probe; after the connection is marked to need keepalive, this counter is not used any further. +The default, 0, means that the operating system defaults are used. This has only +effect if keep-alive is enabled. The functionality may not be available on +all platforms.
  • $InputPTCPServerRun <port>
    Starts a TCP server on selected port
  • $InputPTCPServerInputName <name>
    diff --git a/plugins/imptcp/imptcp.c b/plugins/imptcp/imptcp.c index 8333e050..8751637d 100644 --- a/plugins/imptcp/imptcp.c +++ b/plugins/imptcp/imptcp.c @@ -50,6 +50,7 @@ #include #include #include +#include #if HAVE_FCNTL_H #include #endif @@ -89,6 +90,9 @@ DEFobjCurrIf(ruleset) /* config settings */ typedef struct configSettings_s { int bKeepAlive; /* support keep-alive packets */ + int iKeepAliveIntvl; + int iKeepAliveProbes; + int iKeepAliveTime; int bEmitMsgOnClose; /* emit an informational message on close by remote peer */ int iAddtlFrameDelim; /* addtl frame delimiter, e.g. for netscreen, default none */ uchar *pszInputName; /* value for inputname property, NULL is OK and handled by core engine */ @@ -113,6 +117,9 @@ struct ptcpsrv_s { uchar *port; /* Port to listen to */ uchar *lstnIP; /* which IP we should listen on? */ int iAddtlFrameDelim; + int iKeepAliveIntvl; + int iKeepAliveProbes; + int iKeepAliveTime; uchar *pszInputName; prop_t *pInputName; /* InputName in (fast to process) property format */ ruleset_t *pRuleset; @@ -433,7 +440,7 @@ finalize_it: /* Enable KEEPALIVE handling on the socket. */ static inline rsRetVal -EnableKeepAlive(int sock) +EnableKeepAlive(ptcplstn_t *pLstn, int sock) { int ret; int optval; @@ -448,6 +455,51 @@ EnableKeepAlive(int sock) ABORT_FINALIZE(RS_RET_ERR); } +# if defined(TCP_KEEPCNT) + if(pLstn->pSrv->iKeepAliveProbes > 0) { + optval = pLstn->pSrv->iKeepAliveProbes; + optlen = sizeof(optval); + ret = setsockopt(sock, SOL_TCP, TCP_KEEPCNT, &optval, optlen); + } else { + ret = 0; + } +# else + ret = -1; +# endif + if(ret < 0) { + errmsg.LogError(ret, NO_ERRCODE, "imptcp cannot set keepalive probes - ignored"); + } + +# if defined(TCP_KEEPCNT) + if(pLstn->pSrv->iKeepAliveTime > 0) { + optval = pLstn->pSrv->iKeepAliveTime; + optlen = sizeof(optval); + ret = setsockopt(sock, SOL_TCP, TCP_KEEPIDLE, &optval, optlen); + } else { + ret = 0; + } +# else + ret = -1; +# endif + if(ret < 0) { + errmsg.LogError(ret, NO_ERRCODE, "imptcp cannot set keepalive time - ignored"); + } + +# if defined(TCP_KEEPCNT) + if(pLstn->pSrv->iKeepAliveIntvl > 0) { + optval = pLstn->pSrv->iKeepAliveIntvl; + optlen = sizeof(optval); + ret = setsockopt(sock, SOL_TCP, TCP_KEEPINTVL, &optval, optlen); + } else { + ret = 0; + } +# else + ret = -1; +# endif + if(ret < 0) { + errmsg.LogError(errno, NO_ERRCODE, "imptcp cannot set keepalive intvl - ignored"); + } + dbgprintf("KEEPALIVE enabled for socket %d\n", sock); finalize_it: @@ -476,7 +528,7 @@ AcceptConnReq(ptcplstn_t *pLstn, int *newSock, prop_t **peerName, prop_t **peerI } if(pLstn->pSrv->bKeepAlive) - EnableKeepAlive(iNewSock); /* we ignore errors, best to do! */ + EnableKeepAlive(pLstn, iNewSock);/* we ignore errors, best to do! */ CHKiRet(getPeerNames(peerName, peerIP, (struct sockaddr*) &addr)); @@ -913,6 +965,9 @@ static rsRetVal addTCPListener(void __attribute__((unused)) *pVal, uchar *pNewVa pSrv->pSess = NULL; pSrv->pLstn = NULL; pSrv->bKeepAlive = cs.bKeepAlive; + pSrv->iKeepAliveIntvl = cs.iKeepAliveTime; + pSrv->iKeepAliveProbes = cs.iKeepAliveProbes; + pSrv->iKeepAliveTime = cs.iKeepAliveTime; pSrv->bEmitMsgOnClose = cs.bEmitMsgOnClose; pSrv->port = pNewVal; pSrv->iAddtlFrameDelim = cs.iAddtlFrameDelim; @@ -1176,6 +1231,9 @@ resetConfigVariables(uchar __attribute__((unused)) *pp, void __attribute__((unus { cs.bEmitMsgOnClose = 0; cs.bKeepAlive = 0; + cs.iKeepAliveProbes = 0; + cs.iKeepAliveTime = 0; + cs.iKeepAliveIntvl = 0; cs.iAddtlFrameDelim = TCPSRV_NO_ADDTL_DELIMITER; free(cs.pszInputName); cs.pszInputName = NULL; @@ -1210,6 +1268,12 @@ CODEmodInit_QueryRegCFSLineHdlr addTCPListener, NULL, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverkeepalive"), 0, eCmdHdlrBinary, NULL, &cs.bKeepAlive, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverkeepalive_probes"), 0, eCmdHdlrInt, + NULL, &cs.iKeepAliveProbes, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverkeepalive_time"), 0, eCmdHdlrInt, + NULL, &cs.iKeepAliveTime, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserverkeepalive_intvl"), 0, eCmdHdlrInt, + NULL, &cs.iKeepAliveIntvl, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpservernotifyonconnectionclose"), 0, eCmdHdlrBinary, NULL, &cs.bEmitMsgOnClose, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr(UCHAR_CONSTANT("inputptcpserveraddtlframedelimiter"), 0, eCmdHdlrInt, -- cgit From 4de5aa20bc9620562d93658858903aac86b1ce00 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 13 May 2011 14:11:34 +0200 Subject: mmsnmptrapd: doc bugfix and fix issue with config stmt handler --- doc/mmsnmptrapd.html | 9 ++++++--- plugins/mmsnmptrapd/mmsnmptrapd.c | 2 +- 2 files changed, 7 insertions(+), 4 deletions(-) diff --git a/doc/mmsnmptrapd.html b/doc/mmsnmptrapd.html index e69bc241..5dfb392b 100644 --- a/doc/mmsnmptrapd.html +++ b/doc/mmsnmptrapd.html @@ -51,8 +51,11 @@ to control output modules are also available to mmsnmptrapd.
    • $mmsnmptrapdTag [tagname]
      tells the module which start string inside the tag to look for. The default is -"snmptrap/" -
    • $mmsnmptrapdSevertiyMapping [severtiymap]
      +"snmptrap". Note that a slash is automatically added to this tag when it comes to +matching incoming messages. It MUST not be given, except if two slashes are required +for whatever reasons (so "tag/" results in a check for "tag//" at the start of +the tag field). +
    • $mmsnmptrapdSeverityMapping [severtiymap]
      This specifies the severity mapping table. It needs to be specified as a list. Note that due to the current config system no whitespace is supported inside the list, so be sure not to use any whitespace inside it.
      @@ -76,7 +79,7 @@ severities. The default tag is used.
      # ... other module loads and listener setup ... *.* /path/to/file/with/orignalMessage # this file receives *un*modified messages $mmsnmptrapdSeverityMapping warning/4,error/3 -*.* ::mmsnmptrapd: # *now* message is modified +*.* :mmsnmptrapd: # *now* message is modified *.* /path/to/file/with/modifiedMessage # this file receives modified messages # ... rest of config ... diff --git a/plugins/mmsnmptrapd/mmsnmptrapd.c b/plugins/mmsnmptrapd/mmsnmptrapd.c index 8f996832..9311d5c6 100644 --- a/plugins/mmsnmptrapd/mmsnmptrapd.c +++ b/plugins/mmsnmptrapd/mmsnmptrapd.c @@ -421,7 +421,7 @@ CODEmodInit_QueryRegCFSLineHdlr cs.pszTagName = NULL; cs.pszSeverityMapping = NULL; - CHKiRet(omsdRegCFSLineHdlr((uchar *)"mmsnmptrapdtag", 0, eCmdHdlrInt, + CHKiRet(omsdRegCFSLineHdlr((uchar *)"mmsnmptrapdtag", 0, eCmdHdlrGetWord, NULL, &cs.pszTagName, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"mmsnmptrapdseveritymapping", 0, eCmdHdlrGetWord, NULL, &cs.pszSeverityMapping, STD_LOADABLE_MODULE_ID)); -- cgit From 1cd5224a9cd3a036053b185ef3af1be7e0a455d0 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 13 May 2011 14:17:02 +0200 Subject: doc bugfix: yet another typo ... am I really that dumb... ;) --- configure.ac | 2 +- doc/mmsnmptrapd.html | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/configure.ac b/configure.ac index 6ac6ff65..fb0cff8d 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ(2.61) -AC_INIT([rsyslog],[5.8.0],[rsyslog@lists.adiscon.com]) +AC_INIT([rsyslog],[5.8.1-pre3],[rsyslog@lists.adiscon.com]) AM_INIT_AUTOMAKE m4_ifdef([AM_SILENT_RULES], [AM_SILENT_RULES([yes])]) diff --git a/doc/mmsnmptrapd.html b/doc/mmsnmptrapd.html index 5dfb392b..699049d3 100644 --- a/doc/mmsnmptrapd.html +++ b/doc/mmsnmptrapd.html @@ -51,7 +51,7 @@ to control output modules are also available to mmsnmptrapd.
      • $mmsnmptrapdTag [tagname]
        tells the module which start string inside the tag to look for. The default is -"snmptrap". Note that a slash is automatically added to this tag when it comes to +"snmptrapd". Note that a slash is automatically added to this tag when it comes to matching incoming messages. It MUST not be given, except if two slashes are required for whatever reasons (so "tag/" results in a check for "tag//" at the start of the tag field). -- cgit From 59056371156616274d9970300b3ab02432201422 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Tue, 24 May 2011 09:34:14 +0200 Subject: enhanced imfile to support input batching --- ChangeLog | 1 + plugins/imfile/imfile.c | 14 +++++++++++++- 2 files changed, 14 insertions(+), 1 deletion(-) diff --git a/ChangeLog b/ChangeLog index 665ed184..0d35ce0f 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,4 @@ +- enhanced imfile to support input batching --------------------------------------------------------------------------- Version 5.8.1 [V5-stable] (rgerhards), 2011-05-19 - bugfix: invalid processing in QUEUE_FULL condition diff --git a/plugins/imfile/imfile.c b/plugins/imfile/imfile.c index cac3a55d..415eb137 100644 --- a/plugins/imfile/imfile.c +++ b/plugins/imfile/imfile.c @@ -64,6 +64,7 @@ DEFobjCurrIf(strm) DEFobjCurrIf(prop) DEFobjCurrIf(ruleset) +#define NUM_MULTISUB 1024 /* max number of submits -- TODO: make configurable */ typedef struct fileInfo_s { uchar *pszFileName; uchar *pszTag; @@ -76,6 +77,7 @@ typedef struct fileInfo_s { strm_t *pStrm; /* its stream (NULL if not assigned) */ int readMode; /* which mode to use in ReadMulteLine call? */ ruleset_t *pRuleset; /* ruleset to bind listener to (use system default if unspecified) */ + multi_submit_t multiSub; } fileInfo_t; @@ -122,7 +124,9 @@ static rsRetVal enqLine(fileInfo_t *pInfo, cstr_t *cstrLine) pMsg->iFacility = LOG_FAC(pInfo->iFacility); pMsg->iSeverity = LOG_PRI(pInfo->iSeverity); MsgSetRuleset(pMsg, pInfo->pRuleset); - CHKiRet(submitMsg(pMsg)); + pInfo->multiSub.ppMsgs[pInfo->multiSub.nElem++] = pMsg; + if(pInfo->multiSub.nElem == pInfo->multiSub.maxElem) + CHKiRet(multiSubmitMsg(&pInfo->multiSub)); finalize_it: RETiRet; } @@ -229,8 +233,13 @@ static rsRetVal pollFile(fileInfo_t *pThis, int *pbHadFileData) pThis->nRecords = 0; } } + /* NOTE: This is usually not reached due to loop exit via CHKiRet() only! */ finalize_it: + if(pThis->multiSub.nElem > 0) { + /* submit everything that was not yet submitted */ + CHKiRet(multiSubmitMsg(&pThis->multiSub)); + } ; /*EMPTY STATEMENT - needed to keep compiler happy - see below! */ /* Note: the problem above is that pthread:cleanup_pop() is a macro which * evaluates to something like "} while(0);". So the code would become @@ -513,6 +522,9 @@ static rsRetVal addMonitor(void __attribute__((unused)) *pVal, uchar *pNewVal) pThis->pszStateFile = (uchar*) strdup((char*) pszStateFile); } + CHKmalloc(pThis->multiSub.ppMsgs = MALLOC(NUM_MULTISUB * sizeof(msg_t*))); + pThis->multiSub.maxElem = NUM_MULTISUB; + pThis->multiSub.nElem = 0; pThis->iSeverity = iSeverity; pThis->iFacility = iFacility; pThis->iPersistStateInterval = iPersistStateInterval; -- cgit From ffdc33e3f178ad85ba5c2c9f7fcee98b743e9d5e Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Tue, 24 May 2011 10:09:43 +0200 Subject: imfile: added $InputFileMaxLinesAtOnce directive --- ChangeLog | 1 + doc/imfile.html | 11 +++++++++-- plugins/imfile/imfile.c | 11 ++++++++++- tests/inputfilegen.c | 1 + 4 files changed, 21 insertions(+), 3 deletions(-) diff --git a/ChangeLog b/ChangeLog index 0d35ce0f..d139f5b3 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,4 @@ +- imfile: added $InputFileMaxLinesAtOnce directive - enhanced imfile to support input batching --------------------------------------------------------------------------- Version 5.8.1 [V5-stable] (rgerhards), 2011-05-19 diff --git a/doc/imfile.html b/doc/imfile.html index 60726ceb..60bbbeea 100644 --- a/doc/imfile.html +++ b/doc/imfile.html @@ -98,9 +98,16 @@ performance, especially when set to a low value. Frequently writing the state file is very time consuming.
      • $InputFileReadMode [mode]
        Available in 5.7.5+ +
      • $InputFileMaxLinesAtOnce [number]
        +Available in 5.9.0+
        -Mode to be used when reading lines. 0 (the default) means that each line is forwarded -as its own log message. +This is useful if multiple files need to be monitored. If set to 0, each file +will be fully processed and then processing switches to the next file +(this was the default in previous versions). If it is set, a maximum of +[number] lines is processed in sequence for each file, and then the file is +switched. This provides a kind of mutiplexing the load of multiple files and +probably leads to a more natural distribution of events when multiple busy files +are monitored. The default is 10240.
      • $InputFileBindRuleset <ruleset>
        Available in 5.7.5+, 6.1.5+ Binds the listener to a specific         ruleset.
        • diff --git a/plugins/imfile/imfile.c b/plugins/imfile/imfile.c index 415eb137..9bc84220 100644 --- a/plugins/imfile/imfile.c +++ b/plugins/imfile/imfile.c @@ -72,6 +72,7 @@ typedef struct fileInfo_s { uchar *pszStateFile; /* file in which state between runs is to be stored */ int iFacility; int iSeverity; + int maxLinesAtOnce; int nRecords; /**< How many records did we process before persisting the stream? */ int iPersistStateInterval; /**< how often should state be persisted? (0=on close only) */ strm_t *pStrm; /* its stream (NULL if not assigned) */ @@ -93,6 +94,7 @@ static int iPersistStateInterval = 0; /* how often if state file to be persisted static int iFacility = 128; /* local0 */ static int iSeverity = 5; /* notice, as of rfc 3164 */ static int readMode = 0; /* mode to use for ReadMultiLine call */ +static int maxLinesAtOnce = 10240; /* how many lines to process in a row? */ static ruleset_t *pBindRuleset = NULL; /* ruleset to bind listener to (use system default if unspecified) */ static int iFilPtr = 0; /* number of files to be monitored; pointer to next free spot during config */ @@ -210,6 +212,7 @@ static void pollFileCancelCleanup(void *pArg) static rsRetVal pollFile(fileInfo_t *pThis, int *pbHadFileData) { cstr_t *pCStr = NULL; + int nProcessed = 0; DEFiRet; ASSERT(pbHadFileData != NULL); @@ -224,7 +227,10 @@ static rsRetVal pollFile(fileInfo_t *pThis, int *pbHadFileData) /* loop below will be exited when strmReadLine() returns EOF */ while(glbl.GetGlobalInputTermState() == 0) { + if(pThis->maxLinesAtOnce != 0 && nProcessed >= pThis->maxLinesAtOnce) + break; CHKiRet(strm.ReadLine(pThis->pStrm, &pCStr, pThis->readMode)); + ++nProcessed; *pbHadFileData = 1; /* this is just a flag, so set it and forget it */ CHKiRet(enqLine(pThis, pCStr)); /* process line */ rsCStrDestruct(&pCStr); /* discard string (must be done by us!) */ @@ -233,7 +239,6 @@ static rsRetVal pollFile(fileInfo_t *pThis, int *pbHadFileData) pThis->nRecords = 0; } } - /* NOTE: This is usually not reached due to loop exit via CHKiRet() only! */ finalize_it: if(pThis->multiSub.nElem > 0) { @@ -484,6 +489,7 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __a iSeverity = 5; /* notice, as of rfc 3164 */ readMode = 0; pBindRuleset = NULL; + maxLinesAtOnce = 10240; RETiRet; } @@ -527,6 +533,7 @@ static rsRetVal addMonitor(void __attribute__((unused)) *pVal, uchar *pNewVal) pThis->multiSub.nElem = 0; pThis->iSeverity = iSeverity; pThis->iFacility = iFacility; + pThis->maxLinesAtOnce = maxLinesAtOnce; pThis->iPersistStateInterval = iPersistStateInterval; pThis->nRecords = 0; pThis->readMode = readMode; @@ -604,6 +611,8 @@ CODEmodInit_QueryRegCFSLineHdlr NULL, &iPollInterval, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputfilereadmode", 0, eCmdHdlrInt, NULL, &readMode, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputfilemaxlinesatonce", 0, eCmdHdlrSize, + NULL, &maxLinesAtOnce, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputfilepersiststateinterval", 0, eCmdHdlrInt, NULL, &iPersistStateInterval, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputfilebindruleset", 0, eCmdHdlrGetWord, diff --git a/tests/inputfilegen.c b/tests/inputfilegen.c index 26fb79af..0ff8d049 100644 --- a/tests/inputfilegen.c +++ b/tests/inputfilegen.c @@ -1,5 +1,6 @@ /* generate an input file suitable for use by the testbench * Copyright (C) 2011 by Rainer Gerhards and Adiscon GmbH. + * usage: ./inputfilegen num-lines > file * Part of rsyslog, licensed under GPLv3 */ #include -- cgit From 209948aa4da22727a33c408d4c7961dcd1f630fc Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Tue, 7 Jun 2011 19:07:23 +0200 Subject: set queue name to aciton name (useful for impstats!) so far untested, test follows --- action.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/action.c b/action.c index c5bd03cb..6a8bd2a3 100644 --- a/action.c +++ b/action.c @@ -290,7 +290,12 @@ actionConstructFinalize(action_t *pThis) ASSERT(pThis != NULL); /* find a name for our queue */ - snprintf((char*) pszQName, sizeof(pszQName)/sizeof(uchar), "action %d queue", iActionNbr); + if(pThis->pszName == NULL) { + snprintf((char*) pszQName, sizeof(pszQName)/sizeof(uchar), "action %d queue", iActionNbr); + } else { + strncpy(pszQName, pThis->pszName, sizeof(pszQName)); + pszQName[63] = '\0'; /* to be on the save side */ + } /* now check if we can run the action in "firehose mode" during stage one of * its processing (that is before messages are enqueued into the action q). -- cgit From e1f7577b4881d9c72985be4001adfd2e58894abf Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 10 Jun 2011 01:14:15 +0200 Subject: bugfix: error state not correctly set for gone-away config directive --- tools/omfile.c | 1 + 1 file changed, 1 insertion(+) diff --git a/tools/omfile.c b/tools/omfile.c index 7585ea8c..4e80e2f6 100644 --- a/tools/omfile.c +++ b/tools/omfile.c @@ -238,6 +238,7 @@ rsRetVal setDynaFileCacheSize(void __attribute__((unused)) *pVal, int iNewVal) rsRetVal goneAway(void __attribute__((unused)) *pVal, int iNewVal) { errmsg.LogError(0, RS_RET_ERR, "directive $omfileForceChown is no longer supported"); + return RS_RET_ERR; } -- cgit From 8851decb0fbd82f3fd88fe2a0b7e662ef4479e71 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 10 Jun 2011 01:28:04 +0200 Subject: $ActionName is now also used for naming of queues in impstats... ...as well as in the debug output. This functionality has now been fully tested. --- ChangeLog | 2 ++ 1 file changed, 2 insertions(+) diff --git a/ChangeLog b/ChangeLog index 1150de9a..fb55044f 100644 --- a/ChangeLog +++ b/ChangeLog @@ -8,6 +8,8 @@ Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? reference: http://kb.monitorware.com/post20791.html - added support to control KEEPALIVE settings in imptcp this has not yet been added to imtcp, but could be done on request. +- $ActionName is now also used for naming of queues in impstats + as well as in the debug output - bugfix: do not open files with full privileges, if privs will be dropped This make the privilege drop code more bulletproof, but breaks Ubuntu's work-around for log files created by external programs with the wrong -- cgit From 49d7b4cd666429ece524ea4b3b2bd4041b5662e5 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 10 Jun 2011 03:39:40 +0200 Subject: preparing for 5.9.0 --- ChangeLog | 2 +- action.c | 2 +- configure.ac | 2 +- doc/manual.html | 2 +- tests/testsuites/imfile-basic.conf | 1 + 5 files changed, 5 insertions(+), 4 deletions(-) diff --git a/ChangeLog b/ChangeLog index fb55044f..855534d8 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,5 @@ --------------------------------------------------------------------------- -Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-03-?? +Version 5.9.0 [V5-DEVEL] (rgerhards), 2011-06-08 - imfile: added $InputFileMaxLinesAtOnce directive - enhanced imfile to support input batching - added capability for imtcp and imptcp to activate keep-alive packets diff --git a/action.c b/action.c index 6a8bd2a3..b4762379 100644 --- a/action.c +++ b/action.c @@ -293,7 +293,7 @@ actionConstructFinalize(action_t *pThis) if(pThis->pszName == NULL) { snprintf((char*) pszQName, sizeof(pszQName)/sizeof(uchar), "action %d queue", iActionNbr); } else { - strncpy(pszQName, pThis->pszName, sizeof(pszQName)); + ustrncpy(pszQName, pThis->pszName, sizeof(pszQName)); pszQName[63] = '\0'; /* to be on the save side */ } diff --git a/configure.ac b/configure.ac index 1faaff89..49d8f2fa 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ(2.61) -AC_INIT([rsyslog],[5.8.1],[rsyslog@lists.adiscon.com]) +AC_INIT([rsyslog],[5.9.0],[rsyslog@lists.adiscon.com]) AM_INIT_AUTOMAKE m4_ifdef([AM_SILENT_RULES], [AM_SILENT_RULES([yes])]) diff --git a/doc/manual.html b/doc/manual.html index 5c656752..f6ae3000 100644 --- a/doc/manual.html +++ b/doc/manual.html @@ -19,7 +19,7 @@ rsyslog support available directly from the source!

        Please visit the rsyslog sponsor's page to honor the project sponsors or become one yourself! We are very grateful for any help towards the project goals.

        -

        This documentation is for version 5.8.1 (stable branch) of rsyslog. +

        This documentation is for version 5.9.0 (stable branch) of rsyslog. Visit the rsyslog status page to obtain current version information and project status.

        If you like rsyslog, you might diff --git a/tests/testsuites/imfile-basic.conf b/tests/testsuites/imfile-basic.conf index 9fb9b5ca..59b109a6 100644 --- a/tests/testsuites/imfile-basic.conf +++ b/tests/testsuites/imfile-basic.conf @@ -6,6 +6,7 @@ $InputFileTag file: $InputFileStateFile stat-file1 $InputFileSeverity error $InputFileFacility local7 +$InputFileMaxLinesAtOnce 100000 $InputRunFileMonitor $template outfmt,"%msg:F,58:2%\n" -- cgit From d5f78989d8fd2a3c11fd1e6ed1cd4d688b1e6728 Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Mon, 20 Jun 2011 12:17:51 +0200 Subject: added support for obtaining timestamp from system for imuxsock This permits to read the time a message was submitted to the system log socket. Most importantly, this is provided in microsecond resolution. So we are able to obtain high precision timestampis even for messages that were - as is usual - not formatted with them. This also simplifies things in regard to local time calculation in chroot environments. Many thanks to Lennart Poettering for suggesting this feature, providing some guidance on implementing it and coordinating getting the necessary support into the Linux kernel. --- ChangeLog | 9 ++++++ configure.ac | 2 ++ doc/imuxsock.html | 12 ++++++- plugins/imuxsock/imuxsock.c | 74 ++++++++++++++++++++++++++++++++++++------- runtime/datetime.c | 77 +++++++++++++++++++++++++-------------------- runtime/datetime.h | 5 ++- 6 files changed, 132 insertions(+), 47 deletions(-) diff --git a/ChangeLog b/ChangeLog index 6391ab99..c13cc142 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,14 @@ --------------------------------------------------------------------------- Version 5.9.1 [V5-DEVEL] (rgerhards), 2011-06-?? +- added support for obtaining timestamp from system for imuxsock + This permits to read the time a message was submitted to the system + log socket. Most importantly, this is provided in microsecond resolution. + So we are able to obtain high precision timestampis even for messages + that were - as is usual - not formatted with them. This also simplifies + things in regard to local time calculation in chroot environments. + Many thanks to Lennart Poettering for suggesting this feature, + providing some guidance on implementing it and coordinating getting the + necessary support into the Linux kernel. - bugfix: timestamp was incorrectly calculated for timezones with minute offset closes: http://bugzilla.adiscon.com/show_bug.cgi?id=271 diff --git a/configure.ac b/configure.ac index 49d8f2fa..41468f16 100644 --- a/configure.ac +++ b/configure.ac @@ -118,6 +118,8 @@ AC_CHECK_FUNCS([flock basename alarm clock_gettime gethostbyname gethostname get # let me know! -- rgerhards, 2010-10-06 AC_CHECK_DECL([SCM_CREDENTIALS], [AC_DEFINE(HAVE_SCM_CREDENTIALS, [1], [set define])], [], [#include #include ]) +AC_CHECK_DECL([SO_TIMESTAMP], [AC_DEFINE(HAVE_SO_TIMESTAMP, [1], [set define])], [], [#include +#include ]) # Check for MAXHOSTNAMELEN AC_MSG_CHECKING(for MAXHOSTNAMELEN) diff --git a/doc/imuxsock.html b/doc/imuxsock.html index ee5db22d..58b3ae54 100644 --- a/doc/imuxsock.html +++ b/doc/imuxsock.html @@ -68,9 +68,18 @@ messages that shall be rate-limited. be obtained from the log socket itself. If so, the TAG part of the message is rewritten. It is recommended to turn this option on, but the default is "off" to keep compatible with earlier versions of rsyslog. This option was introduced in 5.7.0. +

      • $InputUnixListenSocketUseSysTimeStamp [on/off] instructs imuxsock +to obtain message time from the system (via control messages) insted of using time +recorded inside the message. This may be most useful in combination with systemd. Note: +this option was introduced with version 5.9.1. Due to the usefulness of it, we +decided to enable it by default. As such, 5.9.1 and above behave slightly different +than previous versions. However, we do not see how this could negatively affect +existing environments.
      • $SystemLogSocketIgnoreMsgTimestamp [on/off]
        Ignore timestamps included in the messages, applies to messages received via the system log socket.
        • -
      • $OmitLocalLogging (imuxsock) [on/off] -- former -o option
        • +
      • $OmitLocalLogging (imuxsock) [on/off] -- former -o option; +do NOT listen for the local log socket. This is most useful if you run multiple +instances of rsyslogd where only one shall handle the system log socket.
      • $SystemLogSocketName <name-of-socket> -- former -p option
      • $SystemLogFlowControl [on/off] - specifies if flow control should be applied to the system log socket.
        • @@ -87,6 +96,7 @@ burst in number of messages. Default is 200.
      • $SystemLogRateLimitSeverity [numerical severity] - specifies the severity of messages that shall be rate-limited.
        • +
      • $SystemLogUseSysTimeStamp [on/off] the same as $InputUnixListenSocketUseSysTimeStamp, but for the system log socket.
      • $InputUnixListenSocketCreatePath [on/off] - create directories in the socket path if they do not already exist. They are created with 0755 permissions with the owner being the process under which rsyslogd runs. The default is not to create directories. Keep in mind, though, that rsyslogd always diff --git a/plugins/imuxsock/imuxsock.c b/plugins/imuxsock/imuxsock.c index af034b9f..da9eb993 100644 --- a/plugins/imuxsock/imuxsock.c +++ b/plugins/imuxsock/imuxsock.c @@ -6,7 +6,7 @@ * * File begun on 2007-12-20 by RGerhards (extracted from syslogd.c) * - * Copyright 2007-2010 Rainer Gerhards and Adiscon GmbH. + * Copyright 2007-2011 Rainer Gerhards and Adiscon GmbH. * * This file is part of rsyslog. * @@ -136,6 +136,7 @@ typedef struct lstn_s { sbool bCreatePath; /* auto-creation of socket directory? */ sbool bUseCreds; /* pull original creator credentials from socket */ sbool bWritePid; /* write original PID into tag */ + sbool bUseSysTimeStamp; /* use timestamp from system (instead of from message) */ } lstn_t; static lstn_t listeners[MAXFUNIX]; @@ -156,6 +157,8 @@ static int bUseFlowCtl = 0; /* use flow control or not (if yes, only LIGHT is u static int bIgnoreTimestamp = 1; /* ignore timestamps present in the incoming message? */ static int bWritePid = 0; /* use credentials from recvmsg() and fixup PID in TAG */ static int bWritePidSysSock = 0; /* use credentials from recvmsg() and fixup PID in TAG */ +static int bUseSysTimeStamp = 1; /* use timestamp from system (rather than from message) */ +static int bUseSysTimeStampSysSock = 1; /* same, for system log socket */ #define DFLT_bCreatePath 0 static int bCreatePath = DFLT_bCreatePath; /* auto-create socket path? */ #define DFLT_ratelimitInterval 5 @@ -302,6 +305,7 @@ addLstnSocketName(void __attribute__((unused)) *pVal, uchar *pNewVal) listeners[nfd].sockName = pNewVal; listeners[nfd].bUseCreds = (bWritePid || ratelimitInterval) ? 1 : 0; listeners[nfd].bWritePid = bWritePid; + listeners[nfd].bUseSysTimeStamp = bUseSysTimeStamp; nfd++; } else { errmsg.LogError(0, NO_ERRCODE, "Out of unix socket name descriptors, ignoring %s\n", @@ -415,6 +419,10 @@ openLogSocket(lstn_t *pLstn) errmsg.LogError(errno, NO_ERRCODE, "set SCM_CREDENTIALS failed on '%s'", pLstn->sockName); pLstn->bUseCreds = 0; } +// TODO: move to its own #if + if(setsockopt(pLstn->fd, SOL_SOCKET, SO_TIMESTAMP, &one, sizeof(one)) != 0) { + errmsg.LogError(errno, NO_ERRCODE, "set SO_TIMESTAMP failed on '%s'", pLstn->sockName); + } } # else /* HAVE_SCM_CREDENTIALS */ pLstn->bUseCreds = 0; @@ -505,7 +513,7 @@ fixPID(uchar *bufTAG, int *lenTag, struct ucred *cred) * can also mangle it if necessary. */ static inline rsRetVal -SubmitMsg(uchar *pRcv, int lenRcv, lstn_t *pLstn, struct ucred *cred) +SubmitMsg(uchar *pRcv, int lenRcv, lstn_t *pLstn, struct ucred *cred, struct timeval *ts) { msg_t *pMsg; int lenMsg; @@ -544,7 +552,13 @@ SubmitMsg(uchar *pRcv, int lenRcv, lstn_t *pLstn, struct ucred *cred) findRatelimiter(pLstn, cred, &ratelimiter); /* ignore error, better so than others... */ } - datetime.getCurrTime(&st, &tt); + if(ts == NULL) { + datetime.getCurrTime(&st, &tt); + } else { + datetime.timeval2syslogTime(ts, &st); + tt = ts->tv_sec; + } + if(ratelimiter != NULL && !withinRatelimit(ratelimiter, tt, cred->pid)) { STATSCOUNTER_INC(ctrLostRatelimit, mutCtrLostRatelimit); FINALIZE; @@ -564,8 +578,26 @@ SubmitMsg(uchar *pRcv, int lenRcv, lstn_t *pLstn, struct ucred *cred) parse++; lenMsg--; /* '>' */ - if(datetime.ParseTIMESTAMP3164(&(pMsg->tTIMESTAMP), &parse, &lenMsg) != RS_RET_OK) { - DBGPRINTF("we have a problem, invalid timestamp in msg!\n"); + if(ts == NULL) { + if(datetime.ParseTIMESTAMP3164(&(pMsg->tTIMESTAMP), &parse, &lenMsg) != RS_RET_OK) { + DBGPRINTF("we have a problem, invalid timestamp in msg!\n"); + } + } else { /* if we pulled the time from the system, we need to update the message text */ + if(lenMsg >= 16) { + /* RFC3164 timestamp is 16 bytes long, so assuming a valid stamp, + * we can fixup the message. If the part is smaller, the stamp can + * not be valid and we do not touch the message. Note that there may + * be some scenarios where the message is larg enough but the stamp is + * still invalid. In those cases we will destruct part of the message, + * but this case is considered extremely unlikely and thus not handled + * specifically. -- rgerhards, 2011-06-20 + */ + datetime.formatTimestamp3164(&st, (char*)parse, 0); + parse[15] = ' '; /* re-write \0 from fromatTimestamp3164 by SP */ + /* update "counters" to reflect processed timestamp */ + parse += 16; + lenMsg -= 16; + } } /* pull tag */ @@ -616,6 +648,7 @@ static rsRetVal readSocket(lstn_t *pLstn) struct cmsghdr *cm; # endif struct ucred *cred; + struct timeval *ts; uchar bufRcv[4096+1]; char aux[128]; uchar *pRcv = NULL; /* receive buffer */ @@ -654,21 +687,32 @@ static rsRetVal readSocket(lstn_t *pLstn) dbgprintf("Message from UNIX socket: #%d\n", pLstn->fd); if(iRcvd > 0) { cred = NULL; -# if HAVE_SCM_CREDENTIALS - if(pLstn->bUseCreds) { + ts = NULL; + if(pLstn->bUseCreds || pLstn->bUseSysTimeStamp) { dbgprintf("XXX: pre CM loop, length of control message %d\n", (int) msgh.msg_controllen); - for (cm = CMSG_FIRSTHDR(&msgh); cm; cm = CMSG_NXTHDR(&msgh, cm)) { + for(cm = CMSG_FIRSTHDR(&msgh); cm; cm = CMSG_NXTHDR(&msgh, cm)) { dbgprintf("XXX: in CM loop, %d, %d\n", cm->cmsg_level, cm->cmsg_type); - if (cm->cmsg_level == SOL_SOCKET && cm->cmsg_type == SCM_CREDENTIALS) { +# if HAVE_SCM_CREDENTIALS + if( pLstn->bUseCreds + && cm->cmsg_level == SOL_SOCKET && cm->cmsg_type == SCM_CREDENTIALS) { cred = (struct ucred*) CMSG_DATA(cm); dbgprintf("XXX: got credentials pid %d\n", (int) cred->pid); break; } +# endif /* HAVE_SCM_CREDENTIALS */ +# if HAVE_SO_TIMESTAMP + if( pLstn->bUseSysTimeStamp + && cm->cmsg_level == SOL_SOCKET && cm->cmsg_type == SO_TIMESTAMP) { + ts = (struct timeval *)CMSG_DATA(cm); + dbgprintf("XXX: got timestamp %ld.%ld\n", + (long) ts->tv_sec, (long) ts->tv_usec); + break; + } +# endif /* HAVE_SO_TIMESTAMP */ } dbgprintf("XXX: post CM loop\n"); } -# endif /* HAVE_SCM_CREDENTIALS */ - CHKiRet(SubmitMsg(pRcv, iRcvd, pLstn, cred)); + CHKiRet(SubmitMsg(pRcv, iRcvd, pLstn, cred, ts)); } else if(iRcvd < 0 && errno != EINTR) { char errStr[1024]; rs_strerror_r(errno, errStr, sizeof(errStr)); @@ -780,6 +824,7 @@ CODESTARTwillRun listeners[0].ratelimitSev = ratelimitSeveritySysSock; listeners[0].bUseCreds = (bWritePidSysSock || ratelimitIntervalSysSock) ? 1 : 0; listeners[0].bWritePid = bWritePidSysSock; + listeners[0].bUseSysTimeStamp = bUseSysTimeStampSysSock; sd_fds = sd_listen_fds(0); if (sd_fds < 0) { @@ -892,6 +937,8 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __a bUseFlowCtl = 0; bWritePid = 0; bWritePidSysSock = 0; + bUseSysTimeStamp = 1; + bUseSysTimeStampSysSock = 1; bCreatePath = DFLT_bCreatePath; ratelimitInterval = DFLT_ratelimitInterval; ratelimitIntervalSysSock = DFLT_ratelimitInterval; @@ -927,6 +974,7 @@ CODEmodInit_QueryRegCFSLineHdlr listeners[0].bParseHost = 0; listeners[0].bUseCreds = 0; listeners[0].bCreatePath = 0; + listeners[0].bUseSysTimeStamp = 1; /* initialize socket names */ for(i = 1 ; i < MAXFUNIX ; ++i) { @@ -958,6 +1006,8 @@ CODEmodInit_QueryRegCFSLineHdlr NULL, &bCreatePath, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputunixlistensocketusepidfromsystem", 0, eCmdHdlrBinary, NULL, &bWritePid, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr((uchar *)"inputunixlistensocketusesystimestamp", 0, eCmdHdlrBinary, + NULL, &bUseSysTimeStamp, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"addunixlistensocket", 0, eCmdHdlrGetWord, addLstnSocketName, NULL, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"imuxsockratelimitinterval", 0, eCmdHdlrInt, @@ -978,6 +1028,8 @@ CODEmodInit_QueryRegCFSLineHdlr setSystemLogTimestampIgnore, NULL, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"systemlogsocketflowcontrol", 0, eCmdHdlrBinary, setSystemLogFlowControl, NULL, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr((uchar *)"systemlogusesystimestamp", 0, eCmdHdlrBinary, + NULL, &bUseSysTimeStampSysSock, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"systemlogusepidfromsystem", 0, eCmdHdlrBinary, NULL, &bWritePidSysSock, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"systemlogratelimitinterval", 0, eCmdHdlrInt, diff --git a/runtime/datetime.c b/runtime/datetime.c index f81180ea..89452f1c 100644 --- a/runtime/datetime.c +++ b/runtime/datetime.c @@ -55,6 +55,47 @@ static const int tenPowers[6] = { 1, 10, 100, 1000, 10000, 100000 }; /* ------------------------------ methods ------------------------------ */ +/** + * Convert struct timeval to syslog_time + */ +void +timeval2syslogTime(struct timeval *tp, struct syslogTime *t) +{ + struct tm *tm; + struct tm tmBuf; + long lBias; + + tm = localtime_r((time_t*) &(tp->tv_sec), &tmBuf); + + t->year = tm->tm_year + 1900; + t->month = tm->tm_mon + 1; + t->day = tm->tm_mday; + t->hour = tm->tm_hour; + t->minute = tm->tm_min; + t->second = tm->tm_sec; + t->secfrac = tp->tv_usec; + t->secfracPrecision = 6; + +# if __sun + /* Solaris uses a different method of exporting the time zone. + * It is UTC - localtime, which is the opposite sign of mins east of GMT. + */ + lBias = -(daylight ? altzone : timezone); +# elif defined(__hpux) + lBias = tz.tz_dsttime ? - tz.tz_minuteswest : 0; +# else + lBias = tm->tm_gmtoff; +# endif + if(lBias < 0) { + t->OffsetMode = '-'; + lBias *= -1; + } else + t->OffsetMode = '+'; + t->OffsetHour = lBias / 3600; + t->OffsetMinute = (lBias % 3600) / 60; + t->timeType = TIME_TYPE_RFC5424; /* we have a high precision timestamp */ +} + /** * Get the current date/time in the best resolution the operating * system has to offer (well, actually at most down to the milli- @@ -74,9 +115,6 @@ static const int tenPowers[6] = { 1, 10, 100, 1000, 10000, 100000 }; static void getCurrTime(struct syslogTime *t, time_t *ttSeconds) { struct timeval tp; - struct tm *tm; - struct tm tmBuf; - long lBias; # if defined(__hpux) struct timezone tz; # endif @@ -93,37 +131,7 @@ static void getCurrTime(struct syslogTime *t, time_t *ttSeconds) if(ttSeconds != NULL) *ttSeconds = tp.tv_sec; - tm = localtime_r((time_t*) &(tp.tv_sec), &tmBuf); - - t->year = tm->tm_year + 1900; - t->month = tm->tm_mon + 1; - t->day = tm->tm_mday; - t->hour = tm->tm_hour; - t->minute = tm->tm_min; - t->second = tm->tm_sec; - t->secfrac = tp.tv_usec; - t->secfracPrecision = 6; - -# if __sun - /* Solaris uses a different method of exporting the time zone. - * It is UTC - localtime, which is the opposite sign of mins east of GMT. - */ - lBias = -(daylight ? altzone : timezone); -# elif defined(__hpux) - lBias = tz.tz_dsttime ? - tz.tz_minuteswest : 0; -# else - lBias = tm->tm_gmtoff; -# endif - if(lBias < 0) - { - t->OffsetMode = '-'; - lBias *= -1; - } - else - t->OffsetMode = '+'; - t->OffsetHour = lBias / 3600; - t->OffsetMinute = (lBias % 3600) / 60; - t->timeType = TIME_TYPE_RFC5424; /* we have a high precision timestamp */ + timeval2syslogTime(&tp, t); } @@ -861,6 +869,7 @@ CODESTARTobjQueryInterface(datetime) */ pIf->getCurrTime = getCurrTime; pIf->GetTime = getTime; + pIf->timeval2syslogTime = timeval2syslogTime; pIf->ParseTIMESTAMP3339 = ParseTIMESTAMP3339; pIf->ParseTIMESTAMP3164 = ParseTIMESTAMP3164; pIf->formatTimestampToMySQL = formatTimestampToMySQL; diff --git a/runtime/datetime.h b/runtime/datetime.h index 70bbf416..2175d6a1 100644 --- a/runtime/datetime.h +++ b/runtime/datetime.h @@ -44,8 +44,10 @@ BEGINinterface(datetime) /* name must also be changed in ENDinterface macro! */ int (*formatTimestampSecFrac)(struct syslogTime *ts, char* pBuf); /* v3, 2009-11-12 */ time_t (*GetTime)(time_t *ttSeconds); + /* v6, 2011-06-20 */ + void (*timeval2syslogTime)(struct timeval *tp, struct syslogTime *t); ENDinterface(datetime) -#define datetimeCURR_IF_VERSION 5 /* increment whenever you change the interface structure! */ +#define datetimeCURR_IF_VERSION 6 /* increment whenever you change the interface structure! */ /* interface changes: * 1 - initial version * 2 - not compatible to 1 - bugfix required ParseTIMESTAMP3164 to accept char ** as @@ -54,6 +56,7 @@ ENDinterface(datetime) * 3 - taken by v5 branch! * 4 - formatTimestamp3164 takes a third int parameter * 5 - merge of versions 3 + 4 (2010-03-09) + * 6 - see above */ /* prototypes */ -- cgit From 47729f3b9362f7956c936088ac4bb703633cb33b Mon Sep 17 00:00:00 2001 From: Rainer Gerhards Date: Fri, 24 Jun 2011 17:07:11 +0200 Subject: added support for obtaining timestamp for kernel message from message If the kernel time-stamps messages, time is now take from that timestamp instead of the system time when the message was read. This provides much better accuracy. Thanks to Lennart Poettering for suggesting this feature and his help during implementation. --- ChangeLog | 5 ++ plugins/imklog/bsd.c | 6 +-- plugins/imklog/imklog.c | 30 ++++++++---- plugins/imklog/imklog.h | 4 +- plugins/imklog/linux.c | 116 ++++++++++++++++++++++++++++++++++++++++------- plugins/imklog/solaris.c | 68 --------------------------- 6 files changed, 130 insertions(+), 99 deletions(-) diff --git a/ChangeLog b/ChangeLog index 4c315819..3459f7d1 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,10 @@ --------------------------------------------------------------------------- Version 5.9.1 [V5-DEVEL] (rgerhards), 2011-06-?? +- added support for obtaining timestamp for kernel message from message + If the kernel time-stamps messages, time is now take from that + timestamp instead of the system time when the message was read. This + provides much better accuracy. Thanks to Lennart Poettering for + suggesting this feature and his help during implementation. - added support for obtaining timestamp from system for imuxsock This permits to read the time a message was submitted to the system log socket. Most importantly, this is provided in microsecond resolution. diff --git a/plugins/imklog/bsd.c b/plugins/imklog/bsd.c index 0a4c7cd4..930bbd11 100644 --- a/plugins/imklog/bsd.c +++ b/plugins/imklog/bsd.c @@ -155,18 +155,18 @@ readklog(void) for (p = (char*)pRcv; (q = strchr(p, '\n')) != NULL; p = q + 1) { *q = '\0'; - Syslog(LOG_INFO, (uchar*) p); + Syslog(LOG_INFO, (uchar*) p, NULL); } len = strlen(p); if (len >= iMaxLine - 1) { - Syslog(LOG_INFO, (uchar*)p); + Syslog(LOG_INFO, (uchar*)p, NULL); len = 0; } if (len > 0) memmove(pRcv, p, len + 1); } if (len > 0) - Syslog(LOG_INFO, pRcv); + Syslog(LOG_INFO, pRcv, NULL); if(pRcv != NULL && (size_t) iMaxLine >= sizeof(bufRcv) - 1) free(pRcv); diff --git a/plugins/imklog/imklog.c b/plugins/imklog/imklog.c index c09fa4d8..cb28e68e 100644 --- a/plugins/imklog/imklog.c +++ b/plugins/imklog/imklog.c @@ -18,7 +18,10 @@ * Please note that this file replaces the klogd daemon that was * also present in pre-v3 versions of rsyslog. * - * Copyright (C) 2008, 2009 by Rainer Gerhards and Adiscon GmbH + * To test under Linux: + * echo test1 > /dev/kmsg + * + * Copyright (C) 2008-2011 by Rainer Gerhards and Adiscon GmbH * * This file is part of rsyslog. * @@ -93,15 +96,21 @@ static prop_t *pLocalHostIP = NULL; /* a pseudo-constant propterty for 127.0.0.1 * rgerhards, 2008-04-12 */ static rsRetVal -enqMsg(uchar *msg, uchar* pszTag, int iFacility, int iSeverity) +enqMsg(uchar *msg, uchar* pszTag, int iFacility, int iSeverity, struct timeval *tp) { - DEFiRet; + struct syslogTime st; msg_t *pMsg; + DEFiRet; assert(msg != NULL); assert(pszTag != NULL); - CHKiRet(msgConstruct(&pMsg)); + if(tp == NULL) { + CHKiRet(msgConstruct(&pMsg)); + } else { + datetime.timeval2syslogTime(tp, &st); + CHKiRet(msgConstructWithTime(&pMsg, &st, tp->tv_sec)); + } MsgSetFlowControlType(pMsg, eFLOWCTL_LIGHT_DELAY); MsgSetInputName(pMsg, pInputName); MsgSetRawMsgWOSize(pMsg, (char*)msg); @@ -174,22 +183,23 @@ rsRetVal imklogLogIntMsg(int priority, char *fmt, ...) va_end(ap); iRet = enqMsg((uchar*)pLogMsg, (uchar*) ((iFacilIntMsg == LOG_KERN) ? "kernel:" : "imklog:"), - iFacilIntMsg, LOG_PRI(priority)); + iFacilIntMsg, LOG_PRI(priority), NULL); RETiRet; } -/* log a kernel message +/* log a kernel message. If tp is non-NULL, it contains the message creation + * time to use. * rgerhards, 2008-04-14 */ -rsRetVal Syslog(int priority, uchar *pMsg) +rsRetVal Syslog(int priority, uchar *pMsg, struct timeval *tp) { - DEFiRet; int pri = -1; rsRetVal localRet; + DEFiRet; - /* first check if we have two PRIs. This can happen in case of systemd, + /* then check if we have two PRIs. This can happen in case of systemd, * in which case the second PRI is the rigth one. * TODO: added kernel timestamp support to this PoC. -- rgerhards, 2011-03-18 */ @@ -214,7 +224,7 @@ rsRetVal Syslog(int priority, uchar *pMsg) if(bPermitNonKernel == 0 && LOG_FAC(priority) != LOG_KERN) FINALIZE; /* silently ignore */ - iRet = enqMsg((uchar*)pMsg, (uchar*) "kernel:", LOG_FAC(priority), LOG_PRI(priority)); + iRet = enqMsg((uchar*)pMsg, (uchar*) "kernel:", LOG_FAC(priority), LOG_PRI(priority), tp); finalize_it: RETiRet; diff --git a/plugins/imklog/imklog.h b/plugins/imklog/imklog.h index c183026d..39bdeb5c 100644 --- a/plugins/imklog/imklog.h +++ b/plugins/imklog/imklog.h @@ -5,7 +5,7 @@ * Major change: 2008-04-09: switched to a driver interface for * several platforms * - * Copyright 2007-2008 Rainer Gerhards and Adiscon GmbH. + * Copyright 2007-2011 Rainer Gerhards and Adiscon GmbH. * * This file is part of rsyslog. * @@ -56,7 +56,7 @@ extern uchar *pszPath; /* the functions below may be called by the drivers */ rsRetVal imklogLogIntMsg(int priority, char *fmt, ...) __attribute__((format(printf,2, 3))); -rsRetVal Syslog(int priority, uchar *msg); +rsRetVal Syslog(int priority, uchar *msg, struct timeval *tp); /* prototypes */ extern int klog_getMaxLine(void); /* work-around for klog drivers to get configured max line size */ diff --git a/plugins/imklog/linux.c b/plugins/imklog/linux.c index 727708a5..8d9c8ad7 100644 --- a/plugins/imklog/linux.c +++ b/plugins/imklog/linux.c @@ -28,6 +28,8 @@ #include "rsyslog.h" #include #include +#include +#include #include #include #include @@ -181,6 +183,96 @@ static int copyin( uchar *line, int space, return(i); } + +/* submit a message to imklog Syslog() API. In this function, we check if + * a kernel timestamp is present and, if so, extract and strip it. + * Note: this is an extra processing step. We should revisit the whole + * idea in v6 and remove all that old stuff that we do not longer need + * (like symbol resolution). <-- TODO + * Special thanks to Lennart Poettering for suggesting on how to convert + * the kernel timestamp to a realtime timestamp. This method depends on + * the fact the the kernel timestamp is written using the monotonic clock. + * Shall that change (very unlikely), this code must be changed as well. Note + * that due to the way we generate the delta, we are unable to write the + * absolutely correc timestamp (system call overhead of the clock calls + * prevents us from doing so). However, the difference is very minor. + * rgerhards, 201106-24 + */ +static void +submitSyslog(int pri, uchar *buf) +{ + long secs; + long nsecs; + long secOffs; + long nsecOffs; + unsigned i; + unsigned bufsize; + struct timespec monotonic, realtime; + struct timeval tv; + struct timeval *tp = NULL; + + if(buf[3] != '[') + goto done; + DBGPRINTF("imklog: kernel timestamp detected, extracting it\n"); + + /* we now try to parse the timestamp. iff it parses, we assume + * it is a timestamp. Otherwise we know for sure it is no ts ;) + */ + i = 4; /* first digit after '[' */ + secs = 0; + while(buf[i] && isdigit(buf[i])) { + secs = secs * 10 + buf[i] - '0'; + ++i; + } + if(buf[i] != '.') { + DBGPRINTF("no dot --> no kernel timestamp\n"); + goto done; /* no TS! */ + } + + ++i; /* skip dot */ + nsecs = 0; + while(buf[i] && isdigit(buf[i])) { + nsecs = nsecs * 10 + buf[i] - '0'; + ++i; + } + if(buf[i] != ']') { + DBGPRINTF("no trailing ']' --> no kernel timestamp\n"); + goto done; /* no TS! */ + } + ++i; /* skip ']' */ + + /* we have a timestamp */ + DBGPRINTF("kernel timestamp is %ld %ld\n", secs, nsecs); + bufsize= strlen((char*)buf); + memcpy(buf+3, buf+i, bufsize - i + 1); + + clock_gettime(CLOCK_MONOTONIC, &monotonic); + clock_gettime(CLOCK_REALTIME, &realtime); + secOffs = realtime.tv_sec - monotonic.tv_sec; + nsecOffs = realtime.tv_nsec - monotonic.tv_nsec; + if(nsecOffs < 0) { + secOffs--; + nsecOffs += 1000000000l; + } + monotonic.tv_sec, monotonic.tv_nsec, + realtime.tv_sec, realtime.tv_nsec, + secOffs, nsecOffs); + + nsecs +=nsecOffs; + if(nsecs > 999999999l) { + secs++; + nsecs -= 1000000000l; + } + secs += secOffs; + tv.tv_sec = secs; + tv.tv_usec = nsecs / 1000; + tp = &tv; + +done: + Syslog(pri, buf, tp); +} + + /* * Messages are separated by "\n". Messages longer than * LOG_LINE_LENGTH are broken up. @@ -235,7 +327,7 @@ static void LogLine(char *ptr, int len) //dbgprintf("Line buffer full:\n"); //dbgprintf("\tLine: %s\n", line); - Syslog(LOG_INFO, line_buff); + submitSyslog(LOG_INFO, line_buff); line = line_buff; space = sizeof(line_buff)-1; parse_state = PARSING_TEXT; @@ -254,28 +346,24 @@ static void LogLine(char *ptr, int len) space -= delta; len -= delta; - if( space == 0 || len == 0 ) - { + if( space == 0 || len == 0 ) { break; /* full line_buff or end of input buffer */ } - if( *ptr == '\0' ) /* zero byte */ - { + if( *ptr == '\0' ) /* zero byte */ { ptr++; /* skip zero byte */ space -= 1; len -= 1; - break; } - if( *ptr == '\n' ) /* newline */ - { + if( *ptr == '\n' ) /* newline */ { ptr++; /* skip newline */ space -= 1; len -= 1; *line = 0; /* force null terminator */ - Syslog(LOG_INFO, line_buff); + submitSyslog(LOG_INFO, line_buff); line = line_buff; space = sizeof(line_buff)-1; if (symbols_twice) { @@ -285,9 +373,7 @@ static void LogLine(char *ptr, int len) skip_symbol_lookup = 1; ptr = save_ptr; len = save_len; - } - else - { + } else { skip_symbol_lookup = 0; save_ptr = ptr; save_len = len; @@ -295,8 +381,7 @@ static void LogLine(char *ptr, int len) } break; } - if( *ptr == '[' ) /* possible kernel symbol */ - { + if( *ptr == '[' ) /* possible kernel symbol */ { *line++ = *ptr++; space -= 1; len -= 1; @@ -310,8 +395,7 @@ static void LogLine(char *ptr, int len) break; case PARSING_SYMSTART: - if( *ptr != '<' ) - { + if( *ptr != '<' ) { parse_state = PARSING_TEXT; /* not a symbol */ break; } diff --git a/plugins/imklog/solaris.c b/plugins/imklog/solaris.c index 8a6d5af1..0a169cdd 100644 --- a/plugins/imklog/solaris.c +++ b/plugins/imklog/solaris.c @@ -80,74 +80,6 @@ klogWillRun(void) } -#if 0 -/* Read /dev/klog while data are available, split into lines. - * Contrary to standard BSD syslogd, we do a blocking read. We can - * afford this as imklog is running on its own threads. So if we have - * a single file, it really doesn't matter if we wait inside a 1-file - * select or the read() directly. - */ -static void -readklog(void) -{ - char *p, *q; - int len, i; - int iMaxLine; - uchar bufRcv[4096+1]; - uchar *pRcv = NULL; /* receive buffer */ - - iMaxLine = klog_getMaxLine(); - - /* we optimize performance: if iMaxLine is below 4K (which it is in almost all - * cases, we use a fixed buffer on the stack. Only if it is higher, heap memory - * is used. We could use alloca() to achive a similar aspect, but there are so - * many issues with alloca() that I do not want to take that route. - * rgerhards, 2008-09-02 - */ - if((size_t) iMaxLine < sizeof(bufRcv) - 1) { - pRcv = bufRcv; - } else { - if((pRcv = (uchar*) malloc(sizeof(uchar) * (iMaxLine + 1))) == NULL) - iMaxLine = sizeof(bufRcv) - 1; /* better this than noting */ - } - - len = 0; - for (;;) { - dbgprintf("----------imklog(BSD) waiting for kernel log line\n"); - i = read(fklog, pRcv + len, iMaxLine - len); - if (i > 0) { - pRcv[i + len] = '\0'; - } else { - if (i < 0 && errno != EINTR && errno != EAGAIN) { - imklogLogIntMsg(LOG_ERR, - "imklog error %d reading kernel log - shutting down imklog", - errno); - fklog = -1; - } - break; - } - - for(p = pRcv; (q = strchr(p, '\n')) != NULL; p = q + 1) { - *q = '\0'; - Syslog(LOG_INFO, (uchar*) p); - } - len = strlen(p); - if (len >= iMaxLine - 1) { - Syslog(LOG_INFO, (uchar*)p); - len = 0; - } - if (len > 0) - memmove(pRcv, p, len + 1); - } - if (len > 0) - Syslog(LOG_INFO, pRcv); - - if(pRcv != NULL && (size_t) iMaxLine >= sizeof(bufRcv) - 1) - free(pRcv); -} -#endif - - /* to be called in the module's AfterRun entry point * rgerhards, 2008-04-09 */ -- cgit