diff options
author | Michael Biebl <biebl@debian.org> | 2010-04-07 12:11:52 +0200 |
---|---|---|
committer | Michael Biebl <biebl@debian.org> | 2010-04-07 12:11:52 +0200 |
commit | 0c3924200ff23e6444058f01b2b7446cde6e1581 (patch) | |
tree | 08967d6f21a0f578d03a92a802343a1313450534 | |
parent | 4af6f89dda61bb5acd862b805302542d9c0da005 (diff) | |
download | rsyslog-0c3924200ff23e6444058f01b2b7446cde6e1581.tar.gz |
Imported Upstream version 4.6.2upstream/4.6.2
78 files changed, 1570 insertions, 193 deletions
@@ -1,4 +1,80 @@ --------------------------------------------------------------------------- +Version 4.6.2 [v4-stable] (rgerhards), 2010-03-26 +- new feature: "." action type added to support writing files to relative + pathes (this is primarily meant as a debug aid) +- new feature: $OMFileAsyncWriting directive added + it permits to specifiy if asynchronous writing should be done or not +- bugfix(temporary): message-induced off-by-one error (potential segfault) + Some types of malformed messages could trigger an off-by-one error + (for example, \0 or \n as the last character, and generally control + character escaption is questionable). This is due to not strictly + following a the \0 or string counted string paradigm (during the last + optimization on the cstring class). As a temporary fix, we have + introduced a proper recalculation of the size. However, a final + patch is expected in the future. See bug tracker for further details + and when the final patch will be available: + http://bugzilla.adiscon.com/show_bug.cgi?id=184 + Note that the current patch is considered sufficient to solve the + situation, but it requires a bit more runtime than desirable. +- bugfix: potential segfault in dynafile cache + This bug was triggered by an open failure. The the cache was full and + a new entry needed to be placed inside it, a victim for eviction was + selected. That victim was freed, then the open of the new file tried. If + the open failed, the victim entry was still freed, and the function + exited. However, on next invocation and cache search, the victim entry + was used as if it were populated, most probably resulting in a segfault. +- bugfix: race condition during directory creation + If multiple files try to create a directory at (almost) the same time, + some of them may fail. This is a data race and also exists with other + processes that may create the same directory. We do now check for this + condition and gracefully handle it. +- bugfix: potential re-use of free()ed file stream object in omfile + when dynaCache is enabled, the cache is full, a new entry needs to + be allocated, thus the LRU discarded, then a new entry is opend and that + fails. In that case, it looks like the discarded stream may be reused + improperly (based on code analysis, test case and confirmation pending) +- added new property replacer option "date-rfc3164-buggyday" primarily + to ease migration from syslog-ng. See property replacer doc for + details. [backport from 5.5.3 because urgently needed by some] +- improved testbench +- bugfix: invalid buffer write in (file) stream class + currently being accessed buffer could be overwritten with new data. + While this probably did not cause access violations, it could case loss + and/or duplication of some data (definitely a race with no deterministic + outcome) +- bugfix: potential hang condition during filestream close + predicate was not properly checked when waiting for the background file + writer +- bugfix: improper synchronization when "$OMFileFlushOnTXEnd on" was used + Internal data structures were not properly protected due to missing + mutex calls. +- bugfix: potential data loss during file stream shutdown +- bugfix: potential problems during file stream shutdown + The shutdown/close sequence was not clean, what potentially (but + unlikely) could lead to some issues. We have not been able to describe + any fatal cases, but there was some bug potential. Sequence has now + been straighted out. +- bugfix: potential problem (loop, abort) when file write error occured + When a write error occured in stream.c, variable iWritten had the error + code but this was handled as if it were the actual number of bytes + written. That was used in pointer arithmetic later on, and thus could + lead to all sorts of problems. However, this could only happen if the + error was EINTR or the file in question was a tty. All other cases were + handled properly. Now, iWritten is reset to zero in such cases, resulting + in proper retries. +- bugfix: $omfileFlushOnTXEnd was turned on when set to off and vice + versa due to an invalid check +- bugfix: recent patch to fix small memory leak could cause invalid free. + This could only happen during config file parsing. +- bugfix(minor): handling of extremely large strings in dbgprintf() fixed + Previously, it could lead to garbagge output and, in extreme cases, also + to segfaults. Note: this was a problem only when debug output was + actually enabled, so it caused no problem in production use. +- bugfix(minor): BSD_SO_COMPAT query function had some global vars not + properly initialized. However, in practice the loader initializes them + with zero, the desired value, so there were no actual issue in almost + all cases. +--------------------------------------------------------------------------- Version 4.6.1 [v4-stable] (rgerhards), 2010-03-04 - re-enabled old pipe output (using new module ompipe, built-in) after some problems with pipes (and especially in regard to xconsole) were @@ -4,7 +4,7 @@ * * File begun on 2007-08-06 by RGerhards (extracted from syslogd.c) * - * Copyright 2007-2009 Rainer Gerhards and Adiscon GmbH. + * Copyright 2007-2010 Rainer Gerhards and Adiscon GmbH. * * This file is part of rsyslog. * @@ -1,6 +1,6 @@ #! /bin/sh # Guess values for system-dependent variables and create Makefiles. -# Generated by GNU Autoconf 2.63 for rsyslog 4.6.1. +# Generated by GNU Autoconf 2.63 for rsyslog 4.6.2. # # Report bugs to <rsyslog@lists.adiscon.com>. # @@ -745,8 +745,8 @@ SHELL=${CONFIG_SHELL-/bin/sh} # Identity of this package. PACKAGE_NAME='rsyslog' PACKAGE_TARNAME='rsyslog' -PACKAGE_VERSION='4.6.1' -PACKAGE_STRING='rsyslog 4.6.1' +PACKAGE_VERSION='4.6.2' +PACKAGE_STRING='rsyslog 4.6.2' PACKAGE_BUGREPORT='rsyslog@lists.adiscon.com' ac_unique_file="ChangeLog" @@ -1603,7 +1603,7 @@ if test "$ac_init_help" = "long"; then # Omit some internal or obsolete options to make the list less imposing. # This message is too long to be a string in the A/UX 3.1 sh. cat <<_ACEOF -\`configure' configures rsyslog 4.6.1 to adapt to many kinds of systems. +\`configure' configures rsyslog 4.6.2 to adapt to many kinds of systems. Usage: $0 [OPTION]... [VAR=VALUE]... @@ -1673,7 +1673,7 @@ fi if test -n "$ac_init_help"; then case $ac_init_help in - short | recursive ) echo "Configuration of rsyslog 4.6.1:";; + short | recursive ) echo "Configuration of rsyslog 4.6.2:";; esac cat <<\_ACEOF @@ -1817,7 +1817,7 @@ fi test -n "$ac_init_help" && exit $ac_status if $ac_init_version; then cat <<\_ACEOF -rsyslog configure 4.6.1 +rsyslog configure 4.6.2 generated by GNU Autoconf 2.63 Copyright (C) 1992, 1993, 1994, 1995, 1996, 1998, 1999, 2000, 2001, @@ -1831,7 +1831,7 @@ cat >config.log <<_ACEOF This file contains any messages produced by compilers while running configure, to aid debugging if configure makes a mistake. -It was created by rsyslog $as_me 4.6.1, which was +It was created by rsyslog $as_me 4.6.2, which was generated by GNU Autoconf 2.63. Invocation command line was $ $0 $@ @@ -2680,7 +2680,7 @@ fi # Define the identity of the package. PACKAGE='rsyslog' - VERSION='4.6.1' + VERSION='4.6.2' cat >>confdefs.h <<_ACEOF @@ -20987,7 +20987,7 @@ exec 6>&1 # report actual input values of CONFIG_FILES etc. instead of their # values after options handling. ac_log=" -This file was extended by rsyslog $as_me 4.6.1, which was +This file was extended by rsyslog $as_me 4.6.2, which was generated by GNU Autoconf 2.63. Invocation command line was CONFIG_FILES = $CONFIG_FILES @@ -21050,7 +21050,7 @@ Report bugs to <bug-autoconf@gnu.org>." _ACEOF cat >>$CONFIG_STATUS <<_ACEOF || ac_write_fail=1 ac_cs_version="\\ -rsyslog config.status 4.6.1 +rsyslog config.status 4.6.2 configured by $0, generated by GNU Autoconf 2.63, with options \\"`$as_echo "$ac_configure_args" | sed 's/^ //; s/[\\""\`\$]/\\\\&/g'`\\" diff --git a/configure.ac b/configure.ac index b059fe7..b01396d 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],[4.6.1],[rsyslog@lists.adiscon.com]) +AC_INIT([rsyslog],[4.6.2],[rsyslog@lists.adiscon.com]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([ChangeLog]) AC_CONFIG_MACRO_DIR([m4]) diff --git a/doc/manual.html b/doc/manual.html index 0efe507..455a711 100644 --- a/doc/manual.html +++ b/doc/manual.html @@ -19,7 +19,7 @@ rsyslog support</a> available directly from the source!</p> <p><b>Please visit the <a href="http://www.rsyslog.com/sponsors">rsyslog sponsor's page</a> to honor the project sponsors or become one yourself!</b> We are very grateful for any help towards the project goals.</p> -<p><b>This documentation is for version 4.6.1 (v4-stable branch) of rsyslog.</b> +<p><b>This documentation is for version 4.6.2 (v4-stable branch) of rsyslog.</b> Visit the <i><a href="http://www.rsyslog.com/doc-status.html">rsyslog status page</a></i></b> to obtain current version information and project status. </p><p><b>If you like rsyslog, you might diff --git a/doc/property_replacer.html b/doc/property_replacer.html index 7b604ea..4d242a3 100644 --- a/doc/property_replacer.html +++ b/doc/property_replacer.html @@ -335,6 +335,19 @@ Especially useful for PIX.</td> <td>format as RFC 3164 date</td> </tr> <tr> +<tr> +<td valign="top"><b>date-rfc3164-buggyday</b></td> +<td>similar to date-rfc3164, but emulates a common coding error: RFC 3164 demands +that a space is written for single-digit days. With this option, a zero is +written instead. This format seems to be used by syslog-ng and the +date-rfc3164-buggyday option can be used in migration scenarios where otherwise +lots of scripts would need to be adjusted. It is recommended <i>not</i> to use this +option when forwarding to remote hosts - they may treat the date as invalid +(especially when parsing strictly according to RFC 3164).</td> +<br><i>This feature was introduced in rsyslog 4.6.2 and v4 versions above and +5.5.3 and all versions above.</i> +</tr> +<tr> <td><b>date-rfc3339</b></td> <td>format as RFC 3339 date</td> </tr> diff --git a/doc/rsyslog_conf_actions.html b/doc/rsyslog_conf_actions.html index 8c4b9cf..6020dd8 100644 --- a/doc/rsyslog_conf_actions.html +++ b/doc/rsyslog_conf_actions.html @@ -37,8 +37,15 @@ compared to the otherwise-equal config directives below:</p> *.=crit /var/log/critmsgs</b></code></p> <p> </p> <h3>Regular File</h3> -<p>Typically messages are logged to real files. The file has to -be specified with full pathname, beginning with a slash "/''.<br> +<p>Typically messages are logged to real files. The file usually is +specified by full pathname, beginning with a slash "/". +Starting with version 4.6.2 and 5.4.1 (previous v5 version do NOT support this) +relative file names can also be specified. To do so, these must begin with a +dot. For example, use "./file-in-current-dir.log" to specify a file in the +current directory. Please note that rsyslogd usually changes its working +directory to the root, so relative file names must be tested with care (they +were introduced primarily as a debugging vehicle, but may have useful other applications +as well).<br> <br> <br> You may prefix each entry with the minus "-'' sign to omit syncing the diff --git a/doc/rsyslog_conf_global.html b/doc/rsyslog_conf_global.html index 50d83a5..d5a2754 100644 --- a/doc/rsyslog_conf_global.html +++ b/doc/rsyslog_conf_global.html @@ -207,13 +207,21 @@ supported in order to be compliant to the upcoming new syslog RFC series. <li><a href="rsconf1_maxopenfiles.html">$MaxOpenFiles</a></li> <li><a href="rsconf1_moddir.html">$ModDir</a></li> <li><a href="rsconf1_modload.html">$ModLoad</a></li> +<li><b>$OMFileAsyncWriting</b> [on/<b>off</b>], if turned on, the files will be written +in asynchronous mode via a separate thread. In that case, double buffers will be used so +that one buffer can be filled while the other buffer is being written. Note that in order +to enable $OMFileFlushInterval, $OMFileAsyncWriting must be set to "on". Otherwise, the flush +interval will be ignored. Also note that when $OMFileFlushOnTXEnd is "on" but +$OMFileAsyncWriting is off, output will only be written when the buffer is full. This may take +several hours, or even require a rsyslog shutdown. However, a buffer flush can be forced +in that case by sending rsyslogd a HUP signal. <li><b>$OMFileZipLevel</b> 0..9 [default 0] - if greater 0, turns on gzip compression of the output file. The higher the number, the better the compression, but also the more CPU is required for zipping.</li> <li><b>$OMFileIOBufferSize</b> <size_nbr>, default 4k, size of the buffer used to writing output data. The larger the buffer, the potentially better performance is. The default of 4k is quite conservative, it is useful to go up to 64k, and 128K if you used gzip compression (then, even higher sizes may make sense)</li> -<li><b>$OMFileFlushOnTXEnd</b> <[<b>on</b>/off]>, default on. Omfile has the +<li><b>$OMFileFlushOnTXEnd</b> <[on/<b>off</b>]>, default ff. Omfile has the capability to -writes output using a buffered writer. Disk writes are only done when the buffer is +write output using a buffered writer. Disk writes are only done when the buffer is full. So if an error happens during that write, data is potentially lost. In cases where this is unacceptable, set $OMFileFlushOnTXEnd to on. Then, data is written at the end of each transaction (for pre-v5 this means after <b>each</b> log message) and the usual diff --git a/plugins/imudp/imudp.c b/plugins/imudp/imudp.c index 0970259..f8555f0 100644 --- a/plugins/imudp/imudp.c +++ b/plugins/imudp/imudp.c @@ -241,7 +241,7 @@ processSocket(int fd, struct sockaddr_storage *frominetPrev, int *pbIsPermitted, } } - DBGPRINTF("recv(%d,%d)/%s,acl:%d,msg:%.80s\n", fd, (int) lenRcvBuf, fromHost, *pbIsPermitted, pRcvBuf); + DBGPRINTF("recv(%d,%d)/%s,acl:%d,msg:%s\n", fd, (int) lenRcvBuf, fromHost, *pbIsPermitted, pRcvBuf); if(*pbIsPermitted) { if((iTimeRequery == 0) || (iNbrTimeUsed++ % iTimeRequery) == 0) { diff --git a/plugins/omgssapi/omgssapi.c b/plugins/omgssapi/omgssapi.c index d9f80c1..782ac22 100644 --- a/plugins/omgssapi/omgssapi.c +++ b/plugins/omgssapi/omgssapi.c @@ -377,7 +377,7 @@ CODESTARTtryResume ENDtryResume BEGINdoAction - char *psz; /* temporary buffering */ + char *psz = NULL; /* temporary buffering */ register unsigned l; int iMaxLine; CODESTARTdoAction @@ -454,7 +454,7 @@ CODESTARTdoAction } finalize_it: # ifdef USE_NETZIP - if(psz != (char*) ppString[0]) { + if((psz != NULL) && (psz != (char*) ppString[0])) { /* we need to free temporary buffer, alloced above - Naoya Nakazawa, 2010-01-11 */ free(psz); } diff --git a/runtime/datetime.c b/runtime/datetime.c index 7b0d8d1..eff72f9 100644 --- a/runtime/datetime.c +++ b/runtime/datetime.c @@ -793,8 +793,12 @@ int formatTimestamp3339(struct syslogTime *ts, char* pBuf) * buffer that will receive the resulting string. The function * returns the size of the timestamp written in bytes (without * the string termnator). If 0 is returend, an error occured. + * rgerhards, 2010-03-05: Added support to for buggy 3164 dates, + * where a zero-digit is written instead of a space for the first + * day character if day < 10. syslog-ng seems to do that, and some + * parsing scripts (in migration cases) rely on that. */ -int formatTimestamp3164(struct syslogTime *ts, char* pBuf) +int formatTimestamp3164(struct syslogTime *ts, char* pBuf, int bBuggyDay) { static char* monthNames[12] = { "Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec" }; @@ -807,7 +811,7 @@ int formatTimestamp3164(struct syslogTime *ts, char* pBuf) pBuf[2] = monthNames[(ts->month - 1) % 12][2]; pBuf[3] = ' '; iDay = (ts->day / 10) % 10; /* we need to write a space if the first digit is 0 */ - pBuf[4] = iDay ? iDay + '0' : ' '; + pBuf[4] = (bBuggyDay || iDay > 0) ? iDay + '0' : ' '; pBuf[5] = ts->day % 10 + '0'; pBuf[6] = ' '; pBuf[7] = (ts->hour / 10) % 10 + '0'; diff --git a/runtime/datetime.h b/runtime/datetime.h index 8140eb7..9dcce3c 100644 --- a/runtime/datetime.h +++ b/runtime/datetime.h @@ -39,15 +39,17 @@ BEGINinterface(datetime) /* name must also be changed in ENDinterface macro! */ 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 (*formatTimestamp3164)(struct syslogTime *ts, char* pBuf, int); int (*formatTimestampSecFrac)(struct syslogTime *ts, char* pBuf); ENDinterface(datetime) -#define datetimeCURR_IF_VERSION 2 /* increment whenever you change the interface structure! */ +#define datetimeCURR_IF_VERSION 4 /* increment whenever you change the interface structure! */ /* interface changes: * 1 - initial version * 2 - not compatible to 1 - bugfix required ParseTIMESTAMP3164 to accept char ** as * last parameter. Did not try to remain compatible as this is not something any * third-party module should call. -- rgerhards, 2008.-09-12 + * 3 - taken by v5 branch! + * 4 - formatTimestamp3164 takes a third int parameter */ /* prototypes */ diff --git a/runtime/debug.c b/runtime/debug.c index 20474a9..9b7c295 100644 --- a/runtime/debug.c +++ b/runtime/debug.c @@ -922,7 +922,7 @@ void dbgoprint(obj_t *pObj, char *fmt, ...) { va_list ap; - char pszWriteBuf[1024]; + char pszWriteBuf[32*1024]; size_t lenWriteBuf; if(!(Debug && debugging_on)) @@ -952,7 +952,7 @@ void dbgprintf(char *fmt, ...) { va_list ap; - char pszWriteBuf[1024]; + char pszWriteBuf[20480]; size_t lenWriteBuf; if(!(Debug && debugging_on)) @@ -961,6 +961,15 @@ dbgprintf(char *fmt, ...) va_start(ap, fmt); lenWriteBuf = vsnprintf(pszWriteBuf, sizeof(pszWriteBuf), fmt, ap); va_end(ap); + if(lenWriteBuf >= sizeof(pszWriteBuf)) { + /* prevent buffer overrruns and garbagge display */ + pszWriteBuf[sizeof(pszWriteBuf) - 5] = '.'; + pszWriteBuf[sizeof(pszWriteBuf) - 4] = '.'; + pszWriteBuf[sizeof(pszWriteBuf) - 3] = '.'; + pszWriteBuf[sizeof(pszWriteBuf) - 2] = '\n'; + pszWriteBuf[sizeof(pszWriteBuf) - 1] = '\0'; + lenWriteBuf = sizeof(pszWriteBuf); + } dbgprint(NULL, pszWriteBuf, lenWriteBuf); } diff --git a/runtime/msg.c b/runtime/msg.c index 7020707..2ce7843 100644 --- a/runtime/msg.c +++ b/runtime/msg.c @@ -1213,10 +1213,12 @@ static inline char *getTimeReported(msg_t *pM, enum tplFormatTypes eFmt) switch(eFmt) { case tplFmtDefault: case tplFmtRFC3164Date: + case tplFmtRFC3164BuggyDate: MsgLock(pM); if(pM->pszTIMESTAMP3164 == NULL) { pM->pszTIMESTAMP3164 = pM->pszTimestamp3164; - datetime.formatTimestamp3164(&pM->tTIMESTAMP, pM->pszTIMESTAMP3164); + datetime.formatTimestamp3164(&pM->tTIMESTAMP, pM->pszTIMESTAMP3164, + (eFmt == tplFmtRFC3164BuggyDate)); } MsgUnlock(pM); return(pM->pszTIMESTAMP3164); @@ -1279,7 +1281,7 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return ""; } - datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164); + datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164, 0); } MsgUnlock(pM); return(pM->pszRcvdAt3164); @@ -1306,13 +1308,15 @@ static inline char *getTimeGenerated(msg_t *pM, enum tplFormatTypes eFmt) MsgUnlock(pM); return(pM->pszRcvdAt_PgSQL); case tplFmtRFC3164Date: + case tplFmtRFC3164BuggyDate: MsgLock(pM); if(pM->pszRcvdAt3164 == NULL) { if((pM->pszRcvdAt3164 = malloc(16)) == NULL) { MsgUnlock(pM); return ""; } - datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164); + datetime.formatTimestamp3164(&pM->tRcvdAt, pM->pszRcvdAt3164, + (eFmt == tplFmtRFC3164BuggyDate)); } MsgUnlock(pM); return(pM->pszRcvdAt3164); @@ -2315,6 +2319,12 @@ uchar *MsgGetProp(msg_t *pMsg, struct templateEntry *pTpe, *pPropLen = sizeof("**INVALID PROPERTY NAME**") - 1; return UCHAR_CONSTANT("**INVALID PROPERTY NAME**"); } + /* the following line fixes the symptom, but not the root cause -- at least MSG sometimes + * returns a size of one too less. To prevent all troubles, we recalculate the sizes based + * on what we actually got. TODO: remove once root cause is found. + * rgerhards, 2010-03-23 + */ + bufLen = ustrlen(pRes); /* If we did not receive a template pointer, we are already done... */ diff --git a/runtime/net.c b/runtime/net.c index e91c8a7..fe6eef5 100644 --- a/runtime/net.c +++ b/runtime/net.c @@ -1010,8 +1010,8 @@ static int should_use_so_bsdcompat(void) { #ifndef OS_BSD - static int init_done; - static int so_bsdcompat_is_obsolete; + static int init_done = 0; + static int so_bsdcompat_is_obsolete = 0; if (!init_done) { struct utsname myutsname; diff --git a/runtime/srutils.c b/runtime/srutils.c index c403b31..1452c9b 100644 --- a/runtime/srutils.c +++ b/runtime/srutils.c @@ -166,10 +166,22 @@ uchar *srUtilStrDup(uchar *pOld, size_t len) /* creates a path recursively - * Return 0 on success, -1 otherwise. On failure, errno - * hold the last OS error. - * Param "mode" holds the mode that all non-existing directories - * are to be created with. + * Return 0 on success, -1 otherwise. On failure, errno * hold the last OS error. + * Param "mode" holds the mode that all non-existing directories are to be + * created with. + * Note that we have a potential race inside that code, a race that even exists + * outside of the rsyslog process (if multiple instances run, or other programs + * generate directories): If the directory does not exist, a context switch happens, + * at that moment another process creates it, then our creation on the context + * switch back fails. This actually happened in practice, and depending on the + * configuration it is even likely to happen. We can not solve this situation + * with a mutex, as that works only within out process space. So the solution + * is that we take the optimistic approach, try the creation, and if it fails + * with "already exists" we go back and do one retry of the check/create + * sequence. That should then succeed. If the directory is still not found but + * the creation fails in the similar way, we return an error on that second + * try because otherwise we would potentially run into an endless loop. + * loop. -- rgerhards, 2010-03-25 */ int makeFileParentDirs(uchar *szFile, size_t lenFile, mode_t mode, uid_t uid, gid_t gid, int bFailOnChownFail) @@ -177,6 +189,8 @@ int makeFileParentDirs(uchar *szFile, size_t lenFile, mode_t mode, uchar *p; uchar *pszWork; size_t len; + int err; + int iTry = 0; int bErr = 0; assert(szFile != NULL); @@ -190,8 +204,9 @@ int makeFileParentDirs(uchar *szFile, size_t lenFile, mode_t mode, if(*p == '/') { /* temporarily terminate string, create dir and go on */ *p = '\0'; +again: if(access((char*)pszWork, F_OK)) { - if(mkdir((char*)pszWork, mode) == 0) { + if((err = mkdir((char*)pszWork, mode)) == 0) { if(uid != (uid_t) -1 || gid != (gid_t) -1) { /* we need to set owner/group */ if(chown((char*)pszWork, uid, gid) != 0) @@ -201,8 +216,13 @@ int makeFileParentDirs(uchar *szFile, size_t lenFile, mode_t mode, * to do so. */ } - } else + } else { + if(err == EEXIST && iTry == 0) { + iTry = 1; + goto again; + } bErr = 1; + } if(bErr) { int eSave = errno; free(pszWork); diff --git a/runtime/stream.c b/runtime/stream.c index 36f4400..e8805a4 100644 --- a/runtime/stream.c +++ b/runtime/stream.c @@ -67,7 +67,7 @@ DEFobjStaticHelpers DEFobjCurrIf(zlibw) /* forward definitions */ -static rsRetVal strmFlush(strm_t *pThis); +static rsRetVal strmFlushInternal(strm_t *pThis); static rsRetVal strmWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf); static rsRetVal strmCloseFile(strm_t *pThis); static void *asyncWriterThread(void *pPtr); @@ -163,7 +163,7 @@ doSizeLimitProcessing(strm_t *pThis) ASSERT(pThis->fd != -1); if(pThis->iCurrOffs >= pThis->iSizeLimit) { - /* strmClosefile() destroys the current file name, so we + /* strmCloseFile() destroys the current file name, so we * need to preserve it. */ CHKmalloc(pszCurrFName = ustrdup(pThis->pszCurrFName)); @@ -220,7 +220,7 @@ doPhysOpen(strm_t *pThis) char errStr[1024]; int err = errno; rs_strerror_r(err, errStr, sizeof(errStr)); - dbgoprint((obj_t*) pThis, "open error %d, file '%s': %s\n", errno, pThis->pszCurrFName, errStr); + DBGOPRINT((obj_t*) pThis, "open error %d, file '%s': %s\n", errno, pThis->pszCurrFName, errStr); if(err == ENOENT) ABORT_FINALIZE(RS_RET_FILE_NOT_FOUND); else @@ -278,7 +278,7 @@ static rsRetVal strmOpenFile(strm_t *pThis) pThis->iCurrOffs = offset; } - dbgoprint((obj_t*) pThis, "opened file '%s' for %s as %d\n", pThis->pszCurrFName, + DBGOPRINT((obj_t*) pThis, "opened file '%s' for %s as %d\n", pThis->pszCurrFName, (pThis->tOperationsMode == STREAMMODE_READ) ? "READ" : "WRITE", pThis->fd); finalize_it: @@ -296,8 +296,10 @@ strmWaitAsyncWriterDone(strm_t *pThis) BEGINfunc if(pThis->bAsyncWrite) { /* awake writer thread and make it write out everything */ - pthread_cond_signal(&pThis->notEmpty); - d_pthread_cond_wait(&pThis->isEmpty, &pThis->mut); + while(pThis->iCnt > 0) { + pthread_cond_signal(&pThis->notEmpty); + d_pthread_cond_wait(&pThis->isEmpty, &pThis->mut); + } } ENDfunc } @@ -306,27 +308,33 @@ strmWaitAsyncWriterDone(strm_t *pThis) /* close a strm file * Note that the bDeleteOnClose flag is honored. If it is set, the file will be * deleted after close. This is in support for the qRead thread. + * Note: it is valid to call this function when the physical file is closed. If so, + * strmCloseFile() will still check if there is any unwritten data inside buffers + * (this may be the case) and, if so, will open the file, write the data, and then + * close it again (this is done via strmFlushInternal and friends). */ static rsRetVal strmCloseFile(strm_t *pThis) { DEFiRet; ASSERT(pThis != NULL); - ASSERT(pThis->fd != -1); - dbgoprint((obj_t*) pThis, "file %d closing\n", pThis->fd); + DBGOPRINT((obj_t*) pThis, "file %d(%s) closing\n", pThis->fd, + (pThis->pszFName == NULL) ? "N/A" : (char*)pThis->pszFName); - if(!pThis->bInClose && pThis->tOperationsMode != STREAMMODE_READ) { - pThis->bInClose = 1; + if(pThis->tOperationsMode != STREAMMODE_READ) { + strmFlushInternal(pThis); if(pThis->bAsyncWrite) { - strmFlush(pThis); - } else { strmWaitAsyncWriterDone(pThis); } - pThis->bInClose = 0; } - close(pThis->fd); - pThis->fd = -1; + /* the file may already be closed (or never have opened), so guard + * against this. -- rgerhards, 2010-03-19 + */ + if(pThis->fd != -1) { + close(pThis->fd); + pThis->fd = -1; + } if(pThis->fdDir != -1) { /* close associated directory handle, if it is open */ @@ -441,7 +449,7 @@ strmHandleEOF(strm_t *pThis) case STREAMTYPE_FILE_CIRCULAR: /* we have multiple files and need to switch to the next one */ /* TODO: think about emulating EOF in this case (not yet needed) */ - dbgoprint((obj_t*) pThis, "file %d EOF\n", pThis->fd); + DBGOPRINT((obj_t*) pThis, "file %d EOF\n", pThis->fd); CHKiRet(strmNextFile(pThis)); break; case STREAMTYPE_FILE_MONITOR: @@ -473,7 +481,7 @@ strmReadBuf(strm_t *pThis) */ CHKiRet(strmOpenFile(pThis)); iLenRead = read(pThis->fd, pThis->pIOBuf, pThis->sIOBufSize); - dbgoprint((obj_t*) pThis, "file %d read %ld bytes\n", pThis->fd, iLenRead); + DBGOPRINT((obj_t*) pThis, "file %d read %ld bytes\n", pThis->fd, iLenRead); if(iLenRead == 0) { CHKiRet(strmHandleEOF(pThis)); } else if(iLenRead < 0) @@ -505,7 +513,7 @@ static rsRetVal strmReadChar(strm_t *pThis, uchar *pC) ASSERT(pThis != NULL); ASSERT(pC != NULL); - /* DEV debug only: dbgoprint((obj_t*) pThis, "strmRead index %d, max %d\n", pThis->iBufPtr, pThis->iBufPtrMax); */ + /* DEV debug only: DBGOPRINT((obj_t*) pThis, "strmRead index %d, max %d\n", pThis->iBufPtr, pThis->iBufPtrMax); */ if(pThis->iUngetC != -1) { /* do we have an "unread" char that we need to provide? */ *pC = pThis->iUngetC; ++pThis->iCurrOffs; /* one more octet read */ @@ -617,11 +625,11 @@ static rsRetVal strmConstructFinalize(strm_t *pThis) * to make sure we can write out everything with a SINGLE api call! * We add another 128 bytes to take care of the gzip header and "all eventualities". */ - CHKmalloc(pThis->pZipBuf = (Bytef*) malloc(sizeof(uchar) * pThis->sIOBufSize + 128)); + CHKmalloc(pThis->pZipBuf = (Bytef*) malloc(sizeof(uchar) * (pThis->sIOBufSize + 128))); } } - /* if we are aset to sync, we must obtain a file handle to the directory for fsync() purposes */ + /* if we are set to sync, we must obtain a file handle to the directory for fsync() purposes */ if(pThis->bSync && !pThis->bIsTTY) { pThis->fdDir = open((char*)pThis->pszDir, O_RDONLY | O_CLOEXEC | O_NOCTTY); if(pThis->fdDir == -1) { @@ -633,6 +641,9 @@ static rsRetVal strmConstructFinalize(strm_t *pThis) } } + DBGPRINTF("file stream %s params: flush interval %d, async write %d\n", + (pThis->pszFName == NULL) ? "N/A" : (char*)pThis->pszFName, + pThis->iFlushInterval, pThis->bAsyncWrite); /* if we have a flush interval, we need to do async writes in any case */ if(pThis->iFlushInterval != 0) { pThis->bAsyncWrite = 1; @@ -685,8 +696,10 @@ CODESTARTobjDestruct(strm) /* Note: mutex will be unlocked in stopWriter! */ d_pthread_mutex_lock(&pThis->mut); - if(pThis->tOperationsMode != STREAMMODE_READ) - strmFlush(pThis); + /* strmClose() will handle read-only files as well as need to open + * files that have unwritten buffers. -- rgerhards, 2010-03-09 + */ + strmCloseFile(pThis); if(pThis->bAsyncWrite) { stopWriter(pThis); @@ -705,14 +718,11 @@ CODESTARTobjDestruct(strm) * IMPORTANT: we MUST free this only AFTER the ansyncWriter has been stopped, else * we get random errors... */ - if(pThis->fd != -1) - strmCloseFile(pThis); - free(pThis->pszDir); free(pThis->pZipBuf); free(pThis->pszCurrFName); free(pThis->pszFName); - + pThis->bStopWriter = 2; /* RG: use as flag for destruction */ ENDobjDestruct(strm) @@ -732,7 +742,7 @@ static rsRetVal strmCheckNextOutputFile(strm_t *pThis) strmWaitAsyncWriterDone(pThis); if(pThis->iCurrOffs >= pThis->iMaxFileSize) { - dbgoprint((obj_t*) pThis, "max file size %ld reached for %d, now %ld - starting new file\n", + DBGOPRINT((obj_t*) pThis, "max file size %ld reached for %d, now %ld - starting new file\n", (long) pThis->iMaxFileSize, pThis->fd, (long) pThis->iCurrOffs); CHKiRet(strmNextFile(pThis)); } @@ -790,6 +800,7 @@ doWriteCall(strm_t *pThis, uchar *pBuf, size_t *pLenBuf) if(iWritten < 0) { char errStr[1024]; int err = errno; + iWritten = 0; /* we have written NO bytes! */ rs_strerror_r(err, errStr, sizeof(errStr)); DBGPRINTF("log file (%d) write error %d: %s\n", pThis->fd, err, errStr); if(err == EINTR) { @@ -811,7 +822,7 @@ doWriteCall(strm_t *pThis, uchar *pBuf, size_t *pLenBuf) pWriteBuf += iWritten; } while(lenBuf > 0); /* Warning: do..while()! */ - dbgoprint((obj_t*) pThis, "file %d write wrote %d bytes\n", pThis->fd, (int) iWritten); + DBGOPRINT((obj_t*) pThis, "file %d write wrote %d bytes\n", pThis->fd, (int) iWritten); finalize_it: *pLenBuf = iTotalWritten; @@ -855,7 +866,8 @@ doAsyncWriteInternal(strm_t *pThis, size_t lenBuf) DEFiRet; ISOBJ_TYPE_assert(pThis, strm); - while(pThis->iCnt >= STREAM_ASYNC_NUMBUFS) + /* the -1 below is important, because we need one buffer for the main thread! */ + while(pThis->iCnt >= STREAM_ASYNC_NUMBUFS - 1) d_pthread_cond_wait(&pThis->notFull, &pThis->mut); pThis->asyncBuf[pThis->iEnq % STREAM_ASYNC_NUMBUFS].lenBuf = lenBuf; @@ -880,13 +892,22 @@ strmSchedWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf) ASSERT(pThis != NULL); + /* we need to reset the buffer pointer BEFORE calling the actual write + * function. Otherwise, in circular mode, the write function will + * potentially close the file, then close will flush and as the + * buffer pointer is nonzero, will re-call into this code here. In + * the end result, we than have a problem (and things are screwed + * up). So we reset the buffer pointer first, and all this can + * not happen. It is safe to do so, because that pointer is NOT + * used inside the write functions. -- rgerhads, 2010-03-10 + */ + pThis->iBufPtr = 0; /* we are at the begin of a new buffer */ if(pThis->bAsyncWrite) { CHKiRet(doAsyncWriteInternal(pThis, lenBuf)); } else { CHKiRet(doWriteInternal(pThis, pBuf, lenBuf)); } - pThis->iBufPtr = 0; /* we are at the begin of a new buffer */ finalize_it: RETiRet; @@ -911,10 +932,11 @@ asyncWriterThread(void *pPtr) if(prctl(PR_SET_NAME, "rs:asyn strmwr", 0, 0, 0) != 0) { DBGPRINTF("prctl failed, not setting thread name for '%s'\n", "stream writer"); } -#endif +# endif while(1) { /* loop broken inside */ d_pthread_mutex_lock(&pThis->mut); +dbgprintf("XXX: asyncWriterThread iterating %s\n", pThis->pszFName); while(pThis->iCnt == 0) { if(pThis->bStopWriter) { pthread_cond_broadcast(&pThis->isEmpty); @@ -923,13 +945,14 @@ asyncWriterThread(void *pPtr) } if(bTimedOut && pThis->iBufPtr > 0) { /* if we timed out, we need to flush pending data */ - strmFlush(pThis); + strmFlushInternal(pThis); bTimedOut = 0; continue; /* now we should have data */ } bTimedOut = 0; - timeoutComp(&t, pThis->iFlushInterval * 2000); /* *1000 millisconds */ + timeoutComp(&t, pThis->iFlushInterval * 2000); /* *1000 millisconds */ // TODO: check the 2000?!? if(pThis->bDoTimedWait) { +dbgprintf("asyncWriter thread going to timeout sleep\n"); if(pthread_cond_timedwait(&pThis->notEmpty, &pThis->mut, &t) != 0) { int err = errno; if(err == ETIMEDOUT) { @@ -943,13 +966,16 @@ asyncWriterThread(void *pPtr) } } } else { +dbgprintf("asyncWriter thread going to eternal sleep\n"); d_pthread_cond_wait(&pThis->notEmpty, &pThis->mut); } +dbgprintf("asyncWriter woke up\n"); } bTimedOut = 0; /* we may have timed out, but there *is* work to do... */ iDeq = pThis->iDeq++ % STREAM_ASYNC_NUMBUFS; +dbgprintf("asyncWriter writes data\n"); doWriteInternal(pThis, pThis->asyncBuf[iDeq].pBuf, pThis->asyncBuf[iDeq].lenBuf); // TODO: error check????? 2009-07-06 @@ -1058,10 +1084,6 @@ finalize_it: * add a config switch so that the user can decide the risk he is ready * to take, but so far this is not yet implemented (not even requested ;)). * rgerhards, 2009-06-04 - * For the time being, we take a very conservative approach and do not run this - * method multithreaded. This is done in an effort to solve a segfault condition - * that seems to be related to the zip code. -- rgerhards, 2009-09-22 - * TODO: make multithreaded again! */ static rsRetVal doZipWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf) @@ -1120,12 +1142,14 @@ finalize_it: * rgerhards, 2008-01-10 */ static rsRetVal -strmFlush(strm_t *pThis) +strmFlushInternal(strm_t *pThis) { DEFiRet; ASSERT(pThis != NULL); - dbgoprint((obj_t*) pThis, "file %d flush, buflen %ld\n", pThis->fd, (long) pThis->iBufPtr); + DBGOPRINT((obj_t*) pThis, "file %d(%s) flush, buflen %ld%s\n", pThis->fd, + (pThis->pszFName == NULL) ? "N/A" : (char*)pThis->pszFName, + (long) pThis->iBufPtr, (pThis->iBufPtr == 0) ? " (no need to flush)" : ""); if(pThis->tOperationsMode != STREAMMODE_READ && pThis->iBufPtr > 0) { iRet = strmSchedWrite(pThis, pThis->pIOBuf, pThis->iBufPtr); @@ -1135,6 +1159,31 @@ strmFlush(strm_t *pThis) } +/* flush stream output buffer to persistent storage. This can be called at any time + * and is automatically called when the output buffer is full. This function is for + * use by EXTERNAL callers. Do NOT use it internally. It locks the async writer + * mutex if ther is need to do so. + * rgerhards, 2010-03-18 + */ +static rsRetVal +strmFlush(strm_t *pThis) +{ + DEFiRet; + + ASSERT(pThis != NULL); + + if(pThis->bAsyncWrite) + d_pthread_mutex_lock(&pThis->mut); + CHKiRet(strmFlushInternal(pThis)); + +finalize_it: + if(pThis->bAsyncWrite) + d_pthread_mutex_unlock(&pThis->mut); + + RETiRet; +} + + /* seek a stream to a specific location. Pending writes are flushed, read data * is invalidated. * rgerhards, 2008-01-12 @@ -1148,9 +1197,9 @@ static rsRetVal strmSeek(strm_t *pThis, off_t offs) if(pThis->fd == -1) strmOpenFile(pThis); else - strmFlush(pThis); + strmFlushInternal(pThis); int i; - dbgoprint((obj_t*) pThis, "file %d seek, pos %ld\n", pThis->fd, (long) offs); + DBGOPRINT((obj_t*) pThis, "file %d seek, pos %ld\n", pThis->fd, (long) offs); i = lseek(pThis->fd, offs, SEEK_SET); // TODO: check error! pThis->iCurrOffs = offs; /* we are now at *this* offset */ pThis->iBufPtr = 0; /* buffer invalidated */ @@ -1189,7 +1238,7 @@ static rsRetVal strmWriteChar(strm_t *pThis, uchar c) /* if the buffer is full, we need to flush before we can write */ if(pThis->iBufPtr == pThis->sIOBufSize) { - CHKiRet(strmFlush(pThis)); + CHKiRet(strmFlushInternal(pThis)); } /* we now always have space for one character, so we simply copy it */ *(pThis->pIOBuf + pThis->iBufPtr) = c; @@ -1233,6 +1282,11 @@ finalize_it: * caller-provided buffer is larger than our one. So instead of optimizing a case * which normally does not exist, we expect some degradation in its case but make us * perform better in the regular cases. -- rgerhards, 2009-07-07 + * Note: the pThis->iBufPtr == pThis->sIOBufSize logic below looks a bit like an + * on-off error. In fact, it is not, because iBufPtr always points to the next + * *free* byte in the buffer. So if it is sIOBufSize - 1, there actually is one + * free byte left. This came up during a code walkthrough and was considered + * worth nothing. -- rgerhards, 2010-03-10 */ static rsRetVal strmWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf) @@ -1254,7 +1308,7 @@ strmWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf) iOffset = 0; do { if(pThis->iBufPtr == pThis->sIOBufSize) { - CHKiRet(strmFlush(pThis)); /* get a new buffer for rest of data */ + CHKiRet(strmFlushInternal(pThis)); /* get a new buffer for rest of data */ } iWrite = pThis->sIOBufSize - pThis->iBufPtr; /* this fits in current buf */ if(iWrite > lenBuf) @@ -1269,7 +1323,7 @@ strmWrite(strm_t *pThis, uchar *pBuf, size_t lenBuf) * write it. This seems more natural than waiting (hours?) for the next message... */ if(pThis->iBufPtr == pThis->sIOBufSize) { - CHKiRet(strmFlush(pThis)); /* get a new buffer for rest of data */ + CHKiRet(strmFlushInternal(pThis)); /* get a new buffer for rest of data */ } finalize_it: @@ -1357,8 +1411,7 @@ strmSetDir(strm_t *pThis, uchar *pszDir, size_t iLenDir) if(iLenDir < 1) ABORT_FINALIZE(RS_RET_FILE_PREFIX_MISSING); - if((pThis->pszDir = malloc(sizeof(uchar) * iLenDir + 1)) == NULL) - ABORT_FINALIZE(RS_RET_OUT_OF_MEMORY); + CHKmalloc(pThis->pszDir = malloc(sizeof(uchar) * iLenDir + 1)); memcpy(pThis->pszDir, pszDir, iLenDir + 1); /* always think about the \0! */ pThis->lenDir = iLenDir; @@ -1429,7 +1482,7 @@ static rsRetVal strmSerialize(strm_t *pThis, strm_t *pStrm) ISOBJ_TYPE_assert(pThis, strm); ISOBJ_TYPE_assert(pStrm, strm); - strmFlush(pThis); + strmFlushInternal(pThis); CHKiRet(obj.BeginSerialize(pStrm, (obj_t*) pThis)); objSerializeSCALAR(pStrm, iCurrFNum, INT); diff --git a/runtime/stream.h b/runtime/stream.h index 89175b0..369d5a0 100644 --- a/runtime/stream.h +++ b/runtime/stream.h @@ -119,7 +119,6 @@ typedef struct strm_s { size_t iBufPtr; /* pointer into current buffer */ int iUngetC; /* char set via UngetChar() call or -1 if none set */ bool bInRecord; /* if 1, indicates that we are currently writing a not-yet complete record */ - bool bInClose; /* used to break "deadly close loops", tells us we are already inside a close */ int iZipLevel; /* zip level (0..9). If 0, zip is completely disabled */ Bytef *pZipBuf; /* support for async flush procesing */ diff --git a/tcps_sess.c b/tcps_sess.c index 8d30738..dec14b5 100644 --- a/tcps_sess.c +++ b/tcps_sess.c @@ -59,8 +59,6 @@ DEFobjCurrIf(datetime) static int iMaxLine; /* maximum size of a single message */ -static int iNbrTimeUsed = 0; /* how often has previous time been used so far? */ - /* forward definitions */ static rsRetVal Close(tcps_sess_t *pThis); @@ -475,7 +473,6 @@ DataRcvd(tcps_sess_t *pThis, char *pData, size_t iLen) /* We now copy the message to the session buffer. */ pEnd = pData + iLen; /* this is one off, which is intensional */ - iNbrTimeUsed = 0; /* full time query */ while(pData < pEnd) { CHKiRet(processDataRcvd(pThis, *pData++, &stTime, ttGenTime, &multiSub)); } @@ -487,6 +487,8 @@ static void doOptions(unsigned char **pp, struct templateEntry *pTpe) pTpe->data.field.eDateFormat = tplFmtPgSQLDate; } else if(!strcmp((char*)Buf, "date-rfc3164")) { pTpe->data.field.eDateFormat = tplFmtRFC3164Date; + } else if(!strcmp((char*)Buf, "date-rfc3164-buggyday")) { + pTpe->data.field.eDateFormat = tplFmtRFC3164BuggyDate; } else if(!strcmp((char*)Buf, "date-rfc3339")) { pTpe->data.field.eDateFormat = tplFmtRFC3339Date; } else if(!strcmp((char*)Buf, "date-subseconds")) { @@ -48,7 +48,7 @@ struct template { enum EntryTypes { UNDEFINED = 0, CONSTANT = 1, FIELD = 2 }; enum tplFormatTypes { tplFmtDefault = 0, tplFmtMySQLDate = 1, tplFmtRFC3164Date = 2, tplFmtRFC3339Date = 3, tplFmtPgSQLDate = 4, - tplFmtSecFrac = 5}; + tplFmtSecFrac = 5, tplFmtRFC3164BuggyDate = 6}; enum tplFormatCaseConvTypes { tplCaseConvNo = 0, tplCaseConvUpper = 1, tplCaseConvLower = 2 }; #include "msg.h" diff --git a/tests/INSTALL b/tests/INSTALL new file mode 100644 index 0000000..e69de29 --- /dev/null +++ b/tests/INSTALL diff --git a/tests/Makefile.am b/tests/Makefile.am index 7cc25e4..42ef32e 100644 --- a/tests/Makefile.am +++ b/tests/Makefile.am @@ -9,6 +9,21 @@ TESTS = $(TESTRUNS) cfg.sh \ manytcp.sh \ sndrcv.sh \ sndrcv_gzip.sh \ + asynwr_simple.sh \ + asynwr_timeout.sh \ + asynwr_small.sh \ + asynwr_tinybuf.sh \ + wr_large_async.sh \ + wr_large_sync.sh \ + asynwr_deadlock.sh \ + asynwr_deadlock2.sh \ + asynwr_deadlock4.sh \ + gzipwr_large.sh \ + gzipwr_large_dynfile.sh \ + dynfile_invld_async.sh \ + dynfile_invld_sync.sh \ + dynfile_invalid2.sh \ + complex1.sh \ queue-persist.sh \ pipeaction.sh execonlyonce.sh \ @@ -78,6 +93,7 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/1.parse1 \ testsuites/2.parse1 \ testsuites/3.parse1 \ + testsuites/snare.parse1 \ testsuites/oversizeTag-1.parse1 \ testsuites/weird.parse1 \ testsuites/date1.parse1 \ @@ -92,8 +108,15 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/rfc5424-4.parse1 \ testsuites/parse3.conf \ testsuites/reallife.parse3 \ + testsuites/parse-nodate.conf \ testsuites/parse_invld_regex.conf \ testsuites/samples.parse_invld_regex \ + testsuites/parse-3164-buggyday.conf \ + testsuites/samples.parse-3164-buggyday \ + testsuites/snare_ccoff_udp.conf \ + testsuites/samples.snare_ccoff_udp \ + testsuites/snare_ccoff_udp2.conf \ + testsuites/samples.snare_ccoff_udp2 \ testsuites/omod-if-array.conf \ testsuites/1.omod-if-array \ testsuites/1.field1 \ @@ -133,6 +156,36 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/sndrcv_gzip_rcvr.conf \ pipeaction.sh \ testsuites/pipeaction.conf \ + asynwr_simple.sh \ + testsuites/asynwr_simple.conf \ + asynwr_timeout.sh \ + testsuites/asynwr_timeout.conf \ + asynwr_small.sh \ + testsuites/asynwr_small.conf \ + asynwr_tinybuf.sh \ + testsuites/asynwr_tinybuf.conf \ + wr_large_async.sh \ + wr_large_sync.sh \ + wr_large.sh \ + testsuites/wr_large.conf \ + asynwr_deadlock.sh \ + testsuites/asynwr_deadlock.conf \ + asynwr_deadlock2.sh \ + testsuites/asynwr_deadlock2.conf \ + asynwr_deadlock4.sh \ + testsuites/asynwr_deadlock4.conf \ + gzipwr_large.sh \ + testsuites/gzipwr_large.conf \ + gzipwr_large_dynfile.sh \ + testsuites/gzipwr_large_dynfile.conf \ + complex1.sh \ + testsuites/complex1.conf \ + dynfile_invld_async.sh \ + dynfile_invld_sync.sh \ + dynfile_cachemiss.sh \ + testsuites/dynfile_cachemiss.conf \ + dynfile_invalid2.sh \ + testsuites/dynfile_invalid2.conf \ proprepltest.sh \ testsuites/rfctag.conf \ testsuites/master.rfctag \ diff --git a/tests/Makefile.in b/tests/Makefile.in index 5d9c5a2..2f8b12d 100644 --- a/tests/Makefile.in +++ b/tests/Makefile.in @@ -40,6 +40,15 @@ host_triplet = @host@ @ENABLE_TESTBENCH_TRUE@ validation-run.sh imtcp-multiport.sh \ @ENABLE_TESTBENCH_TRUE@ diskqueue.sh diskqueue-fsync.sh \ @ENABLE_TESTBENCH_TRUE@ manytcp.sh sndrcv.sh sndrcv_gzip.sh \ +@ENABLE_TESTBENCH_TRUE@ asynwr_simple.sh asynwr_timeout.sh \ +@ENABLE_TESTBENCH_TRUE@ asynwr_small.sh asynwr_tinybuf.sh \ +@ENABLE_TESTBENCH_TRUE@ wr_large_async.sh wr_large_sync.sh \ +@ENABLE_TESTBENCH_TRUE@ asynwr_deadlock.sh asynwr_deadlock2.sh \ +@ENABLE_TESTBENCH_TRUE@ asynwr_deadlock4.sh gzipwr_large.sh \ +@ENABLE_TESTBENCH_TRUE@ gzipwr_large_dynfile.sh \ +@ENABLE_TESTBENCH_TRUE@ dynfile_invld_async.sh \ +@ENABLE_TESTBENCH_TRUE@ dynfile_invld_sync.sh \ +@ENABLE_TESTBENCH_TRUE@ dynfile_invalid2.sh complex1.sh \ @ENABLE_TESTBENCH_TRUE@ queue-persist.sh pipeaction.sh \ @ENABLE_TESTBENCH_TRUE@ $(am__append_1) @ENABLE_OMSTDOUT_TRUE@@ENABLE_TESTBENCH_TRUE@am__append_1 = omod-if-array.sh \ @@ -52,7 +61,8 @@ host_triplet = @host@ @ENABLE_OMSTDOUT_TRUE@@ENABLE_TESTBENCH_TRUE@ fieldtest.sh subdir = tests -DIST_COMMON = README $(srcdir)/Makefile.am $(srcdir)/Makefile.in +DIST_COMMON = README $(srcdir)/Makefile.am $(srcdir)/Makefile.in \ + INSTALL ACLOCAL_M4 = $(top_srcdir)/aclocal.m4 am__aclocal_m4_deps = $(top_srcdir)/m4/atomic_operations.m4 \ $(top_srcdir)/m4/libtool.m4 $(top_srcdir)/m4/ltoptions.m4 \ @@ -323,6 +333,7 @@ EXTRA_DIST = 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/1.parse1 \ testsuites/2.parse1 \ testsuites/3.parse1 \ + testsuites/snare.parse1 \ testsuites/oversizeTag-1.parse1 \ testsuites/weird.parse1 \ testsuites/date1.parse1 \ @@ -337,8 +348,15 @@ EXTRA_DIST = 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/rfc5424-4.parse1 \ testsuites/parse3.conf \ testsuites/reallife.parse3 \ + testsuites/parse-nodate.conf \ testsuites/parse_invld_regex.conf \ testsuites/samples.parse_invld_regex \ + testsuites/parse-3164-buggyday.conf \ + testsuites/samples.parse-3164-buggyday \ + testsuites/snare_ccoff_udp.conf \ + testsuites/samples.snare_ccoff_udp \ + testsuites/snare_ccoff_udp2.conf \ + testsuites/samples.snare_ccoff_udp2 \ testsuites/omod-if-array.conf \ testsuites/1.omod-if-array \ testsuites/1.field1 \ @@ -378,6 +396,36 @@ EXTRA_DIST = 1.rstest 2.rstest 3.rstest err1.rstest \ testsuites/sndrcv_gzip_rcvr.conf \ pipeaction.sh \ testsuites/pipeaction.conf \ + asynwr_simple.sh \ + testsuites/asynwr_simple.conf \ + asynwr_timeout.sh \ + testsuites/asynwr_timeout.conf \ + asynwr_small.sh \ + testsuites/asynwr_small.conf \ + asynwr_tinybuf.sh \ + testsuites/asynwr_tinybuf.conf \ + wr_large_async.sh \ + wr_large_sync.sh \ + wr_large.sh \ + testsuites/wr_large.conf \ + asynwr_deadlock.sh \ + testsuites/asynwr_deadlock.conf \ + asynwr_deadlock2.sh \ + testsuites/asynwr_deadlock2.conf \ + asynwr_deadlock4.sh \ + testsuites/asynwr_deadlock4.conf \ + gzipwr_large.sh \ + testsuites/gzipwr_large.conf \ + gzipwr_large_dynfile.sh \ + testsuites/gzipwr_large_dynfile.conf \ + complex1.sh \ + testsuites/complex1.conf \ + dynfile_invld_async.sh \ + dynfile_invld_sync.sh \ + dynfile_cachemiss.sh \ + testsuites/dynfile_cachemiss.conf \ + dynfile_invalid2.sh \ + testsuites/dynfile_invalid2.conf \ proprepltest.sh \ testsuites/rfctag.conf \ testsuites/master.rfctag \ diff --git a/tests/asynwr_deadlock.sh b/tests/asynwr_deadlock.sh new file mode 100755 index 0000000..dc08355 --- /dev/null +++ b/tests/asynwr_deadlock.sh @@ -0,0 +1,23 @@ +# This is test case from practice, with the version we introduced it, it +# caused a deadlock on shutdown. I have added it to the test suite to automatically +# detect such things in the future. +# +# added 2010-03-17 by Rgerhards +# This file is part of the rsyslog project, released under GPLv3 +echo ================================================================================ +echo TEST: \[asynwr_deadlock.sh\]: a case known to have caused a deadlock in the past +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_deadlock.conf +# just send one message +source $srcdir/diag.sh tcpflood -m1 +# sleep is important! need to make sure the instance is inactive +sleep 1 +# now try shutdown. The actual test is if the process does hang here! +echo "processing must continue soon" +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 0 0 +source $srcdir/diag.sh exit diff --git a/tests/asynwr_deadlock2.sh b/tests/asynwr_deadlock2.sh new file mode 100755 index 0000000..1190f67 --- /dev/null +++ b/tests/asynwr_deadlock2.sh @@ -0,0 +1,69 @@ +# This is test case from practice, with the version we introduced it, it +# caused a deadlock during processing (when the a stream was purged from the +# dynafile cache). +# We added this as a standard test in the hopes that iw will help +# detect such things in the future. +# +# The problem that originally caused this test to fail was: +# We write to files asynchronously (with the async writer thread). There is +# no signaling done when the file stream is closed. That can lead to the writer +# process hanging in memory, that in turn leads to the main thread waiting on a +# condition that never occurs (because it would need to be signalled by the +# async writer). Even worse, in that case, the async writer was signalled invalid +# in such a way that when it received a wakeup, it thought it shall not terminate, +# but received a spurios wakeup due to timeout and no data to write. In that case +# it (correctly) concluded that it would not need to timeout until a new buffer write +# was done (in which case it would receive a wakeup). As such, it went into an eternal +# wait. However, the invalid signaling did not take into account that it did not +# signal the async writer to shut down. So the main thread went into a condition +# wait - and thus we had a deadlock. That situation occured only under very specific +# cirumstances. As far as the analysis goes, the following need to happen: +# 1. buffers on that file are being flushed +# 2. no new data arrives +# 3. the inactivity timeout has not yet expired +# 4. *then* (and only then) the stream is closed or destructed +# In that, 1 to 4 are prequisites for the deadlock which will happen in 4. However, +# for it to happen, we also need the right "timing". There is a race between the +# main thread and the async writer thread. The deadlock will only happen under +# the "right" circumstances, which basically means it will not happen always. +# In order to create this case as reliable as possible, I have used +# the "$OMFileFlushOnTXEnd on" directive +# inside my test case. It makes sure that #1 above happens. The test uses a dynafile +# cache size of 4, and the load generator generates data for 5 different dynafiles. +# So over time, we will hit a spot where 4 dynafiles are open and the 5th file name +# is generated. As such, one file needs to be discarded. Thanks to FlushOnTXEnd, we +# now likely have #2 in place and thanks to the load pattern generated, we most +# probably have #3 in place. During the dynafile cache displacement of the oldest +# entry, #4 is generated. At this point, we have the deadlock we are testing for. +# Note that this deadlock does not necessarily lead to a total lockup of rsyslogd. +# Parts of it continue to operate. But in our test setup, this means data is +# received and placed into the main queue. Once it's high water mark is hit, data +# is still being enqueued, but at a slow rate. So if one is patient enough, the load +# generator will be able to finish. However, rsyslogd will never process the data +# it received because it is locked in the deadlock caused by #4 above. +# Note that "$OMFileFlushOnTXEnd on" is not causing this behaviour. We just use it +# to (quite) reliably cause the failure condition. The failure described above +# (in version 4.6.1) was also present when the setting was set to "off", but its +# occurence was very much less probable - because the perquisites are then much +# harder to hit. without it, the test may need to run for several hours before +# we hit all failure conditions. +# +# added 2010-03-17 by Rgerhards +# This file is part of the rsyslog project, released under GPLv3 +echo ================================================================================= +echo TEST: \[asynwr_deadlock2.sh\]: a case known to have caused a deadlock in the past +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_deadlock2.conf +# send 20000 messages, each close to 2K (non-randomized!), so that we can fill +# the buffers and hopefully run into the "deadlock". +source $srcdir/diag.sh tcpflood -m20000 -d1800 -P129 -i1 -f5 +# the sleep below is needed to prevent too-early termination of the tcp listener +sleep 1 +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +cat rsyslog.out.*.log > rsyslog.out.log +source $srcdir/diag.sh seq-check 1 20000 -E +source $srcdir/diag.sh exit diff --git a/tests/asynwr_deadlock4.sh b/tests/asynwr_deadlock4.sh new file mode 100755 index 0000000..a3452f5 --- /dev/null +++ b/tests/asynwr_deadlock4.sh @@ -0,0 +1,25 @@ +# This is test case from practice, with the version we introduced it, it +# caused a deadlock during processing. +# We added this as a standard test in the hopes that iw will help +# detect such things in the future. +# +# This is a test that is constructed similar to asynwr_deadlock2.sh, but +# can produce problems in a simpler way. +# +# added 2010-03-18 by Rgerhards +# This file is part of the rsyslog project, released under GPLv3 +echo ================================================================================= +echo TEST: \[asynwr_deadlock4.sh\]: a case known to have caused a deadlock in the past +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_deadlock4.conf +# send 20000 messages, each close to 2K (non-randomized!), so that we can fill +# the buffers and hopefully run into the "deadlock". +source $srcdir/diag.sh tcpflood -m20000 -d18 -P129 -i1 -f5 +# sleep is important! need to make sure the instance is inactive +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 1 20000 -E +source $srcdir/diag.sh exit diff --git a/tests/asynwr_simple.sh b/tests/asynwr_simple.sh new file mode 100755 index 0000000..eb87443 --- /dev/null +++ b/tests/asynwr_simple.sh @@ -0,0 +1,18 @@ +# This is test driver for testing asynchronous file output. +# +# added 2010-03-09 by Rgerhards +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[asynwr_simple.sh\]: simple test for async file writing +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_simple.conf +# send 35555 messages, make sure file size is not a multiple of +# 10K, the buffer size! +source $srcdir/diag.sh tcpflood -m35555 +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 0 35554 +source $srcdir/diag.sh exit diff --git a/tests/asynwr_small.sh b/tests/asynwr_small.sh new file mode 100755 index 0000000..97818f6 --- /dev/null +++ b/tests/asynwr_small.sh @@ -0,0 +1,26 @@ +# This tests async writing with only a small set of data. That +# shall result in data staying in buffers until shutdown, what +# then will trigger some somewhat complex logic in the stream +# writer (open, write, close all during the stream close +# opertion). It is vital that only few messages be sent. +# +# The main effort of this test is not (only) to see if we +# receive the data, but rather to see if we get into an abort +# condition. +# +# added 2010-03-09 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[asynwr_small.sh\]: test for async file writing for few messages +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_small.conf +# send 4000 messages +source $srcdir/diag.sh tcpflood -m2 +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 0 1 +source $srcdir/diag.sh exit diff --git a/tests/asynwr_timeout.sh b/tests/asynwr_timeout.sh new file mode 100755 index 0000000..b0bc5c2 --- /dev/null +++ b/tests/asynwr_timeout.sh @@ -0,0 +1,21 @@ +# This test writes to the output buffers, let's the output +# write timeout (and write data) and then continue. The conf file +# has a 2 second timeout, so we wait 4 seconds to be on the save side. +# +# added 2010-03-09 by Rgerhards +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[asynwr_timeout.sh\]: test async file writing timeout writes +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_timeout.conf +# send 35555 messages, make sure file size is not a multiple of +# 10K, the buffer size! +source $srcdir/diag.sh tcpflood -m 35555 +sleep 4 # wait for output writer to write and empty buffer +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 0 35554 +source $srcdir/diag.sh exit diff --git a/tests/asynwr_tinybuf.sh b/tests/asynwr_tinybuf.sh new file mode 100755 index 0000000..8eae1e2 --- /dev/null +++ b/tests/asynwr_tinybuf.sh @@ -0,0 +1,19 @@ +# This tests async writing with a very small output buffer (1 byte!), +# so it stresses output buffer handling. This also means operations will +# be somewhat slow, so we send only a small amounts of data. +# +# added 2010-03-09 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[asynwr_tinybuf.sh\]: test async file writing with 1-byte buffer +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup asynwr_tinybuf.conf +# send 1000 messages, fairly enough to trigger problems +source $srcdir/diag.sh tcpflood -m1000 +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh seq-check 0 999 +source $srcdir/diag.sh exit diff --git a/tests/chkseq.c b/tests/chkseq.c index 6334d78..b22c899 100644 --- a/tests/chkseq.c +++ b/tests/chkseq.c @@ -32,6 +32,7 @@ #include "config.h" #include <stdio.h> #include <stdlib.h> +#include <string.h> #include <getopt.h> int main(int argc, char *argv[]) @@ -40,14 +41,18 @@ int main(int argc, char *argv[]) int val; int i; int ret = 0; + int scanfOK; int verbose = 0; + int bHaveExtraData = 0; int dupsPermitted = 0; int start = 0, end = 0; int opt; int nDups = 0; + int edLen; /* length of extra data */ + static char edBuf[500*1024]; /* buffer for extra data (pretty large to be on the save side...) */ char *file = NULL; - while((opt = getopt(argc, argv, "e:f:ds:v")) != EOF) { + while((opt = getopt(argc, argv, "e:f:ds:vE")) != EOF) { switch((char)opt) { case 'f': file = optarg; @@ -64,8 +69,11 @@ int main(int argc, char *argv[]) case 'v': ++verbose; break; - default:printf("Invalid call of chkseq\n"); - printf("Usage: chkseq file -sstart -eend -d\n"); + case 'E': + bHaveExtraData = 1; + break; + default:printf("Invalid call of chkseq, optchar='%c'\n", opt); + printf("Usage: chkseq file -sstart -eend -d -E\n"); exit(1); } } @@ -93,7 +101,17 @@ int main(int argc, char *argv[]) } for(i = start ; i < end+1 ; ++i) { - if(fscanf(fp, "%d\n", &val) != 1) { + if(bHaveExtraData) { + scanfOK = fscanf(fp, "%d,%d,%s\n", &val, &edLen, edBuf) == 3 ? 1 : 0; + if(edLen != (int) strlen(edBuf)) { + printf("extra data length specified %d, but actually is %ld in record %d\n", + edLen, (long) strlen(edBuf), i); + exit(1); + } + } else { + scanfOK = fscanf(fp, "%d\n", &val) == 1 ? 1 : 0; + } + if(!scanfOK) { printf("scanf error in index i=%d\n", i); exit(1); } @@ -116,5 +134,10 @@ int main(int argc, char *argv[]) exit(1); } + if(!feof(fp)) { + printf("end of processing, but NOT end of file!\n"); + exit(1); + } + exit(ret); } diff --git a/tests/complex1.sh b/tests/complex1.sh new file mode 100755 index 0000000..b5dc2c9 --- /dev/null +++ b/tests/complex1.sh @@ -0,0 +1,21 @@ +# This is a rather complex test that runs a number of features together. +# +# added 2010-03-16 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo ==================================================================================== +echo TEST: \[complex1.sh\]: complex test with gzip and multiple action queues +source $srcdir/diag.sh init +# uncomment for debugging support: +export RSYSLOG_DEBUG="debug nostdout" +export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup complex1.conf +# send 30,000 messages of 400 bytes plus header max, via three dest ports +source $srcdir/diag.sh tcpflood -m40000 -rd400 -P129 -f5 -n3 -c15 -i1 +sleep 2 # due to large messages, we need this time for the tcp receiver to settle... +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +ls rsyslog.out.*.log +zcat rsyslog.out.*.log > rsyslog.out.log +source $srcdir/diag.sh seq-check 1 40000 -E +source $srcdir/diag.sh exit diff --git a/tests/diag.sh b/tests/diag.sh index f3d75a1..8f268a5 100755 --- a/tests/diag.sh +++ b/tests/diag.sh @@ -8,6 +8,7 @@ #valgrind="valgrind --log-fd=1" #valgrind="valgrind --tool=drd --log-fd=1" #valgrind="valgrind --tool=helgrind --log-fd=1" +#valgrind="valgrind --tool=exp-ptrcheck --log-fd=1" #set -o xtrace #export RSYSLOG_DEBUG="debug nostdout printmutexaction" #export RSYSLOG_DEBUGLOG="log" @@ -15,16 +16,19 @@ case $1 in 'init') $srcdir/killrsyslog.sh # kill rsyslogd if it runs for some reason cp $srcdir/testsuites/diag-common.conf diag-common.conf cp $srcdir/testsuites/diag-common2.conf diag-common2.conf + rm -f rsyslog.action.*.include rm -f rsyslogd.started work-*.conf rm -f rsyslogd2.started work-*.conf rm -f work rsyslog.out.log rsyslog.out.log.save # common work files + rm -f rsyslog.out.*.log rm -rf test-spool rm -f core.* vgcore.* mkdir test-spool ;; 'exit') rm -f rsyslogd.started work-*.conf diag-common.conf - rm -f rsyslogd2.started diag-common2.conf + rm -f rsyslogd2.started diag-common2.conf rsyslog.action.*.include rm -f work rsyslog.out.log rsyslog.out.log.save # common work files + rm -f rsyslog.out.*.log rm -rf test-spool ;; 'startup') # start rsyslogd with default params. $2 is the config file name to use @@ -34,14 +38,16 @@ case $1 in ;; 'wait-startup') # wait for rsyslogd startup ($2 is the instance) while test ! -f rsyslogd$2.started; do - true + #true + sleep 0.1 # if this is not supported by all platforms, use above! done echo "rsyslogd$2 started with pid " `cat rsyslog$2.pid` ;; 'wait-shutdown') # actually, we wait for rsyslog.pid to be deleted. $2 is the # instance while test -f rsyslog$2.pid; do - true + #true + sleep 0.1 # if this is not supported by all platforms, use above! done ;; 'wait-queueempty') # wait for main message queue to be empty. $2 is the instance. @@ -62,7 +68,7 @@ case $1 in # note: we do not wait for the actual termination! ;; 'tcpflood') # do a tcpflood run and check if it worked params are passed to tcpflood - ./tcpflood $2 $3 $4 $5 $6 $7 $8 + ./tcpflood $2 $3 $4 $5 $6 $7 $8 $9 if [ "$?" -ne "0" ]; then echo "error during tcpflood! see rsyslog.out.log.save for what was written" cp rsyslog.out.log rsyslog.out.log.save @@ -85,6 +91,7 @@ case $1 in ;; 'seq-check') # do the usual sequence check to see if everything was properly received. $2 is the instance. rm -f work + cp rsyslog.out.log work-presort sort < rsyslog.out.log > work # $4... are just to have the abilit to pass in more options... ./chkseq -fwork -v -s$2 -e$3 $4 $5 $6 $7 @@ -105,6 +112,18 @@ case $1 in exit 1 fi ;; + 'gzip-seq-check') # do the usual sequence check, but for gzip files + rm -f work + ls -l rsyslog.out.log + gunzip < rsyslog.out.log | sort > work + ls -l work + # $4... are just to have the abilit to pass in more options... + ./chkseq -fwork -v -s$2 -e$3 $4 $5 $6 $7 + if [ "$?" -ne "0" ]; then + echo "sequence error detected" + exit 1 + fi + ;; 'nettester') # perform nettester-based tests # use -v for verbose output! ./nettester -t$2 -i$3 diff --git a/tests/diskqueue-fsync.sh b/tests/diskqueue-fsync.sh index 0282202..c774593 100755 --- a/tests/diskqueue-fsync.sh +++ b/tests/diskqueue-fsync.sh @@ -9,7 +9,7 @@ echo testing queue disk-only mode, fsync case source $srcdir/diag.sh init source $srcdir/diag.sh startup diskqueue-fsync.conf # 1000 messages should be enough - the disk fsync test is very slow! -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 1000 +source $srcdir/diag.sh tcpflood -m1000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown source $srcdir/diag.sh seq-check 0 999 diff --git a/tests/diskqueue.sh b/tests/diskqueue.sh index 8233d56..7a50d82 100755 --- a/tests/diskqueue.sh +++ b/tests/diskqueue.sh @@ -6,11 +6,14 @@ # This file is part of the rsyslog project, released under GPLv3 # uncomment for debugging support: echo diskqueue.sh: testing queue disk-only mode +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" source $srcdir/diag.sh init source $srcdir/diag.sh startup diskqueue.conf # 20000 messages should be enough - the disk test is slow enough ;) sleep 4 -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 20000 +source $srcdir/diag.sh tcpflood -m20000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown source $srcdir/diag.sh seq-check 0 19999 diff --git a/tests/dynfile_cachemiss.sh b/tests/dynfile_cachemiss.sh new file mode 100755 index 0000000..6e2d9cc --- /dev/null +++ b/tests/dynfile_cachemiss.sh @@ -0,0 +1,34 @@ +# This test checks if omfile segfaults when a file open() in dynacache mode fails. +# The test is mimiced after a real-life scenario (which, of course, was much more +# complex). +# +# added 2010-03-09 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[dynfile_cachemiss.sh\]: test open fail for dynafiles with `cat rsyslog.action.1.include` +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup dynfile_cachemiss.conf +# we send handcrafted message. We have a dynafile cache of 4, and now send one message +# each to fill up the cache. +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.0.log:0" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.1.log:1" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.2.log:2" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.3.log:3" +# the next one has caused a segfault in practice +# note that /proc/rsyslog.error.file must not be creatable +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:/proc/rsyslog.error.file:boom" +# some more writes +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.0.log:4" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.1.log:5" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.2.log:6" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.3.log:7" +# done message generation +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +cat rsyslog.out.*.log > rsyslog.out.log +source $srcdir/diag.sh seq-check 0 7 +source $srcdir/diag.sh exit diff --git a/tests/dynfile_invalid2.sh b/tests/dynfile_invalid2.sh new file mode 100755 index 0000000..b6fb394 --- /dev/null +++ b/tests/dynfile_invalid2.sh @@ -0,0 +1,34 @@ +# This test checks if omfile segfaults when a file open() in dynacache mode fails. +# The test is mimiced after a real-life scenario (which, of course, was much more +# complex). +# +# added 2010-03-22 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[dynfile_invalid2.sh\]: test open fail for dynafiles +source $srcdir/diag.sh init +# uncomment for debugging support: +export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup dynfile_invalid2.conf +# we send handcrafted message. We have a dynafile cache of 4, and now send one message +# each to fill up the cache. +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.0.log:0" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.1.log:1" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.2.log:2" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.3.log:3" +# the next one has caused a segfault in practice +# note that /proc/rsyslog.error.file must not be creatable +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:/proc/rsyslog.error.file:boom" +# some more writes +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.0.log:4" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.1.log:5" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.2.log:6" +./tcpflood -m1 -M "<129>Mar 10 01:00:00 172.20.245.8 tag msg:rsyslog.out.3.log:7" +# done message generation +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +cat rsyslog.out.*.log > rsyslog.out.log +source $srcdir/diag.sh seq-check 0 7 +source $srcdir/diag.sh exit diff --git a/tests/dynfile_invld_async.sh b/tests/dynfile_invld_async.sh new file mode 100755 index 0000000..3c9b204 --- /dev/null +++ b/tests/dynfile_invld_async.sh @@ -0,0 +1,2 @@ +echo "\$OMFileAsyncWriting on" > rsyslog.action.1.include +source $srcdir/dynfile_cachemiss.sh diff --git a/tests/dynfile_invld_sync.sh b/tests/dynfile_invld_sync.sh new file mode 100755 index 0000000..cc6b645 --- /dev/null +++ b/tests/dynfile_invld_sync.sh @@ -0,0 +1,2 @@ +echo "\$OMFileAsyncWriting off" > rsyslog.action.1.include +source $srcdir/dynfile_cachemiss.sh diff --git a/tests/execonlyonce.sh b/tests/execonlyonce.sh index a9b9d93..b7f6084 100755 --- a/tests/execonlyonce.sh +++ b/tests/execonlyonce.sh @@ -10,11 +10,11 @@ echo =========================================================================== echo \[execonlyonce.sh\]: test for the $ActionExecOnlyOnceEveryInterval directive source $srcdir/diag.sh init source $srcdir/diag.sh startup execonlyonce.conf -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 10 1 +source $srcdir/diag.sh tcpflood -m10 -i1 # now wait until the interval definitely expires sleep 4 # one more than the once inerval! # and inject another couple of messages -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 10 100 +source $srcdir/diag.sh tcpflood -m10 -i100 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages # now we need your custom logic to see if the result is equal to the diff --git a/tests/gzipwr_large.sh b/tests/gzipwr_large.sh new file mode 100755 index 0000000..ffce06f --- /dev/null +++ b/tests/gzipwr_large.sh @@ -0,0 +1,20 @@ +# This tests writing large data records in gzip mode. We use up to 10K +# record size. +# +# added 2010-03-10 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[gzipwr_large.sh\]: test for gzip file writing for large message sets +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup gzipwr_large.conf +# send 4000 messages of 10.000bytes plus header max, randomized +source $srcdir/diag.sh tcpflood -m4000 -r -d10000 -P129 +sleep 1 # due to large messages, we need this time for the tcp receiver to settle... +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh gzip-seq-check 0 3999 -E +source $srcdir/diag.sh exit diff --git a/tests/gzipwr_large_dynfile.sh b/tests/gzipwr_large_dynfile.sh new file mode 100755 index 0000000..ebd4c55 --- /dev/null +++ b/tests/gzipwr_large_dynfile.sh @@ -0,0 +1,36 @@ +# This tests writing large data records in gzip mode. We also write it to +# 5 different dynafiles, with a dynafile cache size set to 4. So this stresses +# both the input side, as well as zip writing, async writing and the dynafile +# cache logic. +# +# This test is a bit timing-dependent on the tcp reception side, so if it fails +# one may look into the timing first. The main issue is that the testbench +# currently has no good way to know if the tcp receiver is finished. This is NOT +# a problem in rsyslogd, but only of the testbench. +# +# Note that we do not yet have sufficient support for dynafiles in diag.sh, +# so we mangle some files here manually. +# +# added 2010-03-10 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo ==================================================================================== +echo TEST: \[gzipwr_large_dynfile.sh\]: test for gzip file writing for large message sets +source $srcdir/diag.sh init +# uncomment for debugging support: +export RSYSLOG_DEBUG="debug nostdout" +export RSYSLOG_DEBUGLOG="log" +source $srcdir/diag.sh startup gzipwr_large_dynfile.conf +# send 4000 messages of 10.000bytes plus header max, randomized +source $srcdir/diag.sh tcpflood -m4000 -r -d10000 -P129 -f5 +sleep 2 # due to large messages, we need this time for the tcp receiver to settle... +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +gunzip < rsyslog.out.0.log > rsyslog.out.log +gunzip < rsyslog.out.1.log >> rsyslog.out.log +gunzip < rsyslog.out.2.log >> rsyslog.out.log +gunzip < rsyslog.out.3.log >> rsyslog.out.log +gunzip < rsyslog.out.4.log >> rsyslog.out.log +#cat rsyslog.out.* > rsyslog.out.log +source $srcdir/diag.sh seq-check 0 3999 -E +source $srcdir/diag.sh exit diff --git a/tests/imtcp-multiport.sh b/tests/imtcp-multiport.sh index 47a33cb..ad2b44f 100755 --- a/tests/imtcp-multiport.sh +++ b/tests/imtcp-multiport.sh @@ -11,7 +11,7 @@ echo =========================================================================== echo \[imtcp-multiport.sh\]: testing imtcp multiple listeners source $srcdir/diag.sh init source $srcdir/diag.sh startup imtcp-multiport.conf -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 10000 +source $srcdir/diag.sh tcpflood -p13514 -m10000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown source $srcdir/diag.sh seq-check 0 9999 @@ -23,7 +23,7 @@ source $srcdir/diag.sh exit # source $srcdir/diag.sh init source $srcdir/diag.sh startup imtcp-multiport.conf -source $srcdir/diag.sh tcpflood 127.0.0.1 13515 1 10000 +source $srcdir/diag.sh tcpflood -p13515 -m10000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown source $srcdir/diag.sh seq-check 0 9999 @@ -35,7 +35,7 @@ source $srcdir/diag.sh exit # source $srcdir/diag.sh init source $srcdir/diag.sh startup imtcp-multiport.conf -source $srcdir/diag.sh tcpflood 127.0.0.1 13516 1 10000 +source $srcdir/diag.sh tcpflood -p13516 -m10000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown source $srcdir/diag.sh seq-check 0 9999 diff --git a/tests/manytcp.sh b/tests/manytcp.sh index c55eb9c..94a5c03 100755 --- a/tests/manytcp.sh +++ b/tests/manytcp.sh @@ -2,7 +2,10 @@ source $srcdir/diag.sh init source $srcdir/diag.sh startup manytcp.conf # the config file specifies exactly 1100 connections -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1000 40000 +source $srcdir/diag.sh tcpflood -c1000 -m40000 +# the sleep below is needed to prevent too-early termination of the tcp listener +sleep 1 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # we need to wait until rsyslogd is finished! source $srcdir/diag.sh seq-check 0 39999 source $srcdir/diag.sh exit diff --git a/tests/nettester.c b/tests/nettester.c index 209c2a6..e1ecbcb 100644 --- a/tests/nettester.c +++ b/tests/nettester.c @@ -47,6 +47,7 @@ #include <signal.h> #include <netinet/in.h> #include <getopt.h> +#include <ctype.h> #define EXIT_FAILURE 1 #define INVALID_SOCKET -1 @@ -61,6 +62,7 @@ static char *testSuite = NULL; /* name of current test suite */ static int iPort = 12514; /* port which shall be used for sending data */ static char* pszCustomConf = NULL; /* custom config file, use -c conf to specify */ static int verbose = 0; /* verbose output? -v option */ +static int useDebugEnv = 0; /* activate debugging environment (for rsyslog debug log)? */ /* these two are quick hacks... */ int iFailed = 0; @@ -217,10 +219,8 @@ int openPipe(char *configFile, pid_t *pid, int *pfd) "-M../runtime/.libs:../.libs", NULL }; char confFile[1024]; char *newenviron[] = { NULL }; - /* debug aide... - char *newenviron[] = { "RSYSLOG_DEBUG=debug nostdout", + char *newenvironDeb[] = { "RSYSLOG_DEBUG=debug nostdout", "RSYSLOG_DEBUGLOG=log", NULL }; - */ sprintf(confFile, "-f%s/testsuites/%s.conf", srcdir, (pszCustomConf == NULL) ? configFile : pszCustomConf); @@ -243,7 +243,7 @@ int openPipe(char *configFile, pid_t *pid, int *pfd) close(pipefd[1]); close(pipefd[0]); fclose(stdin); - execve("../tools/rsyslogd", newargv, newenviron); + execve("../tools/rsyslogd", newargv, (useDebugEnv) ? newenvironDeb : newenviron); } else { close(pipefd[1]); *pid = cpid; @@ -254,6 +254,62 @@ int openPipe(char *configFile, pid_t *pid, int *pfd) } +/* This function unescapes a string of testdata. That it, escape sequences + * are converted into their one-character equivalent. While doing so, it applies + * C-like semantics. This was made necessary for easy integration of control + * characters inside test cases. -- rgerhards, 2009-03-11 + * Currently supported: + * \\ single backslash + * \n, \t, \r as in C + * \nnn where nnn is a 1 to 3 character octal sequence + * Note that when a problem occurs, the end result is undefined. After all, this + * is for a testsuite generatort, it must not be 100% bullet proof (so do not + * copy this code into something that must be!). Also note that we do in-memory + * unescaping and assume that the string gets shorter but NEVER longer! + */ +void unescapeTestdata(char *testdata) +{ + char *pDst; + char *pSrc; + int i; + int c; + + pDst = pSrc = testdata; + while(*pSrc) { + if(*pSrc == '\\') { + switch(*++pSrc) { + case '\\': *pDst++ = *pSrc++; + break; + case 'n': *pDst++ = '\n'; + ++pSrc; + break; + case 'r': *pDst++ = '\r'; + ++pSrc; + break; + case 't': *pDst++ = '\t'; + ++pSrc; + break; + case '0': + case '1': + case '2': + case '3': c = *pSrc++ - '0'; + i = 1; /* we already processed one digit! */ + while(i < 3 && isdigit(*pSrc)) { + c = c * 8 + *pSrc++ - '0'; + ++i; + } + *pDst++ = c; + break; + default: break; + } + } else { + *pDst++ = *pSrc++; + } + } + *pDst = '\0'; +} + + /* Process a specific test case. File name is provided. * Needs to return 0 if all is OK, something else otherwise. */ @@ -291,6 +347,7 @@ processTestFile(int fd, char *pszFileName) testdata[strlen(testdata)-1] = '\0'; /* remove \n */ /* now we have the test data to send (we could use function pointers here...) */ + unescapeTestdata(testdata); if(inputMode == inputUDP) { if(udpSend(testdata, strlen(testdata)) != 0) return(2); @@ -314,10 +371,13 @@ processTestFile(int fd, char *pszFileName) expected, buf); ret = 1; } - + /* we need to free buffers, as we have potentially modified them! */ + free(testdata); + testdata = NULL; + free(expected); + expected = NULL; } - free(testdata); free(expected); fclose(fp); return(ret); @@ -399,11 +459,14 @@ int main(int argc, char *argv[]) char buf[4096]; char testcases[4096]; - while((opt = getopt(argc, argv, "c:i:p:t:v")) != EOF) { + while((opt = getopt(argc, argv, "dc:i:p:t:v")) != EOF) { switch((char)opt) { case 'c': pszCustomConf = optarg; break; + case 'd': + useDebugEnv = 1; + break; case 'i': if(!strcmp(optarg, "udp")) inputMode = inputUDP; @@ -424,7 +487,7 @@ int main(int argc, char *argv[]) verbose = 1; break; default:printf("Invalid call of nettester, invalid option '%c'.\n", opt); - printf("Usage: nettester -ttestsuite-name -iudp|tcp [-pport] [-ccustomConfFile] \n"); + printf("Usage: nettester -d -ttestsuite-name -iudp|tcp [-pport] [-ccustomConfFile] \n"); exit(1); } } diff --git a/tests/parsertest.sh b/tests/parsertest.sh index 5966a11..fc68ab8 100755 --- a/tests/parsertest.sh +++ b/tests/parsertest.sh @@ -6,6 +6,14 @@ source $srcdir/diag.sh nettester parse3 udp source $srcdir/diag.sh nettester parse3 tcp source $srcdir/diag.sh nettester parse_invld_regex udp source $srcdir/diag.sh nettester parse_invld_regex tcp +source $srcdir/diag.sh nettester parse-3164-buggyday udp +source $srcdir/diag.sh nettester parse-3164-buggyday tcp +source $srcdir/diag.sh nettester parse-nodate udp +source $srcdir/diag.sh nettester parse-nodate tcp +# the following samples can only be run over UDP as they are so +# malformed they break traditional syslog/tcp framing... +source $srcdir/diag.sh nettester snare_ccoff_udp udp +source $srcdir/diag.sh nettester snare_ccoff_udp2 udp echo \[parsertest.sh]: redoing tests in IPv4-only mode source $srcdir/diag.sh nettester parse1 udp -4 @@ -14,4 +22,12 @@ source $srcdir/diag.sh nettester parse3 udp -4 source $srcdir/diag.sh nettester parse3 tcp -4 source $srcdir/diag.sh nettester parse_invld_regex udp -4 source $srcdir/diag.sh nettester parse_invld_regex tcp -4 +source $srcdir/diag.sh nettester parse-3164-buggyday udp -4 +source $srcdir/diag.sh nettester parse-3164-buggyday tcp -4 +source $srcdir/diag.sh nettester parse-nodate udp -4 +source $srcdir/diag.sh nettester parse-nodate tcp -4 +# UDP-only tests +source $srcdir/diag.sh nettester snare_ccoff_udp udp -4 +source $srcdir/diag.sh nettester snare_ccoff_udp2 udp -4 + source $srcdir/diag.sh exit diff --git a/tests/pipeaction.sh b/tests/pipeaction.sh index 26a4c22..c220101 100755 --- a/tests/pipeaction.sh +++ b/tests/pipeaction.sh @@ -17,7 +17,7 @@ echo background cp process id is $CPPROCESS # now do the usual run source $srcdir/diag.sh startup pipeaction.conf # 20000 messages should be enough -#source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 20000 +#source $srcdir/diag.sh tcpflood -m20000 source $srcdir/diag.sh injectmsg 0 20000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh wait-shutdown diff --git a/tests/sndrcv_drvr.sh b/tests/sndrcv_drvr.sh index 63afd6b..3d61306 100755 --- a/tests/sndrcv_drvr.sh +++ b/tests/sndrcv_drvr.sh @@ -34,7 +34,7 @@ source $srcdir/diag.sh wait-startup 2 # now inject the messages into instance 2. It will connect to instance 1, # and that instance will record the data. -source $srcdir/diag.sh tcpflood 127.0.0.1 13514 1 $2 1 +source $srcdir/diag.sh tcpflood -m$2 -i1 sleep 2 # make sure all data is received in input buffers # shut down sender when everything is sent, receiver continues to run concurrently # may be needed by TLS (once we do it): sleep 60 diff --git a/tests/tcpflood.c b/tests/tcpflood.c index 0439e33..32bf959 100644 --- a/tests/tcpflood.c +++ b/tests/tcpflood.c @@ -2,15 +2,28 @@ * messages over them. This is used for stress-testing. * * Params - * argv[1] target address - * argv[2] target port - * argv[3] number of connections - * argv[4] number of messages to send (connection is random) - * argv[5] initial message number (optional) + * -t target address (default 127.0.0.1) + * -p target port (default 13514) + * -n number of target ports (targets are in range -p..(-p+-n-1) + * -c number of connections (default 1) + * -m number of messages to send (connection is random) + * -i initial message number (optional) + * -P PRI to be used for generated messages (default is 167). + * Specify the plain number without leading zeros + * -d amount of extra data to add to message. If present, the + * number itself will be added as third field, and the data + * bytes as forth. Add -r to randomize the amount of extra + * data included in the range 1..(value of -d). + * -r randomize amount of extra data added (-d must be > 0) + * -f support for testing dynafiles. If given, include a dynafile ID + * in the range 0..(f-1) as the SECOND field, shifting all field values + * one field to the right. Zero (default) disables this functionality. + * -M the message to be sent. Disables all message format options, as + * only that exact same message is sent. * * Part of the testbench for rsyslog. * - * Copyright 2009 Rainer Gerhards and Adiscon GmbH. + * Copyright 2009, 2010 Rainer Gerhards and Adiscon GmbH. * * This file is part of rsyslog. * @@ -47,12 +60,21 @@ /* Name of input file, must match $IncludeConfig in test suite .conf files */ #define NETTEST_INPUT_CONF_FILE "nettest.input.conf" /* name of input file, must match $IncludeConfig in .conf files */ -static char *targetIP; -static int targetPort; +#define MAX_EXTRADATA_LEN 100*1024 + +static char *targetIP = "127.0.0.1"; +static char *msgPRI = "167"; +static int targetPort = 13514; +static int numTargetPorts = 1; +static int dynFileIDs = 0; +static int extraDataLen = 0; /* amount of extra data to add to message */ +static int bRandomizeExtraData = 0; /* randomize amount of extra data added */ static int numMsgsToSend; /* number of messages to send */ -static int numConnections; /* number of connections to create */ +static int numConnections = 1; /* number of connections to create */ static int *sockArray; /* array of sockets to use */ static int msgNum = 0; /* initial message number to start with */ +static int bShowProgress = 1; /* show progress messages */ +static char *MsgToSend = NULL; /* if non-null, this is the actual message to send */ /* open a single tcp connection @@ -61,16 +83,25 @@ int openConn(int *fd) { int sock; struct sockaddr_in addr; + int port; int retries = 0; + int rnd; if((sock=socket(AF_INET, SOCK_STREAM, 0))==-1) { perror("socket()"); return(1); } + /* randomize port if required */ + if(numTargetPorts > 1) { + rnd = rand(); /* easier if we need value for debug messages ;) */ + port = targetPort + (rnd % numTargetPorts); + } else { + port = targetPort; + } memset((char *) &addr, 0, sizeof(addr)); addr.sin_family = AF_INET; - addr.sin_port = htons(targetPort); + addr.sin_port = htons(port); if(inet_aton(targetIP, &addr.sin_addr)==0) { fprintf(stderr, "inet_aton() failed\n"); return(1); @@ -103,11 +134,13 @@ int openConnections(void) char msgBuf[128]; size_t lenMsg; - write(1, " open connections", sizeof(" open connections")-1); + if(bShowProgress) + write(1, " open connections", sizeof(" open connections")-1); sockArray = calloc(numConnections, sizeof(int)); for(i = 0 ; i < numConnections ; ++i) { if(i % 10 == 0) { - printf("\r%5.5d", i); + if(bShowProgress) + printf("\r%5.5d", i); //lenMsg = sprintf(msgBuf, "\r%5.5d", i); //write(1, msgBuf, lenMsg); } @@ -136,11 +169,14 @@ void closeConnections(void) char msgBuf[128]; size_t lenMsg; - write(1, " close connections", sizeof(" close connections")-1); + if(bShowProgress) + write(1, " close connections", sizeof(" close connections")-1); for(i = 0 ; i < numConnections ; ++i) { if(i % 10 == 0) { - lenMsg = sprintf(msgBuf, "\r%5.5d", i); - write(1, msgBuf, lenMsg); + if(bShowProgress) { + lenMsg = sprintf(msgBuf, "\r%5.5d", i); + write(1, msgBuf, lenMsg); + } } close(sockArray[i]); } @@ -164,12 +200,14 @@ int sendMessages(void) int socknum; int lenBuf; int lenSend; - char buf[2048]; - - srand(time(NULL)); /* seed is good enough for our needs */ + int edLen; /* actual extra data length to use */ + char dynFileIDBuf[128] = ""; + char buf[MAX_EXTRADATA_LEN + 1024]; + char extraData[MAX_EXTRADATA_LEN + 1]; printf("Sending %d messages.\n", numMsgsToSend); - printf("\r%5.5d messages sent", 0); + if(bShowProgress) + printf("\r%8.8d messages sent", 0); for(i = 0 ; i < numMsgsToSend ; ++i) { if(i < numConnections) socknum = i; @@ -177,7 +215,27 @@ int sendMessages(void) socknum = i - (numMsgsToSend - numConnections); else socknum = rand() % numConnections; - lenBuf = sprintf(buf, "<167>Mar 1 01:00:00 172.20.245.8 tag msgnum:%8.8d:\n", msgNum); + if(MsgToSend == NULL) { + if(dynFileIDs > 0) { + sprintf(dynFileIDBuf, "%d:", rand() % dynFileIDs); + } + if(extraDataLen == 0) { + lenBuf = sprintf(buf, "<%s>Mar 1 01:00:00 172.20.245.8 tag msgnum:%s%8.8d:\n", + msgPRI, dynFileIDBuf, msgNum); + } else { + if(bRandomizeExtraData) + edLen = ((long) rand() + extraDataLen) % extraDataLen + 1; + else + edLen = extraDataLen; + memset(extraData, 'X', edLen); + extraData[edLen] = '\0'; + lenBuf = sprintf(buf, "<%s>Mar 1 01:00:00 172.20.245.8 tag msgnum:%s%8.8d:%d:%s\n", + msgPRI, dynFileIDBuf, msgNum, edLen, extraData); + } + } else { + /* use fixed message format from command line */ + lenBuf = sprintf(buf, "%s\n", MsgToSend); + } lenSend = send(sockArray[socknum], buf, lenBuf, 0); if(lenSend != lenBuf) { printf("\r%5.5d\n", i); @@ -188,11 +246,12 @@ int sendMessages(void) return(1); } if(i % 100 == 0) { - printf("\r%5.5d", i); + if(bShowProgress) + printf("\r%8.8d", i); } ++msgNum; } - printf("\r%5.5d messages sent\n", i); + printf("\r%8.8d messages sent\n", i); return 0; } @@ -251,17 +310,18 @@ tcpSend(char *buf, int lenBuf) } -/* Run the test suite. This must be called with exactly one parameter, the - * name of the test suite. For details, see file header comment at the top - * of this file. +/* Run the test. * rgerhards, 2009-04-03 */ int main(int argc, char *argv[]) { int ret = 0; + int opt; struct sigaction sigAct; static char buf[1024]; + srand(time(NULL)); /* seed is good enough for our needs */ + /* on Solaris, we do not HAVE MSG_NOSIGNAL, so for this reason * we block SIGPIPE (not an issue for this program) */ @@ -271,19 +331,44 @@ int main(int argc, char *argv[]) sigaction(SIGPIPE, &sigAct, NULL); setvbuf(stdout, buf, _IONBF, 48); - - if(argc != 5 && argc != 6) { - printf("Invalid call of tcpflood\n"); - printf("Usage: tcpflood target-host target-port num-connections num-messages [initial msgnum]\n"); - exit(1); - } - targetIP = argv[1]; - targetPort = atoi(argv[2]); - numConnections = atoi(argv[3]); - numMsgsToSend = atoi(argv[4]); - if(argc == 6) - msgNum = atoi(argv[5]); + if(!isatty(1)) + bShowProgress = 0; + + while((opt = getopt(argc, argv, "f:t:p:c:m:i:P:d:n:M:r")) != -1) { + switch (opt) { + case 't': targetIP = optarg; + break; + case 'p': targetPort = atoi(optarg); + break; + case 'n': numTargetPorts = atoi(optarg); + break; + case 'c': numConnections = atoi(optarg); + break; + case 'm': numMsgsToSend = atoi(optarg); + break; + case 'i': msgNum = atoi(optarg); + break; + case 'P': msgPRI = optarg; + break; + case 'd': extraDataLen = atoi(optarg); + if(extraDataLen > MAX_EXTRADATA_LEN) { + fprintf(stderr, "-d max is %d!\n", + MAX_EXTRADATA_LEN); + exit(1); + } + break; + case 'r': bRandomizeExtraData = 1; + break; + case 'f': dynFileIDs = atoi(optarg); + break; + case 'M': MsgToSend = optarg; + break; + default: printf("invalid option '%c' or value missing - terminating...\n", opt); + exit (1); + break; + } + } if(openConnections() != 0) { printf("error opening connections\n"); @@ -295,7 +380,6 @@ int main(int argc, char *argv[]) exit(1); } - //closeConnections(); printf("End of tcpflood Run\n"); exit(ret); diff --git a/tests/testsuites/asynwr_deadlock.conf b/tests/testsuites/asynwr_deadlock.conf new file mode 100644 index 0000000..dc4045b --- /dev/null +++ b/tests/testsuites/asynwr_deadlock.conf @@ -0,0 +1,14 @@ +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%\n" + +$OMFileFlushOnTXEnd on +$OMFileFlushInterval 10 +$OMFileFlushIOBufferSize 10k +$OMFileAsyncWriting on +:msg, contains, "msgnum:" ./rsyslog.out.log;outfmt diff --git a/tests/testsuites/asynwr_deadlock2.conf b/tests/testsuites/asynwr_deadlock2.conf new file mode 100644 index 0000000..0781161 --- /dev/null +++ b/tests/testsuites/asynwr_deadlock2.conf @@ -0,0 +1,16 @@ +# rgerhards, 2010-03-17 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:3%,%msg:F,58:4%,%msg:F,58:5%\n" +$template dynfile,"rsyslog.out.%msg:F,58:2%.log" # use multiple dynafiles + +$OMFileFlushOnTXEnd on +$OMFileFlushInterval 10 +$OMFileIOBufferSize 10k +$OMFileAsyncWriting on +$DynaFileCacheSize 4 +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/asynwr_deadlock4.conf b/tests/testsuites/asynwr_deadlock4.conf new file mode 100644 index 0000000..f4308ff --- /dev/null +++ b/tests/testsuites/asynwr_deadlock4.conf @@ -0,0 +1,16 @@ +# rgerhards, 2010-03-17 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:3%,%msg:F,58:4%,%msg:F,58:5%\n" +$template dynfile,"rsyslog.out.log" # use multiple dynafiles + +$OMFileFlushOnTXEnd on +$OMFileFlushInterval 10 +$OMFileIOBufferSize 10k +$OMFileAsyncWriting on +$DynaFileCacheSize 4 +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/asynwr_simple.conf b/tests/testsuites/asynwr_simple.conf new file mode 100644 index 0000000..44b03f2 --- /dev/null +++ b/tests/testsuites/asynwr_simple.conf @@ -0,0 +1,15 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileFlushInterval 2 +$OMFileFlushIOBufferSize 10k +$OMFileAsyncWriting on +:msg, contains, "msgnum:" ?dynfile;outfmt diff --git a/tests/testsuites/asynwr_small.conf b/tests/testsuites/asynwr_small.conf new file mode 100644 index 0000000..f04ce96 --- /dev/null +++ b/tests/testsuites/asynwr_small.conf @@ -0,0 +1,14 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileFlushInterval 2 +$OMFileAsyncWriting on +:msg, contains, "msgnum:" ?dynfile;outfmt diff --git a/tests/testsuites/asynwr_timeout.conf b/tests/testsuites/asynwr_timeout.conf new file mode 100644 index 0000000..44b03f2 --- /dev/null +++ b/tests/testsuites/asynwr_timeout.conf @@ -0,0 +1,15 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileFlushInterval 2 +$OMFileFlushIOBufferSize 10k +$OMFileAsyncWriting on +:msg, contains, "msgnum:" ?dynfile;outfmt diff --git a/tests/testsuites/asynwr_tinybuf.conf b/tests/testsuites/asynwr_tinybuf.conf new file mode 100644 index 0000000..01dec4d --- /dev/null +++ b/tests/testsuites/asynwr_tinybuf.conf @@ -0,0 +1,15 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileFlushInterval 2 +$OMFileIOBufferSize 1 +$OMFileAsyncWriting on +:msg, contains, "msgnum:" ?dynfile;outfmt diff --git a/tests/testsuites/complex1.conf b/tests/testsuites/complex1.conf new file mode 100644 index 0000000..9e2441d --- /dev/null +++ b/tests/testsuites/complex1.conf @@ -0,0 +1,81 @@ +# complex test case with multiple actions in gzip mode +# rgerhards, 2009-05-22 +$MaxMessageSize 10k +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 + +$template outfmt,"%msg:F,58:3%,%msg:F,58:4%,%msg:F,58:5%\n" +$template dynfile,"rsyslog.out.%inputname%.%msg:F,58:2%.log" + +## RULESET with listener +$Ruleset R13514 +# queue params: +$ActionQueueTimeoutShutdown 60000 +$ActionQueueSize 5000 +$ActionQueueSaveOnShutdown on +$ActionQueueHighWaterMark 4900 +$ActionQueueLowWaterMark 3500 +$ActionQueueType FixedArray +$ActionQueueWorkerThreads 1 +# action params: +$OMFileFlushOnTXEnd off +$OMFileZipLevel 6 +#$OMFileIOBufferSize 256k +$DynaFileCacheSize 4 +$omfileFlushInterval 1 +*.* ?dynfile;outfmt +# listener +$InputTCPServerInputName 13514 +$InputTCPServerBindRuleset R13514 +$InputTCPServerRun 13514 + + +## RULESET with listener +$Ruleset R13515 +# queue params: +$ActionQueueTimeoutShutdown 60000 +$ActionQueueSize 5000 +$ActionQueueSaveOnShutdown on +$ActionQueueHighWaterMark 4900 +$ActionQueueLowWaterMark 3500 +$ActionQueueType FixedArray +$ActionQueueWorkerThreads 1 +# action params: +$OMFileFlushOnTXEnd off +$OMFileZipLevel 6 +$OMFileIOBufferSize 256k +$DynaFileCacheSize 4 +$omfileFlushInterval 1 +*.* ?dynfile;outfmt +# listener +$InputTCPServerInputName 13515 +$InputTCPServerBindRuleset R13515 +$InputTCPServerRun 13515 + + + +## RULESET with listener +$Ruleset R13516 +# queue params: +$ActionQueueTimeoutShutdown 60000 +$ActionQueueSize 5000 +$ActionQueueSaveOnShutdown on +$ActionQueueHighWaterMark 4900 +$ActionQueueLowWaterMark 3500 +$ActionQueueType FixedArray +$ActionQueueWorkerThreads 1 +# action params: +$OMFileFlushOnTXEnd off +$OMFileZipLevel 6 +$OMFileIOBufferSize 256k +$DynaFileCacheSize 4 +$omfileFlushInterval 1 +*.* ?dynfile;outfmt +# listener +$InputTCPServerInputName 13516 +$InputTCPServerBindRuleset R13516 +$InputTCPServerRun 13516 + + diff --git a/tests/testsuites/dynfile_cachemiss.conf b/tests/testsuites/dynfile_cachemiss.conf new file mode 100644 index 0000000..273ff17 --- /dev/null +++ b/tests/testsuites/dynfile_cachemiss.conf @@ -0,0 +1,14 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:3%\n" +$template dynfile,"%msg:F,58:2%.log" # complete name is in message +$OMFileFlushOnTXEnd on +$DynaFileCacheSize 4 +$IncludeConfig rsyslog.action.1.include +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/dynfile_invalid2.conf b/tests/testsuites/dynfile_invalid2.conf new file mode 100644 index 0000000..6d94c40 --- /dev/null +++ b/tests/testsuites/dynfile_invalid2.conf @@ -0,0 +1,14 @@ +# simple async writing test +# rgerhards, 2010-03-22 +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:3%\n" +$template dynfile,"%msg:F,58:2%.log" # complete name is in message +$OMFileFlushOnTXEnd off +$DynaFileCacheSize 4 +$omfileFlushInterval 1 +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/gzipwr_large.conf b/tests/testsuites/gzipwr_large.conf new file mode 100644 index 0000000..54ad3bb --- /dev/null +++ b/tests/testsuites/gzipwr_large.conf @@ -0,0 +1,15 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$MaxMessageSize 10k +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%,%msg:F,58:3%,%msg:F,58:4%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileZipLevel 6 +$OMFileIOBufferSize 256k +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/gzipwr_large_dynfile.conf b/tests/testsuites/gzipwr_large_dynfile.conf new file mode 100644 index 0000000..3a1b255 --- /dev/null +++ b/tests/testsuites/gzipwr_large_dynfile.conf @@ -0,0 +1,17 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$MaxMessageSize 10k +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:3%,%msg:F,58:4%,%msg:F,58:5%\n" +$template dynfile,"rsyslog.out.%msg:F,58:2%.log" # use multiple dynafiles +$OMFileFlushOnTXEnd off +$OMFileZipLevel 6 +$OMFileIOBufferSize 256k +$DynaFileCacheSize 4 +$omfileFlushInterval 1 +local0.* ?dynfile;outfmt diff --git a/tests/testsuites/parse-3164-buggyday.conf b/tests/testsuites/parse-3164-buggyday.conf new file mode 100644 index 0000000..937f423 --- /dev/null +++ b/tests/testsuites/parse-3164-buggyday.conf @@ -0,0 +1,8 @@ +$ModLoad ../plugins/omstdout/.libs/omstdout +$IncludeConfig nettest.input.conf # This picks the to be tested input from the test driver! + +$ErrorMessagesToStderr off + +# use a special format that we can easily parse in expect +$template expect,"%PRI%,%syslogfacility-text%,%syslogseverity-text%,%timestamp:::date-rfc3164-buggyday%,%hostname%,%programname%,%syslogtag%,%msg%\n" +*.* :omstdout:;expect diff --git a/tests/testsuites/parse-nodate.conf b/tests/testsuites/parse-nodate.conf new file mode 100644 index 0000000..570638d --- /dev/null +++ b/tests/testsuites/parse-nodate.conf @@ -0,0 +1,14 @@ +# test is a test config that does not include the timestamp. This is necessary to +# test some illformed messages that do not contain a date. In that case, the system's +# current timestamp is used, and that of course is a bit hard to compare against +# a fixed template. So the solution in this case is to use a format that does +# not contain any timestamp. Maybe not optimal, but it works ;) +# rgerhards, 2010-03-19 +$ModLoad ../plugins/omstdout/.libs/omstdout +$IncludeConfig nettest.input.conf # This picks the to be tested input from the test driver! + +$ErrorMessagesToStderr off + +# use a special format that we can easily parse +$template fmt,"%PRI%,%syslogfacility-text%,%syslogseverity-text%,%hostname%,%programname%,%syslogtag%,%msg%\n" +*.* :omstdout:;fmt diff --git a/tests/testsuites/samples.parse-3164-buggyday b/tests/testsuites/samples.parse-3164-buggyday new file mode 100644 index 0000000..e21df98 --- /dev/null +++ b/tests/testsuites/samples.parse-3164-buggyday @@ -0,0 +1,6 @@ +# in 3164-buggyday mode, we need to have a leading zero in front of the day +<38> Mar 7 19:06:53 example tag: testmessage (only date actually tested) +38,auth,info,Mar 07 19:06:53,example,tag,tag:, testmessage (only date actually tested) +# and now one with a complete date: +<38> Mar 17 19:06:53 example tag: testmessage (only date actually tested) +38,auth,info,Mar 17 19:06:53,example,tag,tag:, testmessage (only date actually tested) diff --git a/tests/testsuites/samples.snare_ccoff_udp b/tests/testsuites/samples.snare_ccoff_udp new file mode 100644 index 0000000..010e44d --- /dev/null +++ b/tests/testsuites/samples.snare_ccoff_udp @@ -0,0 +1,14 @@ +# see comments in snare_ccoff_udp.conf +# note that some of these samples look pretty wild, but they are +# *real* cases (just mangled to anonymize them...) +# Sample 1 - note the absence of PRI! +windowsserver MSWinEventLog 1 Security 1167 Fri Mar 19 15:33:30 2010 540 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Successful Network Logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {79b6eb79-7bcc-8a2e-7dad-953c51dc00fd} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 10.11.11.3 Source Port: 3306 733\n +13,user,notice,localhost,windowsserver,windowsserver MSWinEventLog 1 Security 1167 Fri, Mar 19 15:33:30 2010 540 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Successful Network Logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {79b6eb79-7bcc-8a2e-7dad-953c51dc00fd} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 10.11.11.3 Source Port: 3306 733 +# Sample 2 +# the samples below need to be disabled for the "workaround patch" for the message +# parser to work. They need to be re-enabled once a final solution has been crafted +#windowsserver MSWinEventLog 1 Security 1166 Fri Mar 19 15:33:30 2010 576 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Special privileges assigned to new logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Privileges: SeSecurityPrivilege SeBackupPrivilege SeRestorePrivilege SeTakeOwnershipPrivilege SeDebugPrivilege SeSystemEnvironmentPrivilege SeLoadDriverPrivilege SeImpersonatePrivilege SeEnableDelegationPrivilege 732\n +#13,user,notice,localhost,windowsserver,windowsserver MSWinEventLog 1 Security 1166 Fri, Mar 19 15:33:30 2010 576 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Special privileges assigned to new logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Privileges: SeSecurityPrivilege SeBackupPrivilege SeRestorePrivilege SeTakeOwnershipPrivilege SeDebugPrivilege SeSystemEnvironmentPrivilege SeLoadDriverPrivilege SeImpersonatePrivilege SeEnableDelegationPrivilege 732 +# Sample 3 +#windowsserver MSWinEventLog 1 Security 1165 Fri Mar 19 15:33:30 2010 538 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff User Logoff: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF8830B) Logon Type: 3 731\n +#13,user,notice,localhost,windowsserver,windowsserver MSWinEventLog 1 Security 1165 Fri, Mar 19 15:33:30 2010 538 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff User Logoff: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF8830B) Logon Type: 3 731 diff --git a/tests/testsuites/samples.snare_ccoff_udp2 b/tests/testsuites/samples.snare_ccoff_udp2 new file mode 100644 index 0000000..7837b82 --- /dev/null +++ b/tests/testsuites/samples.snare_ccoff_udp2 @@ -0,0 +1,22 @@ +# see comments in snare_ccoff_udp.conf +# note that some of these samples look pretty wild, but they are +# *real* cases (just mangled to anonymize them...) +# +# NOTE +# The current responses are probably not correct (handling of messages without PRI). +# However, we keep them inside the test to be consistent. We should look at how +# PRI-less messages are handled and once we have fixed that, the test cases may need +# to be adapted. We do NOT try to preserve misbehaviour on such seriously malformed +# messages. +# +# Sample 1 - note the absence of PRI! +windowsserver MSWinEventLog 1 Security 1167 Fri Mar 19 15:33:30 2010 540 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Successful Network Logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {79b6eb79-7bcc-8a2e-7dad-953c51dc00fd} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 10.11.11.3 Source Port: 3306 733\n +insert into windows (Message, Facility,FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (' Mar 19 15:33:30 2010 540 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Successful Network Logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {79b6eb79-7bcc-8a2e-7dad-953c51dc00fd} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 10.11.11.3 Source Port: 3306 733 ', 1, 'localhost',5, '20100321185328', '20100321185328', 1, 'windowsserver MSWinEventLog 1 Security 1167 Fri') +# Sample 2 +# the samples below need to be disabled for the "workaround patch" for the message +# parser to work. They need to be re-enabled once a final solution has been crafted +#windowsserver MSWinEventLog 1 Security 1166 Fri Mar 19 15:33:30 2010 576 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Special privileges assigned to new logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Privileges: SeSecurityPrivilege SeBackupPrivilege SeRestorePrivilege SeTakeOwnershipPrivilege SeDebugPrivilege SeSystemEnvironmentPrivilege SeLoadDriverPrivilege SeImpersonatePrivilege SeEnableDelegationPrivilege 732\n +#insert into windows (Message, Facility,FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (' Mar 19 15:33:30 2010 576 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff Special privileges assigned to new logon: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF88396) Privileges: SeSecurityPrivilege SeBackupPrivilege SeRestorePrivilege SeTakeOwnershipPrivilege SeDebugPrivilege SeSystemEnvironmentPrivilege SeLoadDriverPrivilege SeImpersonatePrivilege SeEnableDelegationPrivilege 732', 1, 'localhost',5, '20100321185328', '20100321185328', 1, 'windowsserver MSWinEventLog 1 Security 1166 Fri') +# Sample 3 +#windowsserver MSWinEventLog 1 Security 1165 Fri Mar 19 15:33:30 2010 538 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff User Logoff: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF8830B) Logon Type: 3 731\n +#insert into windows (Message, Facility,FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (' Mar 19 15:33:30 2010 538 Security SYSTEM User Success Audit WINDOWSSERVER Logon/Logoff User Logoff: User Name: WINDOWSSERVER$ Domain: DOMX Logon ID: (0x0,0xF8830B) Logon Type: 3 731', 1, 'localhost',5, '20100321185328', '20100321185328', 1, 'windowsserver MSWinEventLog 1 Security 1165 Fri') diff --git a/tests/testsuites/snare.parse1 b/tests/testsuites/snare.parse1 new file mode 100644 index 0000000..550b070 --- /dev/null +++ b/tests/testsuites/snare.parse1 @@ -0,0 +1,83 @@ +# some parse test build around data in snare-format +<141>Mar 10 09:30:20 zuse.xysystems.local MSWinEventLog\0111\011Security\011563\011Wed Mar 10 09:30:15 2010\011538\011Security\011XYWS011$\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: XYWS011$ Domain: XYZSYSTEMS Logon ID: (0x0,0x5984789C) Logon Type: 3 \011552 +141,local1,notice,Mar 10 09:30:20,zuse.xysystems.local,MSWinEventLog#0111#011Security#011563#011Wed,MSWinEventLog#0111#011Security#011563#011Wed, Mar 10 09:30:15 2010#011538#011Security#011XYWS011$#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: XYWS011$ Domain: XYZSYSTEMS Logon ID: (0x0,0x5984789C) Logon Type: 3 #011552 +# +# NEXT MESSAGE +# +Mar 10 09:30:20 zuse.xysystems.local MSWinEventLog\0111\011Security\011564\011Wed Mar 10 09:30:19 2010\011540\011Security\011BACKUP1$\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: BACKUP1$ Domain: XYZSYSTEMS Logon ID: (0x0,0x59848DB4) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {f6f65903-1932-d229-4b75-64816121d569} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.31 Source Port: 0 \011553 +13,user,notice,Mar 10 09:30:20,zuse.xysystems.local,MSWinEventLog#0111#011Security#011564#011Wed,MSWinEventLog#0111#011Security#011564#011Wed, Mar 10 09:30:19 2010#011540#011Security#011BACKUP1$#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: BACKUP1$ Domain: XYZSYSTEMS Logon ID: (0x0,0x59848DB4) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {f6f65903-1932-d229-4b75-64816121d569} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.31 Source Port: 0 #011553 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011566\011Wed Mar 10 09:30:21 2010\011540\011Security\011aadminps\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: aadminps Domain: XYSYSTEMS Logon ID: (0x0,0x5984973C) Logon Type: 3 Logon Process: Authz Authentication Package: Kerberos Workstation Name: ZUSE Logon GUID: - Caller User Name: ZUSE$ Caller Domain: XYSYSTEMS Caller Logon ID: (0x0,0x3E7) Caller Process ID: 1004 Transited Services: - Source Network Address: - Source Port: - \011555 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011566#011Wed,MSWinEventLog#0111#011Security#011566#011Wed, Mar 10 09:30:21 2010#011540#011Security#011aadminps#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: aadminps Domain: XYSYSTEMS Logon ID: (0x0,0x5984973C) Logon Type: 3 Logon Process: Authz Authentication Package: Kerberos Workstation Name: ZUSE Logon GUID: - Caller User Name: ZUSE$ Caller Domain: XYSYSTEMS Caller Logon ID: (0x0,0x3E7) Caller Process ID: 1004 Transited Services: - Source Network Address: - Source Port: - #011555 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011567\011Wed Mar 10 09:30:21 2010\011538\011Security\011aadminps\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: aadminps Domain: XYSYSTEMS Logon ID: (0x0,0x5984973C) Logon Type: 3 \011556 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011567#011Wed,MSWinEventLog#0111#011Security#011567#011Wed, Mar 10 09:30:21 2010#011538#011Security#011aadminps#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: aadminps Domain: XYSYSTEMS Logon ID: (0x0,0x5984973C) Logon Type: 3 #011556 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011568\011Wed Mar 10 09:30:25 2010\011540\011Security\011ANONYMOUS LOGON\011Well Known Group\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: Domain: Logon ID: (0x0,0x5984AB6F) Logon Type: 3 Logon Process: NtLmSsp Authentication Package: NTLM Workstation Name: XYWS083 Logon GUID: - Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.91 Source Port: 0 \011557 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011568#011Wed,MSWinEventLog#0111#011Security#011568#011Wed, Mar 10 09:30:25 2010#011540#011Security#011ANONYMOUS LOGON#011Well Known Group#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: Domain: Logon ID: (0x0,0x5984AB6F) Logon Type: 3 Logon Process: NtLmSsp Authentication Package: NTLM Workstation Name: XYWS083 Logon GUID: - Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.91 Source Port: 0 #011557 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011569\011Wed Mar 10 09:30:25 2010\011540\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984ACA7) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2318 \011558 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011569#011Wed,MSWinEventLog#0111#011Security#011569#011Wed, Mar 10 09:30:25 2010#011540#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984ACA7) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2318 #011558 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011570\011Wed Mar 10 09:30:25 2010\011538\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984ACA7) Logon Type: 3 \011559 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011570#011Wed,MSWinEventLog#0111#011Security#011570#011Wed, Mar 10 09:30:25 2010#011538#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984ACA7) Logon Type: 3 #011559 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011571\011Wed Mar 10 09:30:25 2010\011540\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AD7C) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2319 \011560\ +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011571#011Wed,MSWinEventLog#0111#011Security#011571#011Wed, Mar 10 09:30:25 2010#011540#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AD7C) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2319 #011560 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011572\011Wed Mar 10 09:30:25 2010\011538\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AD7C) Logon Type: 3 \011561 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011572#011Wed,MSWinEventLog#0111#011Security#011572#011Wed, Mar 10 09:30:25 2010#011538#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AD7C) Logon Type: 3 #011561 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011573\011Wed Mar 10 09:30:25 2010\011680\011Security\011ettore.trezzani\011User\011Success Audit\011ZUSE\011Account Logon\011\011Logon attempt by: MICROSOFT_AUTHENTICATION_PACKAGE_V1_0 Logon account: ettore.trezzani Source Workstation: XYWS083 Error Code: 0x0 \011562 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011573#011Wed,MSWinEventLog#0111#011Security#011573#011Wed, Mar 10 09:30:25 2010#011680#011Security#011ettore.trezzani#011User#011Success Audit#011ZUSE#011Account Logon#011#011Logon attempt by: MICROSOFT_AUTHENTICATION_PACKAGE_V1_0 Logon account: ettore.trezzani Source Workstation: XYWS083 Error Code: 0x0 #011562 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011574\011Wed Mar 10 09:30:25 2010\011540\011Security\011ettore.trezzani\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: ettore.trezzani Domain: XYSYSTEMS Logon ID: (0x0,0x5984ADD5) Logon Type: 3 Logon Process: NtLmSsp Authentication Package: NTLM Workstation Name: XYWS083 Logon GUID: - Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.91 Source Port: 0 \011563 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011574#011Wed,MSWinEventLog#0111#011Security#011574#011Wed, Mar 10 09:30:25 2010#011540#011Security#011ettore.trezzani#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: ettore.trezzani Domain: XYSYSTEMS Logon ID: (0x0,0x5984ADD5) Logon Type: 3 Logon Process: NtLmSsp Authentication Package: NTLM Workstation Name: XYWS083 Logon GUID: - Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.91 Source Port: 0 #011563 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011575\011Wed Mar 10 09:30:25 2010\011540\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AE49) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2320 \011564 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011575#011Wed,MSWinEventLog#0111#011Security#011575#011Wed, Mar 10 09:30:25 2010#011540#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AE49) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2320 #011564 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011576\011Wed Mar 10 09:30:25 2010\011538\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AE49) Logon Type: 3 \011565 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011576#011Wed,MSWinEventLog#0111#011Security#011576#011Wed, Mar 10 09:30:25 2010#011538#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AE49) Logon Type: 3 #011565 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011577\011Wed Mar 10 09:30:25 2010\011540\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AF00) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2321 \011566 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011577#011Wed,MSWinEventLog#0111#011Security#011577#011Wed, Mar 10 09:30:25 2010#011540#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AF00) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {20014d9a-ce6c-6834-d1ed-607c08f0b6a7} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.0.15 Source Port: 2321 #011566 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011578\011Wed Mar 10 09:30:25 2010\011538\011Security\011SYSTEM\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AF00) Logon Type: 3 \011567 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011578#011Wed,MSWinEventLog#0111#011Security#011578#011Wed, Mar 10 09:30:25 2010#011538#011Security#011SYSTEM#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: ZUSE$ Domain: XYSYSTEMS Logon ID: (0x0,0x5984AF00) Logon Type: 3 #011567 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:25 zuse.xysystems.local MSWinEventLog\0111\011Security\011579\011Wed Mar 10 09:30:25 2010\011538\011Security\011ANONYMOUS LOGON\011Well Known Group\011Success Audit\011ZUSE\011Logon/Logoff\011\011User Logoff: User Name: ANONYMOUS LOGON Domain: NT AUTHORITY Logon ID: (0x0,0x5984AB6F) Logon Type: 3 \011568 +141,local1,notice,Mar 10 09:30:25,zuse.xysystems.local,MSWinEventLog#0111#011Security#011579#011Wed,MSWinEventLog#0111#011Security#011579#011Wed, Mar 10 09:30:25 2010#011538#011Security#011ANONYMOUS LOGON#011Well Known Group#011Success Audit#011ZUSE#011Logon/Logoff#011#011User Logoff: User Name: ANONYMOUS LOGON Domain: NT AUTHORITY Logon ID: (0x0,0x5984AB6F) Logon Type: 3 #011568 +# +# NEXT MESSAGE +# +<141>Mar 10 09:30:30 zuse.xysystems.local MSWinEventLog\0111\011Security\011580\011Wed Mar 10 09:30:29 2010\011540\011Security\011XYWSBADGE$\011User\011Success Audit\011ZUSE\011Logon/Logoff\011\011Successful Network Logon: User Name: XYWSBADGE$ Domain: XYSYSTEMS Logon ID: (0x0,0x59852D73) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {4bc3c075-5a77-4648-5822-bfdf88b4c211} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.18 Source Port: 0 \011569 +141,local1,notice,Mar 10 09:30:30,zuse.xysystems.local,MSWinEventLog#0111#011Security#011580#011Wed,MSWinEventLog#0111#011Security#011580#011Wed, Mar 10 09:30:29 2010#011540#011Security#011XYWSBADGE$#011User#011Success Audit#011ZUSE#011Logon/Logoff#011#011Successful Network Logon: User Name: XYWSBADGE$ Domain: XYSYSTEMS Logon ID: (0x0,0x59852D73) Logon Type: 3 Logon Process: Kerberos Authentication Package: Kerberos Workstation Name: Logon GUID: {4bc3c075-5a77-4648-5822-bfdf88b4c211} Caller User Name: - Caller Domain: - Caller Logon ID: - Caller Process ID: - Transited Services: - Source Network Address: 172.16.3.18 Source Port: 0 #011569 diff --git a/tests/testsuites/snare_ccoff_udp.conf b/tests/testsuites/snare_ccoff_udp.conf new file mode 100644 index 0000000..6abbedf --- /dev/null +++ b/tests/testsuites/snare_ccoff_udp.conf @@ -0,0 +1,21 @@ +# This test some real-world snare cases. I don't like snare (no wonder +# as I have written EventReporter, the ultimate Windows-to-Syslog tool), +# but besides that snare generates severely malformed messages that +# really stress-test the rsyslog engine. They deserve to be beaten by someone ;) +# This test needs to be run over UDP only, as snare puts LF INTO some of the messages, +# which makes it impossible to try these out via traditional syslog/tcp +# added 2010-03-21 rgerhards +$ModLoad ../plugins/omstdout/.libs/omstdout +$IncludeConfig nettest.input.conf # This picks the to be tested input from the test driver! + +$ErrorMessagesToStderr off + +# snare usses HT as field delimiter, so many users have turned off +# control character escaping to make any sense at all from these messages... +$EscapeControlCharactersOnReceive off + +# use a special format that we can easily check. We do NOT include a timestamp because +# the malformed snare messages usually do not contain one (and we can not check against +# the system time in our test cases). +$template fmt,"%PRI%,%syslogfacility-text%,%syslogseverity-text%,%hostname%,%programname%,%syslogtag%,%msg%\n" +*.* :omstdout:;fmt diff --git a/tests/testsuites/snare_ccoff_udp2.conf b/tests/testsuites/snare_ccoff_udp2.conf new file mode 100644 index 0000000..9115c14 --- /dev/null +++ b/tests/testsuites/snare_ccoff_udp2.conf @@ -0,0 +1,17 @@ +# Similar to snare_ccoff_udp_2, but with a different template. This template +# has triggered problems in the past, thus a test is granted. +# added 2010-03-21 rgerhards +$ModLoad ../plugins/omstdout/.libs/omstdout +$IncludeConfig nettest.input.conf # This picks the to be tested input from the test driver! + +$ErrorMessagesToStderr off + +# snare usses HT as field delimiter, so many users have turned off +# control character escaping to make any sense at all from these messages... +$EscapeControlCharactersOnReceive off + +# we need to use a fixed timestamp, as otherwise we can not compare :( +# This could be improved in later versions of the testing tools, but requires +# modification to the rsyslog core... +$template fmt,"insert into windows (Message, Facility,FromHost, Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values ('%msg:::space-cc%', %syslogfacility%, '%HOSTNAME%',%syslogpriority%, '20100321185328', '20100321185328', %iut%, '%syslogtag:::space-cc%')\n",sql +*.* :omstdout:;fmt diff --git a/tests/testsuites/wr_large.conf b/tests/testsuites/wr_large.conf new file mode 100644 index 0000000..b64f132 --- /dev/null +++ b/tests/testsuites/wr_large.conf @@ -0,0 +1,16 @@ +# simple async writing test +# rgerhards, 2010-03-09 +$MaxMessageSize 10k +$IncludeConfig diag-common.conf + +$ModLoad ../plugins/imtcp/.libs/imtcp +$MainMsgQueueTimeoutShutdown 10000 +$InputTCPServerRun 13514 + +$template outfmt,"%msg:F,58:2%,%msg:F,58:3%,%msg:F,58:4%\n" +$template dynfile,"rsyslog.out.log" # trick to use relative path names! +$OMFileFlushOnTXEnd off +$OMFileFlushInterval 2 +$OMFileIOBufferSize 256k +$IncludeConfig rsyslog.action.1.include +local0.* ?dynfile;outfmt diff --git a/tests/threadingmqaq.sh b/tests/threadingmqaq.sh index 9f2ea79..b776482 100755 --- a/tests/threadingmqaq.sh +++ b/tests/threadingmqaq.sh @@ -9,7 +9,7 @@ echo TEST: threadingmqaq.sh - main/action queue concurrency source $srcdir/diag.sh init source $srcdir/diag.sh startup threadingmqaq.conf -#source $srcdir/diag.sh tcpflood 127.0.0.1 13514 2 100000 +#source $srcdir/diag.sh tcpflood -c2 -m100000 #source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages source $srcdir/diag.sh injectmsg 0 100000 source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages diff --git a/tests/wr_large.sh b/tests/wr_large.sh new file mode 100755 index 0000000..84f1298 --- /dev/null +++ b/tests/wr_large.sh @@ -0,0 +1,16 @@ +# This tests async writing large data records. We use up to 10K +# record size. + +# added 2010-03-10 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +cat rsyslog.action.1.include +source $srcdir/diag.sh init +source $srcdir/diag.sh startup wr_large.conf +# send 4000 messages of 10.000bytes plus header max, randomized +source $srcdir/diag.sh tcpflood -m4000 -r -d10000 -P129 +sleep 1 # due to large messages, we need this time for the tcp receiver to settle... +source $srcdir/diag.sh shutdown-when-empty # shut down rsyslogd when done processing messages +source $srcdir/diag.sh wait-shutdown # and wait for it to terminate +source $srcdir/diag.sh seq-check 0 3999 -E +source $srcdir/diag.sh exit diff --git a/tests/wr_large_async.sh b/tests/wr_large_async.sh new file mode 100755 index 0000000..88a1acf --- /dev/null +++ b/tests/wr_large_async.sh @@ -0,0 +1,14 @@ +# This tests async writing large data records. We use up to 10K +# record size. + +# added 2010-03-10 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[wr_large_async.sh\]: test for file writing for large message sets +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +echo "\$OMFileAsyncWriting on" > rsyslog.action.1.include +source $srcdir/wr_large.sh diff --git a/tests/wr_large_sync.sh b/tests/wr_large_sync.sh new file mode 100755 index 0000000..a1c4fd7 --- /dev/null +++ b/tests/wr_large_sync.sh @@ -0,0 +1,14 @@ +# This tests async writing large data records. We use up to 10K +# record size. + +# added 2010-03-10 by Rgerhards +# +# This file is part of the rsyslog project, released under GPLv3 +echo =============================================================================== +echo TEST: \[wr_large_sync.sh\]: test for file writing for large message sets +source $srcdir/diag.sh init +# uncomment for debugging support: +#export RSYSLOG_DEBUG="debug nostdout noprintmutexaction" +#export RSYSLOG_DEBUGLOG="log" +echo "\$OMFileAsyncWriting off" > rsyslog.action.1.include +source $srcdir/wr_large.sh diff --git a/tools/omfile.c b/tools/omfile.c index eb56201..0f47600 100644 --- a/tools/omfile.c +++ b/tools/omfile.c @@ -79,13 +79,14 @@ DEFobjCurrIf(strm) struct s_dynaFileCacheEntry { uchar *pName; /* name currently open, if dynamic name */ strm_t *pStrm; /* our output stream */ - time_t lastUsed; /* for LRU - last access */ // TODO: perforamcne change to counter (see other comment!) + time_t lastUsed; /* for LRU - last access */ }; typedef struct s_dynaFileCacheEntry dynaFileCacheEntry; #define IOBUF_DFLT_SIZE 1024 /* default size for io buffers */ #define FLUSH_INTRVL_DFLT 1 /* default buffer flush interval (in seconds) */ +#define USE_ASYNCWRITER_DFLT 0 /* default buffer use async writer */ /* globals for default values */ static int iDynaFileCacheSize = 10; /* max cache for dynamic files */ @@ -99,9 +100,10 @@ static uid_t dirGID; /* GID to be used for newly created directories */ static int bCreateDirs = 1;/* auto-create directories for dynaFiles: 0 - no, 1 - yes */ static int bEnableSync = 0;/* enable syncing of files (no dash in front of pathname in conf): 0 - no, 1 - yes */ static int iZipLevel = 0; /* zip compression mode (0..9 as usual) */ -static bool bFlushOnTXEnd = 1;/* flush write buffers when transaction has ended? */ +static bool bFlushOnTXEnd = 0;/* flush write buffers when transaction has ended? */ static int64 iIOBufSize = IOBUF_DFLT_SIZE; /* size of an io buffer */ static int iFlushInterval = FLUSH_INTRVL_DFLT; /* how often flush the output buffer on inactivity? */ +static int bUseAsyncWriter = USE_ASYNCWRITER_DFLT; /* should we enable asynchronous writing? */ uchar *pszFileDfltTplName = NULL; /* name of the default template to use */ /* end globals for default values */ @@ -134,6 +136,7 @@ typedef struct _instanceData { int iIOBufSize; /* size of associated io buffer */ int iFlushInterval; /* how fast flush buffer on inactivity? */ bool bFlushOnTXEnd; /* flush write buffers when transaction has ended? */ + bool bUseAsyncWriter; /* use async stream writer? */ } instanceData; @@ -147,26 +150,23 @@ ENDisCompatibleWithFeature BEGINdbgPrintInstInfo CODESTARTdbgPrintInstInfo if(pData->bDynamicName) { - dbgprintf("[dynamic]\n\ttemplate='%s'" - "\tfile cache size=%d\n" - "\tcreate directories: %s\n" - "\tfile owner %d, group %d\n" - "\tdirectory owner %d, group %d\n" - "\tdir create mode 0%3.3o, file create mode 0%3.3o\n" - "\tfail if owner/group can not be set: %s\n", - pData->f_fname, - pData->iDynaFileCacheSize, - pData->bCreateDirs ? "yes" : "no", - pData->fileUID, pData->fileGID, - pData->dirUID, pData->dirGID, - pData->fDirCreateMode, pData->fCreateMode, - pData->bFailOnChown ? "yes" : "no" - ); + dbgprintf("[dynamic]\n"); } else { /* regular file */ - dbgprintf("%s", pData->f_fname); - if (pData->pStrm == NULL) - dbgprintf(" (unused)"); + dbgprintf("%s%s\n", pData->f_fname, + (pData->pStrm == NULL) ? " (unused)" : ""); } + + dbgprintf("\ttemplate='%s'\n", pData->f_fname); + dbgprintf("\tuse async writer=%d\n", pData->bUseAsyncWriter); + dbgprintf("\tflush on TX end=%d\n", pData->bFlushOnTXEnd); + dbgprintf("\tflush interval=%d\n", pData->iFlushInterval); + dbgprintf("\tfile cache size=%d\n", pData->iDynaFileCacheSize); + dbgprintf("\tcreate directories: %s\n", pData->bCreateDirs ? "yes" : "no"); + dbgprintf("\tfile owner %d, group %d\n", pData->fileUID, pData->fileGID); + dbgprintf("\tdirectory owner %d, group %d\n", pData->dirUID, pData->dirGID); + dbgprintf("\tdir create mode 0%3.3o, file create mode 0%3.3o\n", + pData->fDirCreateMode, pData->fCreateMode); + dbgprintf("\tfail if owner/group can not be set: %s\n", pData->bFailOnChown ? "yes" : "no"); ENDdbgPrintInstInfo @@ -283,17 +283,18 @@ dynaFileDelCacheEntry(dynaFileCacheEntry **pCache, int iEntry, int bFreeEntry) DBGPRINTF("Removed entry %d for file '%s' from dynaCache.\n", iEntry, pCache[iEntry]->pName == NULL ? UCHAR_CONSTANT("[OPEN FAILED]") : pCache[iEntry]->pName); - /* if the name is NULL, this is an improperly initilized entry which - * needs to be discarded. In this case, neither the file is to be closed - * not the name to be freed. - */ + if(pCache[iEntry]->pName != NULL) { - if(pCache[iEntry]->pStrm != NULL) - strm.Destruct(&pCache[iEntry]->pStrm); d_free(pCache[iEntry]->pName); pCache[iEntry]->pName = NULL; } + if(pCache[iEntry]->pStrm != NULL) { + strm.Destruct(&pCache[iEntry]->pStrm); + if(pCache[iEntry]->pStrm != NULL) /* safety check -- TODO: remove if no longer necessary */ + abort(); + } + if(bFreeEntry) { d_free(pCache[iEntry]); pCache[iEntry] = NULL; @@ -413,7 +414,7 @@ prepareFile(instanceData *pData, uchar *newFileName) * async processing, which is a real performance waste if we do not do buffered * writes! -- rgerhards, 2009-07-06 */ - if(!pData->bFlushOnTXEnd) + if(pData->bUseAsyncWriter) CHKiRet(strm.SetiFlushInterval(pData->pStrm, pData->iFlushInterval)); if(pData->pszSizeLimitCmd != NULL) CHKiRet(strm.SetpszSizeLimitCmd(pData->pStrm, ustrdup(pData->pszSizeLimitCmd))); @@ -467,11 +468,11 @@ prepareDynFile(instanceData *pData, uchar *newFileName, unsigned iMsgOpts) iOldest = 0; /* we assume the first element to be the oldest - that will change as we loop */ ttOldest = time(NULL) + 1; /* there must always be an older one */ for(i = 0 ; i < pData->iCurrCacheSize ; ++i) { - if(pCache[i] == NULL) { + if(pCache[i] == NULL || pCache[i]->pName == NULL) { if(iFirstFree == -1) iFirstFree = i; } else { /* got an element, let's see if it matches */ - if(!ustrcmp(newFileName, pCache[i]->pName)) { + if(!ustrcmp(newFileName, pCache[i]->pName)) { // RG: name == NULL? /* we found our element! */ pData->pStrm = pCache[i]->pStrm; pData->iCurrElt = i; @@ -494,24 +495,38 @@ prepareDynFile(instanceData *pData, uchar *newFileName, unsigned iMsgOpts) * is error-prone, so I prefer to do it here. -- rgerhards, 2010-03-02 */ pData->iCurrElt = -1; + /* similarly, we need to set the current pStrm to NULL, because otherwise, if prepareFile() fails, + * we may end up using an old stream. This bug depends on how exactly prepareFile fails, + * but it* could be triggered in the common case of a failed open() system call. + * rgerhards, 2010-03-22 + */ + pData->pStrm = NULL; if(iFirstFree == -1 && (pData->iCurrCacheSize < pData->iDynaFileCacheSize)) { /* there is space left, so set it to that index */ iFirstFree = pData->iCurrCacheSize++; } +// RG: this is the begin of a potential problem area + /* Note that the following code sequence does not work with the cache entry itself, + * but rather with pData->pStrm, the (sole) stream pointer in the non-dynafile case. + * The cache array is only updated after the open was successful. -- rgerhards, 2010-03-21 + */ if(iFirstFree == -1) { dynaFileDelCacheEntry(pCache, iOldest, 0); iFirstFree = iOldest; /* this one *is* now free ;) */ } else { /* we need to allocate memory for the cache structure */ + /* TODO: performance note: we could alloc all entries on startup, thus saving malloc + * overhead -- this may be something to consider in v5... + */ CHKmalloc(pCache[iFirstFree] = (dynaFileCacheEntry*) calloc(1, sizeof(dynaFileCacheEntry))); } /* Ok, we finally can open the file */ localRet = prepareFile(pData, newFileName); /* ignore exact error, we check fd below */ - /* file is either open now or an error state set */ + /* file is either open now or an error state set */ // RG: better check localRet? if(pData->pStrm == NULL) { /* do not report anything if the message is an internally-generated * message. Otherwise, we could run into a never-ending loop. The bad @@ -522,17 +537,15 @@ prepareDynFile(instanceData *pData, uchar *newFileName, unsigned iMsgOpts) } else { errmsg.LogError(0, NO_ERRCODE, "Could not open dynamic file '%s' - discarding message", newFileName); } - dynaFileDelCacheEntry(pCache, iFirstFree, 1); ABORT_FINALIZE(localRet); } if((pCache[iFirstFree]->pName = ustrdup(newFileName)) == NULL) { - /* we need to discard the entry, otherwise things could lead to a segfault! */ - dynaFileDelCacheEntry(pCache, iFirstFree, 1); + strm.Destruct(&pData->pStrm); /* need to free failed entry! */ ABORT_FINALIZE(RS_RET_OUT_OF_MEMORY); } pCache[iFirstFree]->pStrm = pData->pStrm; - pCache[iFirstFree]->lastUsed = time(NULL); // monotonically increasing value! TODO: performance + pCache[iFirstFree]->lastUsed = time(NULL); pData->iCurrElt = iFirstFree; DBGPRINTF("Added new entry %d for file cache, file '%s'.\n", iFirstFree, newFileName); @@ -633,7 +646,7 @@ ENDdoAction BEGINparseSelectorAct CODESTARTparseSelectorAct - if(!(*p == '$' || *p == '?' || *p == '/' || *p == '-')) + if(!(*p == '$' || *p == '?' || *p == '/' || *p == '.' || *p == '-')) ABORT_FINALIZE(RS_RET_CONFLINE_UNPROCESSED); CHKiRet(createInstance(&pData)); @@ -683,6 +696,7 @@ CODESTARTparseSelectorAct * need high-performance pipes at a later stage (unlikely). -- rgerhards, 2010-02-28 */ case '/': + case '.': CODE_STD_STRING_REQUESTparseSelectorAct(1) /* we now have *almost* the same semantics for files and pipes, but we still need * to know we deal with a pipe, because we must do non-blocking opens in that case @@ -717,6 +731,7 @@ CODESTARTparseSelectorAct pData->bFlushOnTXEnd = bFlushOnTXEnd; pData->iIOBufSize = (int) iIOBufSize; pData->iFlushInterval = iFlushInterval; + pData->bUseAsyncWriter = bUseAsyncWriter; if(pData->bDynamicName == 0) { /* try open and emit error message if not possible. At this stage, we ignore the @@ -749,9 +764,10 @@ static rsRetVal resetConfigVariables(uchar __attribute__((unused)) *pp, void __a bCreateDirs = 1; bEnableSync = 0; iZipLevel = 0; - bFlushOnTXEnd = 1; + bFlushOnTXEnd = 0; iIOBufSize = IOBUF_DFLT_SIZE; iFlushInterval = FLUSH_INTRVL_DFLT; + bUseAsyncWriter = USE_ASYNCWRITER_DFLT; if(pszFileDfltTplName != NULL) { free(pszFileDfltTplName); pszFileDfltTplName = NULL; @@ -798,6 +814,7 @@ CODEmodInit_QueryRegCFSLineHdlr CHKiRet(omsdRegCFSLineHdlr((uchar *)"dynafilecachesize", 0, eCmdHdlrInt, (void*) setDynaFileCacheSize, NULL, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileziplevel", 0, eCmdHdlrInt, NULL, &iZipLevel, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileflushinterval", 0, eCmdHdlrInt, NULL, &iFlushInterval, STD_LOADABLE_MODULE_ID)); + CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileasyncwriting", 0, eCmdHdlrBinary, NULL, &bUseAsyncWriter, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileflushontxend", 0, eCmdHdlrBinary, NULL, &bFlushOnTXEnd, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"omfileiobuffersize", 0, eCmdHdlrSize, NULL, &iIOBufSize, STD_LOADABLE_MODULE_ID)); CHKiRet(omsdRegCFSLineHdlr((uchar *)"dirowner", 0, eCmdHdlrUID, NULL, &dirUID, STD_LOADABLE_MODULE_ID)); diff --git a/tools/omfwd.c b/tools/omfwd.c index a6d83eb..cbfc36a 100644 --- a/tools/omfwd.c +++ b/tools/omfwd.c @@ -411,7 +411,7 @@ CODESTARTtryResume ENDtryResume BEGINdoAction - char *psz; /* temporary buffering */ + char *psz = NULL; /* temporary buffering */ register unsigned l; int iMaxLine; CODESTARTdoAction @@ -487,7 +487,7 @@ CODESTARTdoAction } finalize_it: # ifdef USE_NETZIP - if(psz != (char*) ppString[0]) { + if((psz != NULL) && (psz != (char*) ppString[0])) { /* we need to free temporary buffer, alloced above - Naoya Nakazawa, 2010-01-11 */ free(psz); } diff --git a/tools/zpipe.c b/tools/zpipe.c index d227835..3806942 100644 --- a/tools/zpipe.c +++ b/tools/zpipe.c @@ -4,6 +4,13 @@ Version 2.0 03 June 2009 Rainer Gerhards */ /* RSYSLOG NOTE: + * This file is primarily been used as a testing aid for rsyslog. We do NOT + * properly maintain it and it has been brought to our attention that it may + * have some security issues. However, we prefer not to remove the file as it + * may turn out to be useful for further testing. All users are advised NOT + * to base any development on this version here, but rather look for the + * original zpipe.c by the authors mentioned above. + * * This file is beeing distributed as part of rsyslog, but is just an * add-on. Most importantly, rsyslog's copyright does not apply but * rather the (non-) copyright stated above. |