On Fri, 20 Apr 2012, Jo Rhett wrote:
On Apr 20, 2012, at 9:58 AM, Rainer Gerhards wrote:
I just tried with that latest 5.8.10 and 5.4.0 (as a random older version). I
could not reproduce the problem in both cases. I would appreciate if you
could either 5.8.10 or let me know the version number of a version where you
had the problem. I'd like to see if I can reproduce - or if it is
environment-induced.
I am using 5.8.10.
We are trying to forward syslog to Zenoss and that's where it is
failing. So I did some testing and gathered some pcaps, and I'm seeing
something odd. The forwarded messages appear to have a lot of nulls in
the same place where a normal syslog message starts.
Interesting, testing to port 514 with a normal syslogd works fine. It's
just when testing to port 1514 that I'm seeing this behavior.
Configuration:
# Load the module which spoofs UDP packets when forwarding
$ModLoad omudpspoof
$template Untouched,"%rawmsg%"
$template RawMessage,"%msg:2:2048%\n"
$ActionOMUDPSpoofTargetHost loghost
$ActionOMUDPSpoofTargetPort 1514
# This doesn't work in any scenario
local7.*
:omudpspoof:;RSYSLOG_TraditionalFileFormat
# The following two work for a normal syslogd on port 514
local7.*
:omudpspoof:;Untouched
local7.*
:omudpspoof:
# The following works for forwarding to Zenoss -- although Zenoss doesn't parse
it correctly since it isn't in the right format
local7.*
:omudpspoof:;RawMessage
HOWEVER, a normal syslog message generated locally by that host works
fine (not through the UDP spoof) and Zenoss parses it correctly too. So
there is some difference in the message formats.
So I went looking at pcap of the files and found that in a normal syslog
message not forwarded through udpspoof, the message consistently starts
at byte 43. Before that byte are mostly binary and very few nulls.
The udpspoofed messages don't begin until byte 63. With %msg:2:2048%
the message part of the syslog event starts immediately. With %rawmsg%
the message beings with the string "<190>" before the date stamp, which
appears to break the parsing of the message on the far side.
the string <190> is the encoded priority and severity of the message (in
this case local7.user). A properly formatted syslog message will have this
(try sending a message with the format RSYSLOG_Traditional_Forward_Format
and you should see a similar thing before the timestamp) If this is
breaking the message parsing, the receiving system is broken
Here's some examples -- msg:2:2048 created with logger -p local7.info "123 This is
another test message" and forwarded via udpspoof
0000 78 2b cb 29 ff 1b 00 26 b9 33 00 3a 08 00 4a 00 x+.)...& .3.:..J.
0010 00 52 00 f2 00 00 40 11 b6 bd 0a d2 82 76 0a d2 .R....@. .....v..
0020 1e ca 00 01 01 01 01 01 01 01 01 01 01 00 01 01 ........ ........
0030 00 01 00 01 01 00 07 7d 05 ea 00 2a 63 a3 31 32 .......} ...*c.12
0040 33 20 54 68 69 73 20 69 73 20 61 6e 6f 74 68 65 3 This i s anothe
0050 72 20 74 65 73 74 20 6d 65 73 73 61 67 65 2e 0a r test m essage..
rawmsg created with logger -p local7.info 123 "This is another test message"
and forwarded via udpspoof
0000 78 2b cb 29 ff 1b 00 26 b9 33 00 3a 08 00 4a 00 x+.)...& .3.:..J.
0010 00 79 00 f2 00 00 40 11 b6 9a 0a d2 82 76 0a d2 .y....@. .....v..
0020 1e ca 01 00 01 01 00 00 00 01 01 01 01 00 00 00 ........ ........
0030 01 01 01 00 01 00 02 7d 05 ea 00 51 33 98 3c 31 .......} ...Q3.<1
0040 39 30 3e 41 70 72 20 32 30 20 31 31 3a 30 30 3a 90>Apr 2 0 11:00:
0050 30 36 20 73 32 32 2d 77 77 77 30 38 20 6a 6f 72 06 s22-w ww08 jor
Here's a normal syslog message from the same host sent directly, not forwarded
by udpspoof: you might recognize the message ;-)
0000 78 2b cb 29 ff 1b 00 26 b9 33 00 3a 08 00 45 00 x+.)...& .3.:..E.
0010 00 6d 00 00 40 00 40 11 e7 53 0a d2 1e bf 0a d2 .m..@.@. .S......
0020 1e ca cb aa 05 ea 00 59 32 64 41 70 72 20 32 30 .......Y 2dApr 20
0030 20 31 37 3a 35 39 3a 33 37 20 73 32 32 2d 66 32 17:59:3 7 s22-f2
0040 30 31 20 6b 65 72 6e 65 6c 3a 20 69 6d 6b 6c 6f 01 kerne l: imklo
0050 67 20 35 2e 38 2e 31 30 2c 20 6c 6f 67 20 73 6f g 5.8.10 , log so
looking at these dumps, I don't think the problem is the <190>, I think
the problem is the three characters before that (Q3. in the text
represnetation), those start at the same point that the timestamp starts
in the last example.
note that the last example is missing the priority/severity information.
This is unfortunantly not an uncommon bug.
David Lang
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
