[syslog-ng] Millisecond Resolution Timestamps

[David Hauck]

Hi Balazs,
 
On Sunday, April 20, 2014 7:33 AM, you  wrote:
> On Apr 15, 2014 8:33 PM, "David Hauck" <davidh at netacquire.com> wrote:
>> 
>> On Tuesday, April 15, 2014 11:10 AM,
> syslog-ng-bounces at lists.balabit.hu wrote:
>>> If you are using the S_* macros then you will get the time stamp 
>>> that the application places into the log line. That is usually a 
>>> time stamp with no subsecond data.
>> 
>> I'm curious about why this is? You mention this "usually"  contains 
>> no
> sub-second granularity: under what conditions is this not true (i.e., 
> when would this actually contain sub-second granularity)?
> 
> The syslog() API doesn't send such timestamps. So unless the app has a 
> custom log implementation, no such information becomes available.

OK, ya, I see that the gLibC implementation uses localtime() while formatting the (syslog) text string that contains the timestamp prior to forwarding. Odd that this restriction exists given the ability (RFC 5424) to include higher precision timestamps in the syslog message.

Thanks,
-David

>>> If you use the R_* macros for your date/time then you should get the 
>>> subsecond resolution.
>> 
>> Thanks, I'm using ISODATE in my custom template (just like the 
>> default
> template). Looking closely I see that I can use the S_ and R_ variants 
> with this macro. Changing my template to use "R_ISODATE" does indeed fix this.
>> 
>> Thanks again for the quick tip!
>> 
>>> On 04/15/2014 10:31 AM, David Hauck wrote:
>>>> Hello,
>>>> 
>>>> I'm using the following global options in order to format messages 
>>>> with millisecond resolution:
>>>> 
>>>>    ts_format(iso);
>>>>    frac_digits(3);
>>>> Although the initial (syslog-ng starting) message appears to 
>>>> include
>>>> sub- second resolution subsequent messages do not:
>>>> 
>>>> 20140415 10:19:23.590 notice syslog(syslog-ng):syslog-ng starting 
>>>> up; version='3.5.4.1' ... 20140415 10:19:33.000 notice 
>>>> authpriv(su):FAILED su for test by root ... 20140415 10:20:11.000 
>>>> notice user(root):test
>>>> 
>>>> This includes messages originating from any number of sources 
>>>> (including
>>> all processes that log via syslog()), *except* messages originating 
>>> from the kernel (these always seem to have sub-second resolution).
>>> Does anyone have any ideas what might be going on here?
>>>> 
>>>> Thanks,
>>>> -David
>>>> 
>>>> PS: the timestamp formatting above is done via a simple template.
>>> Regardless of this (re-)formatting nominal iso messages also exhibit 
>>> this limitation. For e.g.,:
>>>> 
>>>> 2014-04-14T15:23:48.000-07:00 host99738728 nasysconfd: exit code
>>>> 0 for /netacquire/bin/sysconf/osinfo read
>>>> 
>>>> 
>>>> 
>>> 
>>> __________________________________________________________ 
>>> ____________
>>>> ________ Member info:
>>>> https://lists.balabit.hu/mailman/listinfo/syslog-ng
>>>> Documentation:
>>>> http://www.balabit.com/support/documentation/?product=syslog-ng
>>>> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>>>> 
>>> 
>>> 
>> 
> __________________________________________________________
> ______________ ______
>> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
>> Documentation:
>> http://www.balabit.com/support/documentation/?product=syslog-ng FAQ:
>> http://www.balabit.com/wiki/syslog-ng-faq
>> 
>