Messages starting with tab not processed cleanly
We're running into an issue where some syslog messages on our centralized syslog-ng server lack originating hostnames. These messages happen to be formatted funny - the message part starts with a tab (\0x09) character. Solaris 10 x86 everywhere, Syslog-ng 3.1.4, Eventlog 0.2.12. Client syslog: Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.warning] WARNING: /pci@7b,0/pci1022,7458@11/pci1000,3060@2/sd@0,0 (sd2): Sep 15 20:30:21 h.example.com Error for Command: read Error Level: Fatal Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Requested Block: 16065 Error Block: 16065 Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Vendor: SEAGATE Serial Number: 074093HVSX Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Sense Key: Aborted Command Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] ASC: 0x8 (LUN communication time-out), ASCQ: 0x1, FRU: 0x81 This shows up in my centralized syslog-ng server as: Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.warning] WARNING: /pci@7b,0/pci1022,7458@11/pci1000,3060@2/sd@0,0 (sd2): Sep 15 20:30:21 Error for Command: read Error Level: Fatal Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Requested Block: 16065 Error Block: 16065 Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Vendor: SEAGATE Serial Number: 074093HVSX Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] Sense Key: Aborted Command Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.notice] ASC: 0x8 (LUN communication time-out), ASCQ: 0x1, FRU: 0x81 Note that the 2nd line doesn't have a hostname. This is the message coming from the host (tcpdump -n -v -s 0 "port 514"): 20:30:21.454902 IP (tos 0x0, ttl 255, id 43670, offset 0, flags [DF], proto UDP (17), length 141) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 113 Facility kernel (0), Severity warning (4) Msg: Sep 15 20:30:21 scsi: [ID 107833 kern.warning] WARNING: /pci@7b,0/pci1022,7458@11/pci1000,3060@2/sd@0,0 (sd2): 20:30:21.454941 IP (tos 0x0, ttl 255, id 43671, offset 0, flags [DF], proto UDP (17), length 109) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 81 Facility kernel (0), Severity warning (4) Msg: Sep 15 20:30:21 \0x09Error for Command: read Error Level: Fatal 20:30:21.454966 IP (tos 0x0, ttl 255, id 43672, offset 0, flags [DF], proto UDP (17), length 139) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 111 Facility kernel (0), Severity notice (5) Msg: Sep 15 20:30:21 scsi: [ID 107833 kern.notice] \0x09Requested Block: 16065 Error Block: 16065 20:30:21.454986 IP (tos 0x0, ttl 255, id 43673, offset 0, flags [DF], proto UDP (17), length 148) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 120 Facility kernel (0), Severity notice (5) Msg: Sep 15 20:30:21 scsi: [ID 107833 kern.notice] \0x09Vendor: SEAGATE Serial Number: 074093HVSX 20:30:21.455010 IP (tos 0x0, ttl 255, id 43674, offset 0, flags [DF], proto UDP (17), length 104) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 76 Facility kernel (0), Severity notice (5) Msg: Sep 15 20:30:21 scsi: [ID 107833 kern.notice] \0x09Sense Key: Aborted Command 20:30:21.455031 IP (tos 0x0, ttl 255, id 43675, offset 0, flags [DF], proto UDP (17), length 137) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 109 Facility kernel (0), Severity notice (5) Msg: Sep 15 20:30:21 scsi: [ID 107833 kern.notice] \0x09ASC: 0x8 (LUN communication time-out), ASCQ: 0x1, FRU: 0x81 (Hostnames/IPs sanitized) The second message starts with a tab (\0x09) after the timestamp. This seems to throw off syslog-ng such that it won't append a hostname to the message. We do a lot of parsing that relies on the hostname being present in all messages. Any idea why this seems to break syslog-ng, or how to fix it? Our syslog-ng.conf is relatively generic. Here are the relevant parts: filter f_syslog { level(info..emerg); }; destination d_syslog { file("/syslog/logs/$YEAR/$MONTH/$DAY/syslog" flags(no-multi-line)); }; log{ source(s_sys); source(s_remote); filter(f_syslog); destination(d_syslog); }; (Sorry if this hits the list twice, I don't think my first try worked.) Thanks, -Jon
Jon Nathan <jon+dated+1316554556.86f3d9@rupture.net> writes:
Client syslog:
Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.warning] WARNING: /pci@7b,0/pci1022,7458@11/pci1000,3060@2/sd@0,0 (sd2): Sep 15 20:30:21 h.example.com Error for Command: read Error Level: Fatal
This has a hostname because the message is coming from /dev/log (or whatever its Solaris equivalent is), where only the message part appears, the date and host is appended by the syslog daemon.
This shows up in my centralized syslog-ng server as:
Sep 15 20:30:21 h.example.com scsi: [ID 107833 kern.warning] WARNING: /pci@7b,0/pci1022,7458@11/pci1000,3060@2/sd@0,0 (sd2): Sep 15 20:30:21 Error for Command: read Error Level: Fatal
This does not have a host header (it actually does, see below!), because, if you look at the message as it comes through the net:
20:30:21.454941 IP (tos 0x0, ttl 255, id 43671, offset 0, flags [DF], proto UDP (17), length 109) 10.1.1.1.59299 > 10.1.1.2.514: SYSLOG, length: 81 Facility kernel (0), Severity warning (4) Msg: Sep 15 20:30:21 \0x09Error for Command: read Error Level: Fatal
The first word after the date in a BSD syslog message will be the host, thus, syslog-ng will treat \0x09Error as the hostname, as that's what's coming through the wire. For added fun, $PROGRAM will be set to "for" aswell. If you turn off keep-hostname(), which I assume you have on at your source (otherwise the \0x09Error would get replaced), you'll see that it will disappear, and get replaced by a hostname. The best course of action I can think of, is using a filter + rewrite combination, something like the following: filter f_tabhost { host("\t*" type(glob)); }; rewrite r_rewrite_taberror { set("$HOST $PROGRAM $MSG", value("MSG")); set("$HOST_FROM", value("HOST")); set("-", value("PROGRAM")); }; log { source(...); filter(f_tabhost); rewrite(r_rewrite_taberror); destination(d_syslog); flags(final); }; log { source(...); destination(d_syslog); }; This will set the message part appropriately, and set $HOST to $HOST_FROM (which is the originating host's name, as looked up via DNS), and $PROGRAM to a default value of "-". Provided that the sending hosts' reverse dns is the same as the host it sends in syslog messages, the above blocks should do the right thing. (I'm not sure whether all of this is supported in 3.1, I suppose it is. I only tried with 3.3, as that's what I have at hand, but according to the documentation, this should work with 3.2 aswell) -- |8]
* Gergely Nagy <algernon@balabit.hu> [09-16-2011 06:36]:
The best course of action I can think of, is using a filter + rewrite combination, something like the following:
filter f_tabhost { host("\t*" type(glob)); };
rewrite r_rewrite_taberror { set("$HOST $PROGRAM $MSG", value("MSG")); set("$HOST_FROM", value("HOST")); set("-", value("PROGRAM")); };
log { source(...); filter(f_tabhost); rewrite(r_rewrite_taberror); destination(d_syslog); flags(final); };
log { source(...); destination(d_syslog); };
This will set the message part appropriately, and set $HOST to $HOST_FROM (which is the originating host's name, as looked up via DNS), and $PROGRAM to a default value of "-".
Provided that the sending hosts' reverse dns is the same as the host it sends in syslog messages, the above blocks should do the right thing.
(I'm not sure whether all of this is supported in 3.1, I suppose it is. I only tried with 3.3, as that's what I have at hand, but according to the documentation, this should work with 3.2 aswell)
-- |8]
Thank you Gergely, this does exactly what we want. -Jon
On Fri, 2011-09-16 at 12:12 -0400, Jon Nathan wrote:
* Gergely Nagy <algernon@balabit.hu> [09-16-2011 06:36]:
The best course of action I can think of, is using a filter + rewrite combination, something like the following:
filter f_tabhost { host("\t*" type(glob)); };
rewrite r_rewrite_taberror { set("$HOST $PROGRAM $MSG", value("MSG")); set("$HOST_FROM", value("HOST")); set("-", value("PROGRAM")); };
log { source(...); filter(f_tabhost); rewrite(r_rewrite_taberror); destination(d_syslog); flags(final); };
log { source(...); destination(d_syslog); };
This will set the message part appropriately, and set $HOST to $HOST_FROM (which is the originating host's name, as looked up via DNS), and $PROGRAM to a default value of "-".
Provided that the sending hosts' reverse dns is the same as the host it sends in syslog messages, the above blocks should do the right thing.
(I'm not sure whether all of this is supported in 3.1, I suppose it is. I only tried with 3.3, as that's what I have at hand, but according to the documentation, this should work with 3.2 aswell)
-- |8]
Thank you Gergely, this does exactly what we want.
also, check-hostnames() could be at your service, bad-hostnames() even allows you to specify a regexp to discover "bad" hostnames that should rather be part of the message payload. -- Bazsi
participants (4)
-
Balazs Scheidler
-
Gergely Nagy
-
Jon Nathan
-
Jon Nathan