Hi,
Since r332100, FreeBSD uses RFC5424 format internally in libc[1]
This is in both 11.2R and 12.0R the 2 current supported releases.
imuxsock is unable to parse this format without setting "UseSpecialParser=off"
or it generates incorrect data for downstream consumption, like GELF and similar
formats, as well as making it messy in omfile output.
TLDR:
I'm not clear if this is a FreeBSD-induced bug, or rsyslog, or some combination
of the two. Should I file a bug, provide a docs patch for UseSpecialParser
(what does it actually do?), or something else?
Details - for example:
rsyslog 8.40.0 (from ports):
Using standard logger tool as test:
$ logger -H hostname -p local0.notice -s -i -t tag msg_woop
standard FreeBSD log output using rfc5424 output:
# syslogd -dFHO rfc5424
<133>1 2019-06-05T21:21:33.438075+08:00 j01 tag 19190 - - msg_woop
rsyslog using "UseSpecialParser=off":
# rsyslogd -d -f /usr/local/etc/rsyslog.conf -n -dq
2019-06-05T21:30:16.211530+08:00 j01 tag[19351] msg_woop
which produces the expected gelf_JSON output:
{
"version": "1.1",
"host": "j01",
"short_message": "msg_woop",
"timestamp": 1559741402,
"level": "5",
"facility": "local0",
"syslog-tag": "tag[19343]",
"source": "tag",
"program": "tag",
"procid": "19343"
}
Without UseSpecialParser, the datetime.c parser returns an error, presumably
because the wrong parsing format has been chosen?
the input line looks reasonable:
inputname: imuxsock rawmsg: '<133>1 2019-06-05T21:36:53.619029+08:00 j01 tag
19524 - - msg_woop'
but ends up with an odd TIMESTAMP:
FROMHOST: 'jmp', fromhost-ip: '127.0.0.1', HOSTNAME: 'jmp', PRI: 133,
syslogtag '1', programname: '1', APP-NAME: '1', PROCID: '-', MSGID: '-',
TIMESTAMP: 'Jun 5 21:36:53', STRUCTURED-DATA: '-',
msg: ' 2019-06-05T21:36:53.619029+08:00 j01 tag 19524 - - msg_woop'
escaped msg: ' 2019-06-05T21:36:53.619029+08:00 j01 tag 19524 - - msg_woop'
inputname: imuxsock rawmsg: '<133>1 2019-06-05T21:36:53.619029+08:00 j01 tag
19524 - - msg_woop'
$!:
$.:
$/:
And thus the output has the timestamp doubled up (one from the message, one
from rsyslog):
2019-06-05T21:33:47.925435+08:00 jmp 1 2019-06-05T21:33:47.925275+08:00 j01 tag
19455 - - msg_woop
debug output to console from rsyslog:
1813.748464568:main Q:Reg/w0 : wti.c: main Q:Reg/w0: worker IDLE, waiting for
work.
1813.923548068:imuxsock.c : imuxsock.c: Message from UNIX socket: #8, size
138
1813.923601868:imuxsock.c : datetime.c: ParseTIMESTAMP3339: invalid year:
1, pszTS: '2'
1813.923614768:imuxsock.c : main Q: queue.c: qqueueAdd: entry added, size
now log 1, phys 1 entries
1813.923627768:imuxsock.c : main Q: queue.c: EnqueueMsg advised worker start
1813.923634468:imuxsock.c : imuxsock.c: --------imuxsock calling poll() on
3 fds
1813.923648268:main Q:Reg/w0 : wti 0x8009c2b00: wti.c: worker awoke from idle
processing
1813.923657368:main Q:Reg/w0 : queue.c: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
1813.923663668:main Q:Reg/w0 : queue.c: doDeleteBatch: delete batch from
store, new sizes: log 1, phys 1
1813.923669668:main Q:Reg/w0 : main Q: queue.c: dequeued 1 consumable
elements, szlog 0 sz phys 1
1813.923677668:main Q:Reg/w0 : ruleset.c: processBATCH: batch of 1 elements
must be processed
The documentation [2] refers briefly to `useSpecialParser` but the
source code doesn't offer much further clarification either.
thanks
Dave
[1]:
https://github.com/freebsd/freebsd/commits/591ef7c8076109cff3c41f9bb50da996a34121e9
[2]: https://www.rsyslog.com/tag/8-9-0/
commit 591ef7c8076109cff3c41f9bb50da996a34121e9
Author: ed <e...@freebsd.org>
Date: Fri Apr 6 13:00:45 2018 +0000
Let syslog(3) use RFC 5424.
With r332099 changing syslogd(8) to parse RFC 5424 formatted syslog
messages, go ahead and also change the syslog(3) libc function to
generate them. Compared to RFC 3164, RFC 5424 has various advantages,
such as sub-second precision for log entry timestamps.
As this change could have adverse effects when not updating syslogd(8)
or using a different system logging daemon, add a notice to UPDATING and
increase __FreeBSD_version.
Differential Revision: https://reviews.freebsd.org/D14926
Notes:
svn path=/head/; revision=332100
_______________________________________________
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
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE
THAT.
