[rsyslog] Timestamp wrong...?

Michael Maymann michael at maymann.org
Thu Feb 2 11:18:50 CET 2012


David: thanks for your reply...:-) !
here is my debug output:
# cat /tmp/example.log
6858.610152250:7f9222880700: Switching debugging_on to true at 11:00:58
6861.570630926:7f922086b700: main Q:Reg/w0: inactivity timeout, worker
6861.570684356:7f922086b700: main Q:Reg/w0: receiving command 1
6861.570698744:7f922086b700: main Q:Reg/w0: worker terminating
6861.570713062:7f922086b700: main Q:Reg: Worker thread 7f922439d740,
terminated, num workers now 0
6868.949626982:7f9217fff700: Message from UNIX socket: #4
6868.949710093:7f9217fff700: logmsg: flags 4, from '<HOSTNAME>', msg Feb  2
11:01:08 root: testing123
6868.949723782:7f9217fff700: Message has legacy syslog format.
6868.949742988:7f9217fff700: main Q: entry added, size now 1 entries
6868.949760658:7f9217fff700: wtpAdviseMaxWorkers signals busy
6868.949781261:7f9217fff700: main Q: EnqueueMsg advised worker start
6868.949801655:7f9217fff700: --------imuxsock calling select, active file
descriptors (max 4): 4
6868.949850125:7f922086b700: main Q: entry deleted, state 0, size now 0
6868.949902785:7f922086b700: testing filter, f_pmask 255
6868.949923039:7f922086b700: Called action, logging to builtin-fwd
6868.949948112:7f922086b700:  <IP>
6868.949961661:7f922086b700:  <IP>:514/tcp
6868.950006500:7f922086b700: TCP sent 46 bytes, requested 46
6868.950021306:7f922086b700: testing filter, f_pmask 127
6868.950036741:7f922086b700: Called action, logging to builtin-file
6868.950054830:7f922086b700: file to log to: /var/log/messages
6868.950068309:7f922086b700: doWrite, pData->pStrm 0x7f9224384660, lenBuf 59
6868.950084163:7f922086b700: strm 0x7f9224384660: file 7(messages) flush,
buflen 59
6868.950131027:7f922086b700: strm 0x7f9224384660: file 7 write wrote 59
6868.950148138:7f922086b700: testing filter, f_pmask 0
6868.950160639:7f922086b700: testing filter, f_pmask 0
6868.950173420:7f922086b700: testing filter, f_pmask 0
6868.950185642:7f922086b700: testing filter, f_pmask 1
6868.950198004:7f922086b700: testing filter, f_pmask 0
6868.950210227:7f922086b700: testing filter, f_pmask 0
6868.950223915:7f922086b700: main Q:Reg/w0: worker IDLE, waiting for work.
6928.950336176:7f922086b700: main Q:Reg/w0: inactivity timeout, worker
6928.950385417:7f922086b700: main Q:Reg/w0: receiving command 1
6928.950401831:7f922086b700: main Q:Reg/w0: worker terminating
6928.950419293:7f922086b700: main Q:Reg: Worker thread 7f922439d740,
terminated, num workers now 0

Here is the entry on the syslogclient:
2012-02-02T11:01:08.949694+01:00 <HOSTNAME> root: testing123

Here is the same entry on the syslogserver:
2012-02-02T11:01:08+02:00 <HOSTNAME> root: testing123

It seems the server entry gets <client time>+<server UTC-offset>... is this
really right... ?
Can this be changed to one of the following:
1. <UTC time>+00:00
2. <client time>+<client UTC-offset>
3. <server time>+<server UTC-offset>

Here is my clients /etc/rsyslog.conf:
$ModLoad imtcp
$ModLoad imuxsock # provides support for local system logging
$ModLoad imklog   # provides kernel logging support (previously done by
$ModLoad immark  # provides --MARK-- message capability
*.* @@<IP>:514
# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*                                                 /dev/console
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none                /var/log/messages
# The authpriv file has restricted access.
authpriv.*                                              /var/log/secure
# Log all the mail messages in one place.
mail.*                                                  -/var/log/maillog
# Log cron stuff
cron.*                                                  /var/log/cron
# Everybody gets emergency messages
*.emerg                                                 *
# Save news errors of level crit and higher in a special file.
uucp,news.crit                                          /var/log/spooler
# Save boot messages also to boot.log

Thanks in advance :-) !

2012/2/1 <david at lang.hm>

> On Wed, 1 Feb 2012, Michael Maymann wrote:
>  on my syslog client i have the following time:
>> # date && logger testing123
>> Wed Feb  1 14:42:02 CET 2012
>> what get in my syslog server logs:
>> 2012-02-01T14:42:02+02:00 <HOSTNAME> root: testing123
>> Time on my syslog server:
>> date
>> Wed Feb  1 15:42:02 EET 2012
>> according to http://www.timezoneconverter.**com/cgi-bin/tzc.tzc<http://www.timezoneconverter.com/cgi-bin/tzc.tzc>and my
>> calculations it should have been either:
>> 2012-02-01T14:42:02+01:00 <HOSTNAME> root: testing123 (if keeping client
>> timestamp)
>> or
>> 2012-02-01T15:42:02+02:00 <HOSTNAME> root: testing123 (if keeping server
>> timestamp)
>> or
>> 2012-02-01T13:42:02+00:00 <HOSTNAME> root: testing123 (if keeping UTC
>> timestamp)
>> I would prefer client timestamp... Is this a bug or have I completely
>> misunderstood something... ?
>> How do I change to correct client timestamp ?
> timereported is the time that the client put in the log (with whatever
> precision and timezone that the client reported it in)
> timegenerated is the timestamp that the server received the log (high
> precision timestamp in the server's timezone)
> $now is the time the log is being written
> check and see what the clients are sending (writing a log from a
> particular client using the format RSYSLOG_DEBUG is a wonderful
> troubleshooting tool)
> by default, the syslog format tries to keep the timestamp the client
> provides.
> I'm a huge proponent of running all production systems in GMT/UTC it
> avoids a huge number of issues along the way.
> David Lang
> ______________________________**_________________
> rsyslog mailing list
> http://lists.adiscon.net/**mailman/listinfo/rsyslog<http://lists.adiscon.net/mailman/listinfo/rsyslog>
> http://www.rsyslog.com/**professional-services/<http://www.rsyslog.com/professional-services/>

More information about the rsyslog mailing list