Bug 200933 - syslog is not RFC-compliant when receiving remote UDP messages
Summary: syslog is not RFC-compliant when receiving remote UDP messages
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: standards (show other bugs)
Version: 10.1-RELEASE
Hardware: Any Any
: --- Affects Some People
Assignee: Gleb Smirnoff
URL:
Keywords: easy, needs-qa, patch, standards
Depends on:
Blocks:
 
Reported: 2015-06-17 13:31 UTC by Konstantin Pavlov
Modified: 2019-01-14 16:58 UTC (History)
4 users (show)

See Also:
koobs: mfc-stable10?
koobs: mfc-stable11?


Attachments
The patch should deal with the hostname in the message. (794 bytes, text/plain)
2015-11-13 09:27 UTC, Maxim Konovalov
no flags Details
a more complex patch (10.64 KB, patch)
2017-11-28 23:15 UTC, Gleb Smirnoff
no flags Details | Diff
doubled logging fixed (10.67 KB, patch)
2017-12-04 19:02 UTC, Gleb Smirnoff
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Konstantin Pavlov 2015-06-17 13:31:40 UTC
syslog daemon expects the following format when receiving remote UDP messages:

date tag: message

from man syslog.conf:

     If a received message matches the specified facility and is of the speci-
     fied level (or a higher level), and the first word in the message after
     the date matches the program, the action specified in the action field
     will be taken.

however RFC 3164 (and later ones) specify the following format:

date hostname tag: message

this means syslog can not properly filter messages based on tags, which breaks rfc-compliant software like nginx.

an excerpt of what is being sent by nginx, with tag "nginxorg" from the hostname of "www.nginx.org":

13:28:23.422156 IP xx.yy.zz.nn.11312 > 192.168.1.1.514: SYSLOG local7.info, length: 220
E.......@..<...?..+!,0......<190>Jun 17 13:28:23 www.nginx.org nginxorg: 12.34.56.78 - - [17/Jun/2015:13:28:23 +0000] "GET / HTTP/1.1" 404 4075 "-" "Debian APT-HTTP/1.3 (0.9.7.7ubuntu4)" "10.10.20.121"
Comment 1 Maxim Konovalov freebsd_committer 2015-11-13 09:27:28 UTC
Created attachment 163083 [details]
The patch should deal with the hostname in the message.

The patch should deal with the hostname in the message.

Haven't test it thoroughly.
Comment 2 Konstantin Pavlov 2017-10-17 11:41:00 UTC
This is to confirm the patch works fine.
Comment 3 commit-hook freebsd_committer 2017-11-08 16:46:39 UTC
A commit references this bug:

Author: glebius
Date: Wed Nov  8 16:45:53 UTC 2017
New revision: 325558
URL: https://svnweb.freebsd.org/changeset/base/325558

Log:
  When parsing UDP messages skip optional hostname as described by
  RFC 3164.

  PR:		200933
  Submitted by:	maxim
  Reported by:	Konstantin Pavlov <thresh nginx.com>
  MFC after:	2 weeks

Changes:
  head/usr.sbin/syslogd/syslogd.c
Comment 4 commit-hook freebsd_committer 2017-11-22 21:21:33 UTC
A commit references this bug:

Author: glebius
Date: Wed Nov 22 21:20:26 UTC 2017
New revision: 326103
URL: https://svnweb.freebsd.org/changeset/base/326103

Log:
  MFC r325558:

    When parsing UDP messages skip optional hostname as described by
    RFC 3164.

  PR:		200933
  Submitted by:	maxim
  Reported by:	Konstantin Pavlov <thresh nginx.com>

Changes:
_U  stable/11/
  stable/11/usr.sbin/syslogd/syslogd.c
Comment 5 Gleb Smirnoff freebsd_committer 2017-11-28 19:03:19 UTC
Re-opening as patch appeared to be not correct.
Comment 6 Bryan Drewery freebsd_committer 2017-11-28 20:26:04 UTC
(In reply to Gleb Smirnoff from comment #5)
> Re-opening as patch appeared to be not correct.

What's the problem?
Comment 7 Gleb Smirnoff freebsd_committer 2017-11-28 21:14:58 UTC
Syslogd treats local and remote messages differently. I'm now implementing proper parser for remote messages and I'd probably leave the local one as is.
Comment 8 Gleb Smirnoff freebsd_committer 2017-11-28 23:15:28 UTC
Created attachment 188379 [details]
a more complex patch
Comment 9 Gleb Smirnoff freebsd_committer 2017-11-28 23:15:54 UTC
Konstantin,

can you please test attached patch?
Comment 10 Konstantin Pavlov 2017-12-04 13:57:11 UTC
(In reply to Gleb Smirnoff from comment #9)

So I have the following on nginx.conf:

access_log syslog:server=192.168.128.11,facility=local7,tag=nginxorg,severity=info main;

The on-the-wire message is as follows, taken from a tcpdump (the dates will be of course different in the following log files, as I've made multiple requests throughout the time):

13:47:22.559657 IP 192.168.128.55.34947 > 192.168.128.11.514: SYSLOG local7.info, length: 132
E...;6@.@.}....7...........1<190>Dec  4 13:47:22 deb9-test1 nginxorg: 127.0.0.1 - - [04/Dec/2017:13:47:22 +0000] "GET /foo HTTP/1.1" 200 3 "-" "curl/7.52.1" "-"


/etc/syslog.conf contents:

!nginxorg
local7.*                                        -/data/logs/nginx.org.log


I've tested three scenarios:

1/ syslogd from FreeBSD 11.0-RELEASE-p1 to have a baseline.  As expected, this one does not print anything to the file.

2/ syslogd from HEAD with a patch from comment #8 (attachment 188379 [details]), using syslogd_flags="-4 -n", prints the following to the file:

Dec  4 13:49:05 192.168.128.55 nginxorg: 127.0.0.1 - - [04/Dec/2017:13:49:05 +0000] "GET /foo HTTP/1.1" 200 3 "-" "curl/7.52.1" "-"

So as we can see, the hostname from the syslog message became an IP address.  Otherwise, the line is fine.

2/ syslogd from HEAD with a patch from comment #8 (attachment 188379 [details]), using syslogd_flags="-4 -n -H", to have an actual hostname as received in the syslog message.

Now this is where the line gets corrupted, as I see it's almost doubled in the output file - the string after the hostname gets printed twice:

Dec  4 13:51:05 deb9-test1 nginxorg: 127.0.0.1 - - [04/Dec/2017:13:51:05 +0000] "GET /foo HTTP/1.1" 200 3 "-" "curl/7.52.1" "-" nginxorg: 127.0.0.1 - - [04/Dec/2017:13:51:05 +0000] "GET /foo HTTP/1.1" 200 3 "-" "curl/7.52.1" "-"
Comment 11 Gleb Smirnoff freebsd_committer 2017-12-04 19:02:23 UTC
Created attachment 188530 [details]
doubled logging fixed
Comment 12 Gleb Smirnoff freebsd_committer 2017-12-04 19:03:41 UTC
The doubled logging is fixed with new patch.

Regarding the IP address instead of hostname. Syslogd never resolved IP addresses, and it shouldn't do that.
Comment 13 Konstantin Pavlov 2017-12-05 12:51:50 UTC
(In reply to Gleb Smirnoff from comment #12)

Well, I didnt mean to imply there was a name resolution attempt, just sharing my observation on the message change from the wire to the file.

I've tested the patch from comment #11, and everything is now fine.  Thank you!
Comment 14 commit-hook freebsd_committer 2017-12-05 19:55:34 UTC
A commit references this bug:

Author: glebius
Date: Tue Dec  5 19:54:55 UTC 2017
New revision: 326573
URL: https://svnweb.freebsd.org/changeset/base/326573

Log:
  When parsing remote messages, require them to have standard timestamp
  field, and support properly parse out the hostname as described by RFC3164,
  which wasn't done before.  However, don't discard message if it doesn't
  have hostname, for compatibility.

  Enable logging of the message supplied hostname instead of real hostname
  with -H switch.

  PR:		200933
  Reported by:	Konstantin Pavlov <thresh nginx.com>
  MFC after:	2 months

Changes:
  head/usr.sbin/syslogd/syslogd.8
  head/usr.sbin/syslogd/syslogd.c
Comment 15 Eitan Adler freebsd_committer freebsd_triage 2018-05-23 10:27:04 UTC
batch change of PRs untouched in 2018 marked "in progress" back to open.
Comment 16 Gleb Smirnoff freebsd_committer 2018-05-23 16:00:17 UTC
Bug is in progress, since it is fixed in head, but not in a stable branch. The overall diff in syslogd is too big to be merged to stable (imho). Until 12.0-RELEASE, bug should stay in in progress status.
Comment 17 Gleb Smirnoff freebsd_committer 2019-01-14 16:58:46 UTC
Fixed in 12.0-RELEASE.