imfile: proper handling of multiline messages after rsyslog restart

handling of persisted info (and polling loops) was not correct.

This needs some cleanup but I hope to find some folks for
independent testing before I declare victory.

see also https://github.com/rsyslog/rsyslog/issues/144
This commit is contained in:
Rainer Gerhards 2015-03-24 11:35:20 +01:00
parent 6e511e8e8b
commit dd546f82a5
4 changed files with 105 additions and 6 deletions

View File

@ -636,7 +636,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 %zd, max %zd\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 */
@ -699,10 +699,11 @@ strmReadLine(strm_t *pThis, cstr_t **ppCStr, uint8_t mode, sbool bEscapeLF)
ASSERT(pThis != NULL);
ASSERT(ppCStr != NULL);
dbgprintf("DDDDD: readLine: enter, bPrevWasNL %d\n", pThis->bPrevWasNL);
CHKiRet(cstrConstruct(ppCStr));
CHKiRet(strmReadChar(pThis, &c));
dbgprintf("DDDDD: readLine: enter, bPrevWasNL %d\n", pThis->bPrevWasNL);
dbgprintf("DDDDD: readLine: pre-check, bPrevWasNL %d\n", pThis->bPrevWasNL);
/* append previous message to current message if necessary */
if(pThis->prevLineSegment != NULL) {
dbgprintf("DDDDD: readLine: have previous line segment: '%s'\n", rsCStrGetSzStr(pThis->prevLineSegment));
@ -795,8 +796,10 @@ dbgprintf("DDDDD: readLine: enter, bPrevWasNL %d\n", pThis->bPrevWasNL);
finalize_it:
dbgprintf("DDDDD: readLine returns[%d]: '%s' [*ppCStr %p]\n", iRet, (char*)rsCStrGetSzStr(*ppCStr), *ppCStr);
if(iRet != RS_RET_OK && *ppCStr != NULL) {
dbgprintf("DDDDD: readLine saves segment '%s'\n", rsCStrGetSzStr(*ppCStr));
rsCStrConstructFromCStr(&pThis->prevLineSegment, *ppCStr);
if(cstrLen(*ppCStr) > 0) { /* we may have an empty string in an unsuccsfull poll or after restart! */
dbgprintf("DDDDD: readLine saves segment '%s'\n", rsCStrGetSzStr(*ppCStr));
rsCStrConstructFromCStr(&pThis->prevLineSegment, *ppCStr);
}
cstrDestruct(ppCStr);
}
@ -1859,7 +1862,8 @@ static rsRetVal strmSerialize(strm_t *pThis, strm_t *pStrm)
l = pThis->inode;
objSerializeSCALAR_VAR(pStrm, inode, INT64, l);
objSerializePTR(pStrm, prevLineSegment, PSZ);
cstrFinalize(pThis->prevLineSegment);
objSerializePTR(pStrm, prevLineSegment, CSTR);
i = pThis->bPrevWasNL;
objSerializeSCALAR_VAR(pStrm, bPrevWasNL, INT, i);

View File

@ -261,7 +261,10 @@ if ENABLE_EXTENDED_TESTS
endif
if ENABLE_IMFILE
TESTS += imfile-basic.sh
TESTS += imfile-basic.sh \
imfile-readmode2.sh \
imfile-readmode2-with-persists-data-during-stop.sh \
imfile-readmode2-with-persists.sh \
if HAVE_VALGRIND
TESTS += imfile-basic-vg.sh
endif
@ -634,6 +637,12 @@ EXTRA_DIST= 1.rstest 2.rstest 3.rstest err1.rstest \
testsuites/complex1.conf \
random.sh \
testsuites/random.conf \
imfile-readmode2.sh \
imfile-readmode2-with-persists-data-during-stop.sh \
imfile-readmode2-with-persists.sh \
testsuites/imfile-readmode2.conf \
testsuites/imfile-readmode2-with-persists.conf \
testsuites/imfile-readmode2-with-persists-data-during-stop.conf \
imfile-basic.sh \
imfile-basic-vg.sh \
testsuites/imfile-basic.conf \

View File

@ -0,0 +1,65 @@
# This is part of the rsyslog testbench, licensed under ASL 2.0
echo ======================================================================
echo [imfile-readmode2-with-persists.sh]
source $srcdir/diag.sh init
source $srcdir/diag.sh startup imfile-readmode2-with-persists.conf
# write the beginning of the file
echo 'msgnum:0
msgnum:1' > rsyslog.input
echo 'msgnum:2' >> rsyslog.input
# sleep a little to give rsyslog a chance to begin processing
sleep 1
# now stop and restart rsyslog so that the file info must be
# persisted and read again on startup. Results should still be
# correct ;)
echo stopping rsyslog
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!
echo restarting rsyslog
source $srcdir/diag.sh startup imfile-readmode2-with-persists.conf
echo restarted rsyslog, continuing with test
# write some more lines (see https://github.com/rsyslog/rsyslog/issues/144)
echo 'msgnum:3
msgnum:4' >> rsyslog.input
echo 'msgnum:5' >> rsyslog.input # this one shouldn't be written to the output file because of ReadMode 2
# give it time to finish
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!
# give it time to write the output file
sleep 1
## check if we have the correct number of messages
NUMLINES=$(grep -c HEADER $srcdir/rsyslog.out.log 2>/dev/null)
if [ -z $NUMLINES ]; then
echo "ERROR: expecting at least a match for HEADER, maybe rsyslog.out.log wasn't even written?"
exit 1
else
if [ ! $NUMLINES -eq 3 ]; then
echo "ERROR: expecting 3 headers, got $NUMLINES"
exit 1
fi
fi
## check if all the data we expect to get in the file is there
for i in {1..4}; do
grep msgnum:$i $srcdir/rsyslog.out.log > /dev/null 2>&1
if [ ! $? -eq 0 ]; then
echo "ERROR: expecting the string 'msgnum:$i', it's not there"
exit 1
fi
done
## if we got here, all is good :)
source $srcdir/diag.sh exit

View File

@ -0,0 +1,21 @@
$IncludeConfig diag-common.conf
global(workDirectory="test-spool")
module(load="../plugins/imfile/.libs/imfile")
input(type="imfile"
File="./rsyslog.input"
Tag="file:"
ReadMode="2")
template(name="outfmt" type="list") {
constant(value="HEADER ")
property(name="msg" format="json")
constant(value="\n")
}
if $msg contains "msgnum:" then
action(
type="omfile"
file="rsyslog.out.log"
template="outfmt"
)