Home / server / Questions / 113776
Accepted
pehrs
Asked: 2010-02-18 05:43:35 +0800 CST

syslog (auth log) reports incorrect time

  • 772

I have noticed that my syslog reports incorrect time for some authentication entries. The typical behaviour looks like this: 

Feb 16 13:32:20 dev sshd[29537]: Invalid user oracle from 110.188.0.123
Feb 16 12:32:20 dev sshd[29538]: input_userauth_request: invalid user oracle
Feb 16 13:32:20 dev sshd[29537]: pam_unix(sshd:auth): check pass; user unknown
Feb 16 13:32:20 dev sshd[29537]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=110.188.0.123
Feb 16 13:32:20 dev sshd[29537]: pam_succeed_if(sshd:auth): error retrieving information about user oracle
Feb 16 13:32:22 dev sshd[29537]: Failed password for invalid user oracle from 110.188.0.123 port 64368 ssh2
Feb 16 12:32:23 dev sshd[29538]: Received disconnect from 110.188.0.123: 11: Bye Bye

Notice how the hour swaps back and forth. Has anybody seen a similar behaviour? What might cause this? It seems systematic and it's the same entries for each connection attempt that are reported an hour earlier than they should be. System clock is GMT. Timezone GMT+1.

time ssh timezone syslog

2 Answers

  1. Best Answer

    Note that one process 29537 always sends messages marked one hour later than process 29538. Syslog protocol specifies that clients send messages timestamped in a textual MMM DD HH:MM:SS format, not a wise thing at all.

    On UNIX/Linux there is one system time (number of seconds since 1970), but each process on a system can interpret it as if it was placed in a different timezone. How this is handled, each process that wants to convert number-of-seconds to the actual HH:MM:SS text, first reads $TZ environment variable. Because each process has its very own separate environment, each process can have a different value of $TZ and display dates from a different time zone.

    On your system, if $TZ has been changed in /etc/environment, but sshd process has not been restarted since that time, it will use the original $TZ. So please restart all sshd processes and repeat your test.

    • 1

  2. You don't happen to have two syslog daemon running at the same time, one of which has not been configured properly (i.e. you changed the time when the daylight saving came into effect and did not restart it)? Then a race condition affects which daemon intercepts the syscall and writes to disk.

    • 0