imtcp bugfix: oversize message truncation causes log to be garbled

The actual problem is in the tcpserver component. However, the prime user
is imtcp and so users will likely experience this as imtcp problem.

When a too-long message is truncated, the byte after the truncation
position becomes the first byte of the next message. This will garble
the next messages and in almost all cases render it is syslog-incompliant.

The same problem does NOT occur when the message is split.

This commit fixes the issue. It also includes a testbench fix.
Unfortunately the test for exactly this feature was not properly
crafted and so could not detect the problem.

closes https://github.com/rsyslog/rsyslog/issues/3580
This commit is contained in:
Rainer Gerhards 2019-04-29 18:32:49 +02:00
parent c001f226f0
commit ea219194b6
No known key found for this signature in database
GPG Key ID: 0CB6B2A8BE80B499
2 changed files with 10 additions and 22 deletions

View File

@ -348,9 +348,9 @@ Close(tcps_sess_t *pThis)
* the end result to the queue. Introducing this function fixes a long-term bug ;)
* rgerhards, 2008-03-14
*/
static rsRetVal
static rsRetVal ATTR_NONNULL(1)
processDataRcvd(tcps_sess_t *pThis,
char c,
const char c,
struct syslogTime *stTime,
const time_t ttGenTime,
multi_submit_t *pMultiSub,
@ -434,18 +434,14 @@ processDataRcvd(tcps_sess_t *pThis,
assert(pThis->inputState == eInMsg);
if(pThis->iMsg >= iMaxLine) {
/* emergency, we now need to flush, no matter if we are at end of message or not... */
DBGPRINTF("error: message received is larger than max msg size, we split it\n");
DBGPRINTF("error: message received is larger than max msg size, we %s it\n",
pThis->pSrv->discardTruncatedMsg == 1 ? "truncate" : "split");
defaultDoSubmitMessage(pThis, stTime, ttGenTime, pMultiSub);
++(*pnMsgs);
if(pThis->pSrv->discardTruncatedMsg == 1) {
pThis->inputState = eInMsgTruncating;
FINALIZE;
}
/* configuration parameter discardTruncatedMsg controlls
* if rest of message is being processed
* 0 = off
* 1 = on
* Pascal Withopf, 2017-04-21
*/
}
if(( ((c == '\n') && !pThis->pSrv->bDisableLFDelim)

View File

@ -14,21 +14,13 @@ ruleset(name="ruleset1") {
}
'
startup
tcpflood -m1 -M "\"<120> 2011-03-01T11:22:12Z host tag: this is a way to long message that has abcdefghijklmnopqrstuvwxyz test1 test2 test3 test4 test5 test6 test7 test8 test9 test10 test11 test12 test13 test14 test15 test16\""
tcpflood -m1 -M "\"<120> 2011-03-01T11:22:12Z host tag: this is a way to long message\""
tcpflood -m1 -M "\"<120> 2011-03-01T11:22:12Z host tag: this is a way to long message that has abcdefghijklmnopqrstuvwxyz test1 test2 test3 test4 test5 test6 test7 test8 test9 test10 test11 test12 test13 test14 test15 test16\""
tcpflood -m1 -M "\"<120> 2011-03-01T11:22:12Z host tag: this is a way to long message\""
tcpflood -m1 -M "\"<30>Apr 6 13:21:08 docker/6befb258da22[6128]: TOO LONG bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb123456789B123456789Ccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccccc
<30>Apr 6 13:21:09 docker/6defd258da22[6128]: NEXT_MSG\""
shutdown_when_empty
wait_shutdown
echo '<120> 2011-03-01T11:22:12Z host tag: this is a way to long message that has abcdefghijklmnopqrstuvwxyz test1 test2 test3 test4 t
<120> 2011-03-01T11:22:12Z host tag: this is a way to long message
<120> 2011-03-01T11:22:12Z host tag: this is a way to long message that has abcdefghijklmnopqrstuvwxyz test1 test2 test3 test4 t
<120> 2011-03-01T11:22:12Z host tag: this is a way to long message' | cmp - $RSYSLOG_OUT_LOG
if [ ! $? -eq 0 ]; then
echo "invalid response generated, $RSYSLOG_OUT_LOG is:"
cat $RSYSLOG_OUT_LOG
error_exit 1
fi;
export EXPECTED='<30>Apr 6 13:21:08 docker/6befb258da22[6128]: TOO LONG bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb123456789B12
<30>Apr 6 13:21:09 docker/6defd258da22[6128]: NEXT_MSG'
cmp_exact
exit_test