Bug 193184 - Confusing timestamp in /var/log/secure (UTC time instead of localtime)
Summary: Confusing timestamp in /var/log/secure (UTC time instead of localtime)
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: openssh
Version: 5
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Tomas Mraz
QA Contact: Brian Brock
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2006-05-25 21:24 UTC by Roberto Ragusa
Modified: 2014-01-21 22:54 UTC (History)
4 users (show)

Fixed In Version: openssh-4.3p2-4.1
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2007-09-24 19:31:19 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
Fix "/etc/init.d/sshd" for symlinked "/etc/localtime" (382 bytes, patch)
2006-09-25 06:54 UTC, Jan Kratochvil
no flags Details | Diff

Description Roberto Ragusa 2006-05-25 21:24:19 UTC
Description of problem:

sshd logs the same message twice in /var/log/secure, one with
a correct timestamp, one with a wrong timestamp (utc)


Version-Release number of selected component (if applicable):

openssh-4.3p2


How reproducible:

100%

Steps to Reproduce:
1. login using ssh
2. look into /var/log/secure
3.
  
Actual results:

Confusing logs.
Note that correct time is 23:01:22.

May 25 21:01:22 gw sshd[11471]: Accepted publickey for xxx from x.x.x.x port
58088 ssh2
May 25 23:01:22 gw sshd[11470]: Accepted publickey for xxx from x.x.x.x port
58088 ssh2


Expected results:

May 25 23:01:22 gw sshd[11471]: Accepted publickey for xxx from x.x.x.x port
58088 ssh2
May 25 23:01:22 gw sshd[11470]: Accepted publickey for xxx from x.x.x.x port
58088 ssh2

Or maybe only the correct line.


Additional info:

Running "strace -f" on the sshd daemon gives the following outut:

[pid  9996] time(NULL)                  = 1148590882
[pid  9996] open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid  9996] open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid  9996] open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid  9996] open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid  9996] send(6, "<86>May 25 21:01:22 sshd[9996]: "..., 94, MSG_NOSIGNAL) = 94


The file /etc/localtime is not found.
This is caused by the chroot command executed earlier:

[pid 9996] chroot("/var/empty/sshd")   = 0

Comment 1 Tomas Mraz 2006-05-26 10:40:29 UTC
The duplicate messages will be removed (there is already upstream patch for
that) however some of the messages with the wrong timestamp are not duplicate
and there is currently no correct fix possible for this problem. Simply copying
/etc/localtime to the chroot is not possible because it would get out of sync if
the timezone on the computer is changed.
Maybe copying it on every sshd restart would be enough but I am not sure and it
would also contradict the /var/empty directory name.


Comment 2 Roberto Ragusa 2006-05-26 12:05:14 UTC
It looks like this /etc/localtime issue comes out every time
one tries to use chrooted daemons.
The bind package copies the file on start.

This /etc/localtime mechanism is definitively not optimal,
for example there is another kind of "out of sync" problem, where
you upgrade the tzdata package, but you still use the
old /etc/localtime (see bug #186742).

Until now, nobody managed to find the "right" solution.


Comment 3 josip 2006-06-05 00:27:48 UTC
This is very annoying.  Some kind of fix is needed -- inconsistent time stamps
in logs obscure the true sequence of events.  Until a better fix is found, here
is an ugly solution:

Create /etc/sysconfig/sshd containing:

# Make sure that sshd gets the TZ environment variable

if [ -z "$TZ" ]; then
  . /etc/sysconfig/clock
  export TZ="$ZONE"
else
  export TZ
fi

# sshd runs chrooted from /var/empty/sshd but needs /etc/localtime

mkdir -p /var/empty/sshd/etc
chown root.root /var/empty/sshd
chown root.root /var/empty/sshd/etc
chmod 755 /var/empty/sshd/etc
chmod 555 /var/empty/sshd
cp -a -f /etc/localtime /var/empty/sshd/etc/

# /etc/localtime leads to timezone definitions under /usr/share/zoneinfo/$TZ
# Make them available under chroot as well

p="/usr/share/zoneinfo/$TZ"
if [ -f "$p" ]; then
  d=`dirname "$p"`
  f=`basename "$p"`
  mkdir -p "/var/empty/sshd$d"
  cp -a -f "$p" "/var/empty/sshd$p"
fi


Comment 4 Allen Kistler 2006-08-13 19:00:16 UTC
FWIW, this bug is also at http://bugzilla.mindrot.org/show_bug.cgi?id=1214 with
"resolved worksforme" as follows:

-- quote --
Actually the TZ environment variable is there but because the privsep
slave is chrooted it does not have access to the /etc/localtime file
that tells how to interpret the TZ string.

The workaround is to create /etc/localtime inside the chroot ("mkdir
/var/empty/etc && cp -a /etc/localtime /var/empty/etc/" if you have the
chroot in the standard place).
-- unquote --

I just put in /etc/sysconfig/sshd ...

# workaround privsep localtime bug #1214
rm -rf /var/empty/sshd/etc
mkdir /var/empty/sshd/etc && cp -p /etc/localtime /var/empty/sshd/etc

... although if something like this is the official OpenSSH resolution, maybe it
could/should be moved into the init script.

Comment 5 Fedora Update System 2006-09-15 01:45:58 UTC
openssh-4.3p2-4.1 has been pushed for fc5, which should resolve this issue.  If these problems are still present in this version, then please make note of it in this bug report.

Comment 6 Mamoru TASAKA 2006-09-15 05:20:46 UTC
openssh-4.3p2-4.1 seems to work well for me.

Comment 7 Fedora Update System 2006-09-19 17:46:55 UTC
openssh-4.3p2-4.1 has been pushed for fc5, which should resolve this issue.  If these problems are still present in this version, then please make note of it in this bug report.

Comment 8 Jan Kratochvil 2006-09-25 06:54:18 UTC
Created attachment 137032 [details]
Fix "/etc/init.d/sshd" for symlinked "/etc/localtime"

It still does not work for me as I am using symlink for "/etc/localtime":
lrwxrwxrwx 1 root root 35 Jan  8  2006 /etc/localtime ->
../usr/share/zoneinfo/Europe/Prague
IIRC it was being used this way before, still I understand it may be considered
NOTABUG as the current FC configuration tools create it as a regular file.

Comment 9 Matthew Miller 2007-03-08 19:30:16 UTC
I think bug #231326 is actually the correct fix for this issue.

Comment 10 Tomas Mraz 2007-03-19 10:47:24 UTC
Yes, that's even better way how to fix the problem.


Comment 11 Jan Kratochvil 2007-03-19 11:05:20 UTC
(In reply to comment #10)
> Yes, that's even better way how to fix the problem.

Verified on
  sysklogd-1.4.2-2.fc7.i386
  openssh-4.5p1-4.fc7.i386
that /etc/localtime symlink bug reopened in my Comment 8 got fixed by sysklogd.

In this case /var/empty/sshd/etc/localtime should be removed from openssh.spec
together with the /etc/rc.d/init.d/sshd line
	cp -af /etc/localtime /var/empty/sshd/etc
to get unified behavior of /etc/localtime symlink vs. regular file machines.


Comment 12 Tomas Mraz 2007-09-24 19:31:19 UTC
Will be removed in the next rawhide build (openssh-4.7p1-3.fc8).



Note You need to log in before you can comment on or make changes to this bug.