> -----Original Message----- > From: [email protected] [mailto:rsyslog- > [email protected]] On Behalf Of Rodney McKee > Sent: Tuesday, July 19, 2011 12:03 AM > To: rsyslog-users > Subject: Re: [rsyslog] timereported:::date-rfc3339 > > I've been looking further into this and even on my Fedora 15 system > with 2.6.38.8-35 and rsyslog 5.8.2 I'm only seeing low-res times for > local services but for instance, iptables is logging with high-res > times.
Can you provide me a debug format example? I know I can set up another lab for that, but that ties up some resources I don't have during reimplementing the config format. I've checked the ChangeLog. You need at least 5.9.1 to obtain timestamps from the kernel. > > Do the services themselves need to support the use of hi-res timing, for all but imuxsock, that's for sure true, because the apps emit the format. But of course, for imuxsock 5.9.1+ can pull from the kernel (iff the kernel is recent enough -- there was a patch to the kernel to support this - at least SUSE already ships it and I guess F15, too). > if > that's the case then surely the usability of the hi-res timing is going > to be reduced. > Is it likely to impact log analyzers having a mix of hi-res and low-res > times with-in the logs. I really think that log analyzers need to be fixed. After all, what's the problem with parsing an ISO date with different time resolution? I think it's 5 to 10 lines of code in rsyslog. Not a big problem, really. It takes more time to write this post than to code that ;) BUT: if that would be a solution, I could always write milliseconds, even if they are unknown. I could simply write them as "s.000000". However, this gives a false impression of correctness. Because when you see "s.000000", you don't know any longer if it were actually at "s.000000" or even at "s.999999". In order to differentiate between the cases, where we really have "s.000000" vs. where we have just "s", the timestamp is written with the resolution provided. This is also as of RFC recommendation. Please note that this actually is an *aid* to (sufficiently well-written) log analyzers. Rainer > > I'd be interested to hear your thoughts on this. > > > ----- Original Message ----- > > > > Can you elaborate why? That would be very interesting to me. I > > > > really > > > > think > > > > it is a shame that we have hi-res format since 5+ years, but > > > > everybody turns > > > > it off... > > > > > > > > > > It appears that their are a limited number of clients that I'm > > > seeing > > > logging with hi-res so to have it enabled for only a few services > > > logging in hi-res would appear pointless. > > > > I personally think "it depends" because you can correlate the hi-res > > ones > > better. But I see your point. Also let me say that with a > > sufficiently recent > > kernel, 5.8.3 is able to pull a hires timestamp from the system for > > all local > > socket messages. > > > > > If I could enable it in our environment and have all logging hi-res > > > I > > > will certainly be doing it, that's why we have been trying. > > > The java application that we run WILL certainly be logging in > > > hi-res > > > and this will be centralized using log4j and rsyslog with the JSON > > > module. > > > > > > Out of interest we are also monitoring the rsyslog stats using pcp > > > and > > > I suspect we will have some modules/details heading your way once > > > we > > > have completed implementation and testing. > > > > Let them flow :) > > > > Rainer > > > > > > > Rainer > > > > > > > > > > > > > > > ----- Original Message ----- > > > > > > Ahh, I now see it. Look at the raw messages. Lines 7 and 31 > > > > > > are > > > > > > correctly > > > > > > formatted. Lines 15 and 23 have invalid format. With invalid > > > > > > format, > > > > > > interpretation is not guaranteed. Looks like 5.8.0 in that > > > > > > case > > > > > > uses > > > > > > the > > > > > > timestamp of message reception. I suggest to use the current > > > > > > stable, > > > > > > I think > > > > > > it will work somewhat different. Bottom line is that auditd > > > > > > should > > > > > > emit the > > > > > > proper format. > > > > > > > > > > > > Rainer > > > > > > > > > > > > > > > > > > > -----Original Message----- > > > > > > > From: [email protected] [mailto:rsyslog- > > > > > > > [email protected]] On Behalf Of Rodney McKee > > > > > > > Sent: Monday, July 18, 2011 8:26 AM > > > > > > > To: rsyslog-users > > > > > > > Subject: Re: [rsyslog] timereported:::date-rfc3339 > > > > > > > > > > > > > > http://pastebin.com/TzPVzknt > > > > > > > The 2 line I have previously seen with hi-res times are 15 > > > > > > > and > > > > > > > 23 > > > > > > > > > > > > > > ----- Original Message ----- > > > > > > > > > -----Original Message----- > > > > > > > > > From: [email protected] > > > > > > > > > [mailto:rsyslog- > > > > > > > > > [email protected]] On Behalf Of Rodney McKee > > > > > > > > > Sent: Monday, July 18, 2011 8:11 AM > > > > > > > > > To: rsyslog-users > > > > > > > > > Subject: Re: [rsyslog] timereported:::date-rfc3339 > > > > > > > > > > > > > > > > > > The following log has a restart of auditd and a ssh > > > > > > > > > connection > > > > > > > > > during > > > > > > > > > the debug run. > > > > > > > > > http://pastebin.com/cRPuA1Z8 > > > > > > > > > > > > > > > > Thanks! Unfortunately, the instrumentation does not > > > > > > > > provide > > > > > > > > what > > > > > > > > I am > > > > > > > > looking > > > > > > > > for (maybe because of an older build, maybe it's just not > > > > > > > > there...). > > > > > > > > Can you > > > > > > > > please also write all messages to a file with > > > > > > > > RSYSLOG_DebugFormat > > > > > > > > and > > > > > > > > post > > > > > > > > that file. > > > > > > > > > > > > > > > > With 5.8.0, you should probably never see hires, so I am > > > > > > > > a > > > > > > > > bit > > > > > > > > puzzled. Maybe > > > > > > > > auditd does some "interesting" things to the log socket. > > > > > > > > Note > > > > > > > > that > > > > > > > > rsyslog > > > > > > > > expects syslog() API format, but older versions (like > > > > > > > > 5.8.0) > > > > > > > > did > > > > > > > > not > > > > > > > > enforce > > > > > > > > that. > > > > > > > > > > > > > > > > Rainer > > > > > > > > > > > > > > > > > > ----- Original Message ----- > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > -----Original Message----- > > > > > > > > > > > From: [email protected] > > > > > > > > > > > [mailto:rsyslog- > > > > > > > > > > > [email protected]] On Behalf Of Rodney > > > > > > > > > > > McKee > > > > > > > > > > > Sent: Monday, July 18, 2011 7:41 AM > > > > > > > > > > > To: rsyslog-users > > > > > > > > > > > Subject: Re: [rsyslog] timereported:::date-rfc3339 > > > > > > > > > > > > > > > > > > > > > > Wow, Rainer, thanks for the quick response. > > > > > > > > > > > > > > > > > > > > > > So on a local system some processes actually > > > > > > > > > > > provide a > > > > > > > > > > > high > > > > > > > > > > > res > > > > > > > > > > > time > > > > > > > > > > > that rsyslog then logs as %timereported%. > > > > > > > > > > > > > > > > > > > > As far as the local sockets is concerned, things > > > > > > > > > > should > > > > > > > > > > be > > > > > > > > > > consistent. If > > > > > > > > > > that's not the case, it is best if you provide a > > > > > > > > > > debug > > > > > > > > > > log -- > > > > > > > > > > the > > > > > > > > > > log > > > > > > > > > > samples > > > > > > > > > > just show the result but now how we arrived there :) > > > > > > > > > > > > > > > > > > > > Rainer > > > > > > > > > > > > > > > > > > > > Did not realize this would be > > > > > > > > > > > happening. I guess that most clients then do not > > > > > > > > > > > provide > > > > > > > > > > > the > > > > > > > > > > > hi-res > > > > > > > > > > > times and this might explain some messages having > > > > > > > > > > > the > > > > > > > > > > > time > > > > > > > > > > > and > > > > > > > > > > > most > > > > > > > > > > > not: > > > > > > > > > > > > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10+10:00 2011-07- > > > > > > > > > > > 18T14:27:10.702529+10:00 The audit daemon is > > > > > > > > > > > exiting. > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10.703673+10:00 > > > > > > > > > > > 2011-07- > > > > > > > > > > > 18T14:27:10.703673+10:00 > > > > > > > > > > > audit(1310963230.693:4484770): > > > > > > > > > > > audit_pid=0 > > > > > > > > > > > old=1773 by auid=4294967295 > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10.867738+10:00 > > > > > > > > > > > 2011-07- > > > > > > > > > > > 18T14:27:10.867738+10:00 > > > > > > > > > > > audit(1310963230.864:4484771): > > > > > > > > > > > auid=672 > > > > > > > > > > > op=remove rule key=(null) list=2 res=1 > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10+10:00 2011-07- > > > > > > > > > > > 18T14:27:10.959443+10:00 Warning - freq is > > > > > > > > > > > non-zero > > > > > > > > > > > and > > > > > > > > > > > incremental > > > > > > > > > > > flushing not selected. > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10+10:00 2011-07- > > > > > > > > > > > 18T14:27:10.978467+10:00 Started dispatcher: > > > > > > > > > > > /sbin/audispd > > > > > > > > > > > pid: > > > > > > > > > > > 4794 > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10.981061+10:00 > > > > > > > > > > > 2011-07- > > > > > > > > > > > 18T14:27:10.981061+10:00 > > > > > > > > > > > audit(1310963230.979:4484772): > > > > > > > > > > > audit_pid=4792 > > > > > > > > > > > old=0 by auid=672 > > > > > > > > > > > Jul 18 14:27:10 2011-07-18T14:27:10+10:00 2011-07- > > > > > > > > > > > 18T14:27:10.998047+10:00 af_unix plugin > > > > > > > > > > > initialized > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > ----- Original Message ----- > > > > > > > > > > > > > -----Original Message----- > > > > > > > > > > > > > From: [email protected] > > > > > > > > > > > > > [mailto:rsyslog- > > > > > > > > > > > > > [email protected]] On Behalf Of Rodney > > > > > > > > > > > > > McKee > > > > > > > > > > > > > Sent: Monday, July 18, 2011 6:00 AM > > > > > > > > > > > > > To: rsyslog-users > > > > > > > > > > > > > Subject: [rsyslog] timereported:::date-rfc3339 > > > > > > > > > > > > > > > > > > > > > > > > > > What effects the recording of milliseconds when > > > > > > > > > > > > > using > > > > > > > > > > > > > timereported:::date- > > > > > > > > > > > > > rfc3339. > > > > > > > > > > > > > > > > > > > > > > > > This field contains what the sender told us. If > > > > > > > > > > > > the > > > > > > > > > > > > sender > > > > > > > > > > > > sent > > > > > > > > > > > > no > > > > > > > > > > > > ms, we can > > > > > > > > > > > > not report them. Rather than to pretend > > > > > > > > > > > > "x.000000" > > > > > > > > > > > > they > > > > > > > > > > > > are > > > > > > > > > > > > there, we > > > > > > > > > > > > do not > > > > > > > > > > > > give them. Note that for the same reason there > > > > > > > > > > > > may be > > > > > > > > > > > > sub-ms > > > > > > > > > > > > resolution, like > > > > > > > > > > > > us, if that is what the sender reported. > > > > > > > > > > > > > > > > > > > > > > > > Note that starting with the latest v5-devel > > > > > > > > > > > > version > > > > > > > > > > > > AND a > > > > > > > > > > > > recent > > > > > > > > > > > > Linux > > > > > > > > > > > > kernel, we can ask the system for more precise > > > > > > > > > > > > timestamps > > > > > > > > > > > > on > > > > > > > > > > > > messages > > > > > > > > > > > > that > > > > > > > > > > > > come in via the log socket. > > > > > > > > > > > > > > > > > > > > > > > > Rainer > > > > > > > > > > > > > > > > > > > > > > > > > Some log entries get milliseconds and some do > > > > > > > > > > > > > not: > > > > > > > > > > > > > The template: > > > > > > > > > > > > > "%TIMESTAMP% %timereported:::date-rfc3339% > > > > > > > > > > > > > %timegenerated:::date- > > > > > > > > > > > > > rfc3339% %msg%\n" > > > > > > > > > > > > > > > > > > > > > > > > > > The output: > > > > > > > > > > > > > Jul 18 13:58:30 2011-07-18T13:58:30+10:00 > > > > > > > > > > > > > 2011-07-18T13:58:30.723250+10:00 > > > > > > > > > > > > > test > > > > > > > > > > > > > > > > > > > > > > > > > > Am I missing something. > > > > > > > > > > > > > > > > > > > > > > > > > > Rgds > > > > > > > > > > > > > Rodney > > > > > > > > > > > > > _______________________________________________ > > > > > > > > > > > > > rsyslog mailing list > > > > > > > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > > > > > > http://www.rsyslog.com > > > > > > > > > > > > _______________________________________________ > > > > > > > > > > > > rsyslog mailing list > > > > > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > > > > > http://www.rsyslog.com > > > > > > > > > > > > > > > > > > > > > > > _______________________________________________ > > > > > > > > > > > rsyslog mailing list > > > > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > > > > http://www.rsyslog.com > > > > > > > > > > _______________________________________________ > > > > > > > > > > rsyslog mailing list > > > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > > > http://www.rsyslog.com > > > > > > > > > > > > > > > > > > > _______________________________________________ > > > > > > > > > rsyslog mailing list > > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > > http://www.rsyslog.com > > > > > > > > _______________________________________________ > > > > > > > > rsyslog mailing list > > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > > http://www.rsyslog.com > > > > > > > > > > > > > > > _______________________________________________ > > > > > > > rsyslog mailing list > > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > > http://www.rsyslog.com > > > > > > _______________________________________________ > > > > > > rsyslog mailing list > > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > > http://www.rsyslog.com > > > > > > > > > > > _______________________________________________ > > > > > rsyslog mailing list > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > http://www.rsyslog.com > > > > _______________________________________________ > > > > rsyslog mailing list > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > http://www.rsyslog.com > > > > > > > _______________________________________________ > > > rsyslog mailing list > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > http://www.rsyslog.com > > _______________________________________________ > > rsyslog mailing list > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > http://www.rsyslog.com > > > _______________________________________________ > rsyslog mailing list > http://lists.adiscon.net/mailman/listinfo/rsyslog > http://www.rsyslog.com _______________________________________________ rsyslog mailing list http://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com
