SSH syslog lines disordered

Hello,

Would anyone know why the syslog generated by SSHD is
jumping around in 
time?
The date/time tags are after all created by the syslog
daemon, so the 
date/time should be
monotonically increasing. Instead, I see this, with lines
marked 03:00 
coming after
lines marked 05:00 etc. I should probably mention that
syslogd is 
configured to "not flush"
the log after each line, but that should have not influence,
shouldn't it?

Apr 16 02:30:03 MACHINE logrotate: postrotate
Apr 16 05:14:32 MACHINE sshd[1867]: Connection from
::ffff:127.0.0.1 
port 43314
Apr 16 05:14:32 MACHINE sshd[1868]: Failed none for root
from 
::ffff:127.0.0.1 port 43314 ssh2
Apr 16 05:14:32 MACHINE sshd[1867]: Found matching RSA key:

b8:04:1c:94:1e:61:cd:0a:ca:df:3c:5b:b3:45:c6:8a
Apr 16 03:14:32 MACHINE sshd[1868]: Postponed publickey for
root from 
::ffff:127.0.0.1 port 43314 ssh2
Apr 16 05:14:33 MACHINE sshd[1867]: Found matching RSA key:

b8:04:1c:94:1e:61:cd:0a:ca:df:3c:5b:b3:45:c6:8a
Apr 16 03:14:33 MACHINE sshd[1868]: Accepted publickey for
root from 
::ffff:127.0.0.1 port 43314 ssh2
Apr 16 05:14:33 MACHINE sshd[1867]: Accepted publickey for
root from 
::ffff:127.0.0.1 port 43314 ssh2
Apr 16 05:16:49 MACHINE sshd[1867]: Connection closed by
::ffff:127.0.0.1
Apr 16 05:16:49 MACHINE sshd[1867]: Closing connection to
::ffff:127.0.0.1
Apr 16 09:15:13 MACHINE sshd[2685]: Connection from
::ffff:127.0.0.1 
port 43369
Apr 16 09:15:13 MACHINE sshd[2686]: Failed none for root
from 
::ffff:127.0.0.1 port 43369 ssh2
Apr 16 09:15:13 MACHINE sshd[2685]: Found matching RSA key:

b8:04:1c:94:1e:61:cd:0a:ca:df:3c:5b:b3:45:c6:8a
Apr 16 07:15:13 MACHINE sshd[2686]: Postponed publickey for
root from 
::ffff:127.0.0.1 port 43369 ssh2
Apr 16 09:15:13 MACHINE sshd[2685]: Found matching RSA key:

b8:04:1c:94:1e:61:cd:0a:ca:df:3c:5b:b3:45:c6:8a
Apr 16 07:15:13 MACHINE sshd[2686]: Accepted publickey for
root from 
::ffff:127.0.0.1 port 43369 ssh2
Apr 16 09:15:13 MACHINE sshd[2685]: Accepted publickey for
root from 
::ffff:127.0.0.1 port 43369 ssh2
Apr 16 09:17:26 MACHINE sshd[2685]: Connection closed by
::ffff:127.0.0.1
Apr 16 09:17:26 MACHINE sshd[2685]: Closing connection to
::ffff:127.0.0.1
Apr 16 10:14:18 MACHINE sshd[2914]: Connection from
::ffff:XX.XX.XX.XX 
port 49328
Apr 16 10:14:21 MACHINE sshd[2915]: Failed none for root
from 
::ffff:XX.XX.XX.XX port 49328 ssh2
Apr 16 08:14:48 MACHINE sshd[2915]: Accepted password for
root from 
::ffff:XX.XX.XX.XX port 49328 ssh2
Apr 16 10:14:48 MACHINE sshd[2914]: Accepted password for
root from 
::ffff:XX.XX.XX.XX port 49328 ssh2


Any help appreciated,

-- David


-- 
redhat-list mailing list
unsubscribe mailto:redhat-list-requestredhat.com?subject=unsubscribe
h
ttps://www.redhat.com/mailman/listinfo/redhat-list

> Hello,
> 
> Would anyone know why the syslog generated by SSHD is
jumping 
> around in time?
> The date/time tags are after all created by the syslog

> daemon, so the date/time should be monotonically
increasing. 
> Instead, I see this, with lines marked 03:00 coming
after 
> lines marked 05:00 etc. I should probably mention that

> syslogd is configured to "not flush"
> the log after each line, but that should have not
influence, 
> shouldn't it?
> 

If you're experiencing the same problem I had a few months
ago, it is a
reported bug https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=
203671

The fix still seems to be pending.

The way I got around it is to create a hard link between
/var/empty/sshd/etc/localtime (needed to create a few of
those directories)
to /etc/localtime. syslog uses the timezone of the client
logging in.  The
hard link creates a link between the localtime and the
chroot'ed localtime.
I use a hard link because I'm not sure how a symbolic link
would work
through a chroot and a simple copy would lose any new
modifications to
/etc/localtime.  It corrects the time issue (useful if
you're running a
script that uses the time) but you still get duplicate
messages.  Works for
me.

Michael


-- 
redhat-list mailing list
unsubscribe mailto:redhat-list-requestredhat.com?subject=unsubscribe
h
ttps://www.redhat.com/mailman/listinfo/redhat-list

David Tonhofer wrote:

> Hello,
>
> Would anyone know why the syslog generated by SSHD is
jumping 
> around in time?
> The date/time tags are after all created by the syslog

> daemon, so the date/time should be monotonically
increasing. 
> Instead, I see this, with lines marked 03:00 coming
after 
> lines marked 05:00 etc. I should probably mention that

> syslogd is configured to "not flush"
> the log after each line, but that should have not
influence, 
> shouldn't it?
>
>   

Michael Velez wrote:
>
> If you're experiencing the same problem I had a few
months ago, it is a
> reported bug https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=
203671
>
> The fix still seems to be pending.
>
> The way I got around it is to create a hard link
between
> /var/empty/sshd/etc/localtime (needed to create a few
of those directories)
> to /etc/localtime. syslog uses the timezone of the
client logging in.  The
> hard link creates a link between the localtime and the
chroot'ed localtime.
> I use a hard link because I'm not sure how a symbolic
link would work
> through a chroot and a simple copy would lose any new
modifications to
> /etc/localtime.  It corrects the time issue (useful if
you're running a
> script that uses the time) but you still get duplicate
messages.  Works for
> me.
>
> Michael
>   

Thank you Michael ... that's it I guess. Will try the fix
later today.

Best regards,

-- David



-- 
redhat-list mailing list
unsubscribe mailto:redhat-list-requestredhat.com?subject=unsubscribe
h
ttps://www.redhat.com/mailman/listinfo/redhat-list