On Aug 19, 2014, at 6:33 PM, David Lang <[email protected]> wrote: > On Tue, 19 Aug 2014, Ivan Lezhnjov IV wrote: > >> Hello, >> >> On Aug 15, 2014, at 6:17 PM, Rainer Gerhards <[email protected]> >> wrote: >> >>> On Fri, Aug 15, 2014 at 5:13 PM, Mike Hoskins (michoski) <[email protected] >>>> wrote: >>> >>>> I thought %FROMHOST% caused a DNS lookup on rsyslog's side, while >>>> %HOSTNAME% just used the hostname sent in the message...others will >>>> correct if my memory is bad. >>> >>> >>> That's right, but I think we fall back to a dns lookup if there is no >>> detectable hostname in the message(not 100% sure, though). >>> >>> >>>> So if %HOSTNAME% is not right, it must be >>>> something on the client side. >>>> >>>> >>> can very well be, but sounded more like DNS resolution. >>> >>> >>>> I think you just use %rawmsg% to get the raw message. :-) >>>> >>>> http://www.rsyslog.com/doc/property_replacer.html >>>> >>>> >>> yup or use >>> >>> *.* /var/log/messagedebug;RSYSLOG_DebugFormat >>> >>> which will write out all properties. >> >> This is how a normal message looks like: >> >> Debug line with all properties: >> FROMHOST: '172.16.16.4', fromhost-ip: '172.16.16.4', HOSTNAME: >> 'xyz-DDDD-02', PRI: 86, >> syslogtag 'su[42661]:', programname: 'su', APP-NAME: 'su', PROCID: '42661', >> MSGID: '-', >> TIMESTAMP: 'Aug 19 02:11:58', STRUCTURED-DATA: '-', >> msg: ' pam_unix(su:session): session closed for user postgres' >> escaped msg: ' pam_unix(su:session): session closed for user postgres' >> inputname: imtcp rawmsg: '<86>Aug 19 02:11:58 xyz-DDDD-02 su[42661]: >> pam_unix(su:session): session closed for user postgres' >> >> Are we interested in this only, or also what debug message is going to look >> like when the suspected DNS resolution failure occurs again? > > It would be good to get one of a failing message > > In this case, the HOSTNAME is pulled directly from the rawmsg, so no DNS > lookup is done there. > > normally FROMHOST is a DNS lookup of fromhost-ip, so this message shows a > "normal" DNS failure. > > This makes me think that you have a situation where the sender isn't properly > populating the hostname field of the message under some conditions.
Alright, it happened again yesterday and these two debug messages follow exactly one after another: Debug line with all properties: FROMHOST: '172.16.16.5', fromhost-ip: '172.16.16.5', HOSTNAME: 'xyz-DDDD-03', PRI: 29, syslogtag 'dbus[1767]:', programname: 'dbus', APP-NAME: 'dbus', PROCID: '1767', MSGID: '-', TIMESTAMP: 'Aug 19 18:11:57', STRUCTURED-DATA: '-', msg: ' [system] Reloaded configuration' escaped msg: ' [system] Reloaded configuration' inputname: imtcp rawmsg: '<29>Aug 19 18:11:57 xyz-DDDD-03 dbus[1767]: [system] Reloaded configuration' Debug line with all properties: FROMHOST: '172.16.16.5', fromhost-ip: '172.16.16.5', HOSTNAME: '172.16.16.5', PRI: 29, syslogtag '', programname: '', APP-NAME: '', PROCID: '-', MSGID: '-', TIMESTAMP: 'Aug 19 18:11:57', STRUCTURED-DATA: '-', msg: ' dbus[1767]: last message repeated 4 times' escaped msg: ' dbus[1767]: last message repeated 4 times' inputname: imtcp rawmsg: '<29>Aug 19 18:11:57 dbus[1767]: last message repeated 4 times' Then it goes back to proper host name resolution and fails again after some time: Debug line with all properties: FROMHOST: '172.16.16.5', fromhost-ip: '172.16.16.5', HOSTNAME: 'xyz-DDDD-03', PRI: 13, syslogtag 'dataeng:', programname: 'dataeng', APP-NAME: 'dataeng', PROCID: '-', MSGID: '-', TIMESTAMP: 'Aug 19 18:12:03', STRUCTURED-DATA: '-', msg: ' NOTE: OS SNMP support not installed' escaped msg: ' NOTE: OS SNMP support not installed' inputname: imtcp rawmsg: '<13>Aug 19 18:12:03 xyz-DDDD-03 dataeng: NOTE: OS SNMP support not installed' Debug line with all properties: FROMHOST: '172.16.16.5', fromhost-ip: '172.16.16.5', HOSTNAME: '172.16.16.5', PRI: 29, syslogtag '', programname: '', APP-NAME: '', PROCID: '-', MSGID: '-', TIMESTAMP: 'Aug 19 18:12:03', STRUCTURED-DATA: '-', msg: ' dbus[1767]: last message repeated 4 times' escaped msg: ' dbus[1767]: last message repeated 4 times' inputname: imtcp rawmsg: '<29>Aug 19 18:12:03 dbus[1767]: last message repeated 4 times' Note how APP-NAME: '', PROCID: '-', MSGID: '-', are just the "-" sign when HOSTNAME becomes an IP address. Then it happened again: Debug line with all properties: FROMHOST: '172.16.16.5', fromhost-ip: '172.16.16.5', HOSTNAME: '172.16.16.5', PRI: 29, syslogtag '', programname: '', APP-NAME: '', PROCID: '-', MSGID: '-', TIMESTAMP: 'Aug 19 18:12:17', STRUCTURED-DATA: '-', msg: ' dbus[1767]: last message repeated 11 times' escaped msg: ' dbus[1767]: last message repeated 11 times' inputname: imtcp rawmsg: '<29>Aug 19 18:12:17 dbus[1767]: last message repeated 11 times' The /var/log/syslog on 172.16.16.5 has these entries that match the time of the ones mentioned above: Aug 19 17:55:01 xyz-DDDD-03 CRON[46232]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1) Aug 19 18:05:01 xyz-DDDD-03 CRON[49559]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1) Aug 19 18:11:57 xyz-DDDD-03 dbus[1767]: [system] Reloaded configuration Aug 19 18:12:03 dbus[1767]: last message repeated 4 times Aug 19 18:12:03 xyz-DDDD-03 dataeng: NOTE: OS SNMP support not installed Aug 19 18:12:04 xyz-DDDD-03 dbus[1767]: [system] Reloaded configuration Aug 19 18:12:17 dbus[1767]: last message repeated 11 times Aug 19 18:12:17 xyz-DDDD-03 ata_id[55947]: HDIO_GET_IDENTITY failed for '/dev/sdc': Invalid argument Aug 19 18:12:17 xyz-DDDD-03 dbus[1767]: [system] Reloaded configuration Aug 19 18:12:17 xyz-DDDD-03 dbus[1767]: [system] Reloaded configuration So, as we can see the hostname never appears in the client log file actually. Ivan _______________________________________________ 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.
