Bug 203671

Summary: additional (time skewed) log entries in /var/log/secure since U4
Product: Red Hat Enterprise Linux 4 Reporter: Neelesh Arora <narora>
Component: opensshAssignee: Tomas Mraz <tmraz>
Status: CLOSED ERRATA QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: 4.0CC: abulava, andy.clyde, jed, kindyjd, mattdm, nhruby, pb, redbugme3210, suzuki-t, tao
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: RHSA-2007-0257 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2007-05-01 17:29:54 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 Neelesh Arora 2006-08-22 22:48:03 UTC
Description of problem:
Since the update of openssh to 3.9p1-8.RHEL4.15 (part of U4), I am seeing the
following message pattern in /var/log/secure on RHEL4 machines whenever a user
logs in via ssh:

====================
Aug 21 22:46:39 host1 sshd[16318]: Postponed publickey for root from
::ffff:a.b.c.d port 35647 ssh2
Aug 21 18:46:39 host1 sshd[16317]: Accepted publickey for root from
::ffff:a.b.c.d port 35647 ssh2
Aug 21 22:46:39 host1 sshd[16318]: Accepted publickey for root from
::ffff:a.b.c.d port 35647 ssh2
Aug 21 19:07:15 host1 sshd[19690]: Accepted password for userbob from
::ffff:a.b.c.d port 43561 ssh2
Aug 21 23:07:15 host1 sshd[19691]: Accepted password for userbob from
::ffff:a.b.c.d port 43561 ssh2
==================== 

The 'actual' logins happened at 18:46 and 19:07 above.

There is an additional entry for both the regular user and for root, which has a
timestamp of +4 hours (GMT? I am in EDT). Also, only for root, there is a second
additional entry which reports Postponed login.

The ssh login has no issues in itself, but for these unwanted entries. A
side-effect of this is that logwatch catches the Postponed authentication
messages and reports them also as illegal login attempts.

Version-Release number of selected component (if applicable):
openssh-3.9p1-8.RHEL4.15 (on both server and client side)

How reproducible:
Always

Steps to Reproduce:
1. Install openssh version 3.9p1-8.RHEL4.15, on both server and client side
(with dependencies)
2. ssh from client to server
3. Observe additional entries in /var/log/secure on server
  
Actual results:
2 entries for each successful login (one with +4 hours timestamp) for regular
user. 3 entries for root.

Expected results:
1 entry for each successful login, with correct timestamp

Additional info:

Comment 1 Tomas Mraz 2006-08-23 10:29:24 UTC
This is a consequence of fixing a real bug in SSHD where it was not logging some
failure messages when running in PrivilegeSeparation mode. The 'Postponed
publickey' message is one of them. Logwatch should not report this as a login
failure, this is a bug in logwatch and should be reported against it.

The other two problems - wrong timestamp and duplicate messages are a real bug
however low severity ones.

The wrong timestamp is caused by /etc/localtime missing in /var/empty/sshd
chroot. Workaround: you can copy it there from /etc.


Comment 2 Tomas Mraz 2006-08-31 06:57:32 UTC
*** Bug 204720 has been marked as a duplicate of this bug. ***

Comment 3 RHEL Program Management 2006-08-31 15:16:56 UTC
This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux maintenance release.  Product Management has requested
further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed
products.  This request is not yet committed for inclusion in an Update
release.

Comment 5 Tomas Mraz 2006-09-07 06:41:16 UTC
*** Bug 205528 has been marked as a duplicate of this bug. ***

Comment 8 Charlie Wyse 2006-09-20 15:07:35 UTC
I tried placing a copy of /etc/localtime into /var/empty/sshd/ and this did not
work.  However after looking at another bugzilla 1214 I found the solution to be
to copy /etc/localtime to /var/empty/etc/.  

Here is the other bugzilla
http://bugzilla.mindrot.org/show_bug.cgi?id=1214

Comment 9 Neelesh Arora 2006-09-21 13:42:16 UTC
(In reply to comment #1)
> This is a consequence of fixing a real bug in SSHD where it was not logging some
> failure messages when running in PrivilegeSeparation mode. The 'Postponed
> publickey' message is one of them. Logwatch should not report this as a login
> failure, this is a bug in logwatch and should be reported against it.
> 

The 'Postponed publickey' message that I am getting is in response to a valid
login not a failed attempt. It is, at best, a misleading message. To me it looks
like that in the attempt to fix some other bug, a false negative got introduced
into the process.

> The other two problems - wrong timestamp and duplicate messages are a real bug
> however low severity ones.
> 
> The wrong timestamp is caused by /etc/localtime missing in /var/empty/sshd
> chroot. Workaround: you can copy it there from /etc.
> 

The wrong timestamp message is still there, even after copying /etc/localtime in
/var/empty/sshd or /var/empty/etc/ (as reported by Charlie Wyse) and restarting
sshd. Am I missing something here?

-Neel

Comment 10 Tomas Mraz 2006-09-21 19:02:03 UTC
It should be /var/empty/sshd/etc/


Comment 11 Tomas Mraz 2006-10-05 08:51:26 UTC
Fixed in openssh-3.9p1-8.RHEL4.18

Comment 13 Tomas Mraz 2006-10-23 12:16:49 UTC
*** Bug 211821 has been marked as a duplicate of this bug. ***

Comment 15 Tomas Mraz 2006-10-25 09:15:19 UTC
*** Bug 212132 has been marked as a duplicate of this bug. ***

Comment 17 Jeremy Kindy 2006-11-20 17:13:58 UTC
Please note that this is still an issue on x64 RHEL4.4 with openssh
3.9p1-8.RHEL4.17.1 (Install Date: Thu 16 Nov 2006), but not on i686
(3.9p1-8.RHEL4.17, Install Date: Fri Oct  6 2006)

Actual results:
Nov 20 13:55:24 host1 sshd[24706]: Accepted password for kindyjd from
::ffff:xxx.xxx.xxx.xxx port 32790 ssh2
Nov 20 08:55:24 host1 sshd[24705]: Accepted password for kindyjd from
::ffff:xxx.xxx.xxx.xxx port 32790 ssh2

Expected results:
Nov 20 08:55:24 host1 sshd[24705]: Accepted password for kindyjd from
::ffff:xxx.xxx.xxx.xxx port 32790 ssh2

Comment 18 Peter Bieringer 2006-12-13 12:16:16 UTC
This bug hit me also. Is there timeframe for the release of
openssh-3.9p1-8.RHEL4.18 available?

Comment 19 Drew Northup 2007-03-01 15:03:57 UTC
As of March 1, 2007, this is still release pending. Considering that consistent
logs are a legal requirement for some people this isn't a "minor" problem. So,
again, when can we expect this updated daemon release? 
(If the answer is: "you'll have to upgrade to RHEL 5 to get it," I'm sure there
will be a lot of angry people out there....)
Also, worthy of note, the machines I deal with that have this problem are i686,
so it is still a problem there on 8.RHEL4.17.1.

Comment 20 Matthew Miller 2007-03-08 19:27:41 UTC
I think the real fix for the problem is found in bug #231326, especially if you
are considering the consistent-logs-as-a-potential-requirement issue.


Comment 23 Red Hat Bugzilla 2007-05-01 17:29:54 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on the solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2007-0257.html


Comment 24 bato 2007-11-02 09:25:00 UTC
cp -p /etc/localtime /var/empty/sshd/etc/ it is ok ?, so need restart sshd ?