Bug 712151

Summary: Some entries into /var/log/secure are done with incorrect time zone.
Product: [Fedora] Fedora Reporter: Erik Squires <erik_squires>
Component: rsyslogAssignee: Tomas Heinrich <theinric>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 15CC: h1k6zn2m, jose.p.oliveira.oss, mattias.ellert, mgrepl, mrunge, pvrabec, rayvd, rtc, rvokal, silfreed, theinric, tmraz
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: rsyslog-5.8.7-1.fc15 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-02-28 14:00:27 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Erik Squires 2011-06-09 15:37:17 UTC
Description of problem:
The issue is that two messages, "Received disconnect from" and "Connection closed by" message seems to use a different timezone than other messages inserted into secure. 

This appears to be an old issue.  See:  http://www.fedoraforum.org/forum/archive/index.php/t-106710.html but I could not find a matching bug for it. 

Version-Release number of selected component (if applicable):
Kernel info: 2.6.38.7-30.fc15.x86_64 #1 SMP Fri May 27 05:15:53 UTC 2011
openssh-server-5.6p1-31.fc15.1.x86_64
syslog 3.2.4-3 (Not sure if this is even used)

How reproducible:
Every time. 

Steps to Reproduce:
1. Install clean Fedora 15
2. Enable sshd
3. Disable root for remote login
3. Go to a remote machine, ssh to server as root (or anything else)
4. Enter root/boguspassword
5. Note taht using ssh client I get "connection closed" instead of "Received disconnect" but the bad time stamp behavior is the  same. 
6. Examine /var/logs/secure
  
Actual results:
Below is a recent snippet of a break in attempt.  The actual time was around 4 AM East Coast Time, but then the disconnects appear to be UTC:

Jun  9 04:23:43 snape sshd[28460]: Failed password for root from 178.209.106.124 port 51759 ssh2
Jun  9 08:23:43 snape sshd[28461]: Received disconnect from 178.209.106.124: 11: Bye Bye
Jun  9 04:23:44 snape sshd[28463]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.209.106.
124  user=root
Jun  9 04:23:46 snape sshd[28463]: Failed password for root from 178.209.106.124 port 52455 ssh2
Jun  9 08:23:46 snape sshd[28464]: Received disconnect from 178.209.106.124: 11: Bye Bye
Jun  9 04:23:47 snape sshd[28466]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.209.106.
124  user=root
Jun  9 04:23:49 snape sshd[28466]: Failed password for root from 178.209.106.124 port 53279 ssh2
Jun  9 08:23:50 snape sshd[28467]: Received disconnect from 178.209.106.124: 11: Bye Bye
Jun  9 04:23:51 snape sshd[28469]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=178.209.106.
124  user=root


Expected results:
All entries should be chronological and in same time zone. 

Additional info:

Comment 1 Matthias Runge 2011-06-10 09:46:19 UTC
could you please append the output of
 
systemctl status syslog-ng.service

Thanks.

Comment 2 Erik Squires 2011-06-10 13:01:17 UTC
syslog-ng.service
          Loaded: error
          Active: inactive (dead)

Comment 3 Matthias Runge 2011-06-15 06:59:51 UTC
ok, reading this, I  assume, syslog-ng isn't running. You may verify it by issuing systemctl rsyslog.service. (I guess, it's running).

To your problem: I think, there is a misconfiguration or misbehaviour in sshd. 
I see the same problem, using syslog-ng. 

Reassigning this bug to openssh component.

Comment 4 Tomas Mraz 2011-06-15 07:19:35 UTC
Actually this should be handled correctly in rsyslog and I think it is a regression in it.

See bug 231326 where the same problem was fixed in the old sysklogd package.

Comment 5 Tomas Mraz 2011-06-15 07:21:29 UTC
Basically when the syslog daemon receives a message from the local syslog socket it should discard the timestamp and use its own one.

Comment 6 Matthias Runge 2011-06-15 07:26:49 UTC
OK, thank you for the info.

I'll contact syslog-ng upstream. Seems to happen there, too.

Comment 7 Matthias Runge 2011-06-20 06:37:34 UTC
There is an option for syslog-ng to keep incoming messages in sync with server time zone:

http://www.balabit.com/wiki/syslog-ng-faq-timestamp-sync

Comment 8 Tomas Mraz 2011-06-20 06:43:36 UTC
OK, but what about rsyslog which is still the default system logging daemon?

Note this bug is assigned to rsyslog.

Comment 9 Matthias Runge 2011-06-20 06:53:16 UTC
Oops, I'm sorry. You're right.

Comment 10 Tomas Heinrich 2012-02-28 13:55:50 UTC
*** Bug 738364 has been marked as a duplicate of this bug. ***