Re: Future timestamps in /var/log/secure

2010-02-26 Thread Wade Peacock

That does make sense. I will try to simulate that with a temporary
virtual machine as a different timezone.

Wade

aha! there you go, mine doesn't but maybe yours does?


The specification for the syslog protocol is that timestamps embedded in
the message should be used instead of syslogd's time.  Most syslog
daemons as a result apply this concept to both local and remote
messages.

You have to keep in mind that syslogd can also send/receive messages
to/from remote destinations.

William






Re: Future timestamps in /var/log/secure

2010-02-26 Thread Wade Peacock

It might be prudent to mention that all of the connections of this type are
null routed via an iptables drop rule after three failed attempts via a "home
grown" daemon similar to DENYHOSTS. All traffic from host is DENIED for 120 days
unless we manually over ride it.

I do appreciate the cautionary, "better have a look around just to be sure" 
comments

Wade





Re: Future timestamps in /var/log/secure

2010-02-26 Thread Seth Mattinen
On 2/26/2010 11:46, William Pitcock wrote:
> On Fri, 2010-02-26 at 19:30 +, gordon b slater wrote:
>> On Fri, 2010-02-26 at 13:17 -0600, William Pitcock wrote:
>>> The syslog message sent to the local unix socket (/dev/log
>>> or /dev/syslog) may contain a timestamp, in which case, that timestamp
>>> may be used instead of the local time.  As the syslog protocol defines
>>> that timestamps are localtime, without any specification of what
>>> timezone localtime actually is, the TZ environment variable of the
>>> application calling syslog() will affect the timestamp placed in the
>>> log.
>>
>> aha! there you go, mine doesn't but maybe yours does?
> 
> The specification for the syslog protocol is that timestamps embedded in
> the message should be used instead of syslogd's time.  Most syslog
> daemons as a result apply this concept to both local and remote
> messages.
> 
> You have to keep in mind that syslogd can also send/receive messages
> to/from remote destinations.
> 

It's easier to see these timezone issues when using an ISO timestamp
like "2010-02-26T06:26:17-08:00" instead of the old style that omits the
timezone.

~Seth



Re: Future timestamps in /var/log/secure

2010-02-26 Thread William Pitcock
On Fri, 2010-02-26 at 19:30 +, gordon b slater wrote:
> On Fri, 2010-02-26 at 13:17 -0600, William Pitcock wrote:
> > The syslog message sent to the local unix socket (/dev/log
> > or /dev/syslog) may contain a timestamp, in which case, that timestamp
> > may be used instead of the local time.  As the syslog protocol defines
> > that timestamps are localtime, without any specification of what
> > timezone localtime actually is, the TZ environment variable of the
> > application calling syslog() will affect the timestamp placed in the
> > log.
> 
> aha! there you go, mine doesn't but maybe yours does?

The specification for the syslog protocol is that timestamps embedded in
the message should be used instead of syslogd's time.  Most syslog
daemons as a result apply this concept to both local and remote
messages.

You have to keep in mind that syslogd can also send/receive messages
to/from remote destinations.

William




Re: Future timestamps in /var/log/secure

2010-02-26 Thread Valdis . Kletnieks
On Fri, 26 Feb 2010 10:51:43 PST, Wade Peacock said:
> It is classic syslogd
> syslogd -v
> 
> 
> syslogd 1.4.1
> 
> I was thinking timezone but we are PST (-8:00) so I can not explain the
> +12:00 difference.

Feb 26 09:50:38 mx sshd[19102]: 
Feb 26 17:50:38 mx sshd[19113]: 

That's 8 hours difference, one logged in UTC, one in local. Where do you
see +12?


pgp58vMmMVTIO.pgp
Description: PGP signature


Re: Future timestamps in /var/log/secure

2010-02-26 Thread gordon b slater
On Fri, 2010-02-26 at 13:17 -0600, William Pitcock wrote:
> On Fri, 2010-02-26 at 11:29 -0700, Brielle Bruns wrote:
> > Isn't the timestamps inserted by syslog rather then the reporting 
> > program itself?
> 
> The syslog message sent to the local unix socket (/dev/log
> or /dev/syslog) may contain a timestamp, in which case, that timestamp
> may be used instead of the local time.  As the syslog protocol defines
> that timestamps are localtime, without any specification of what
> timezone localtime actually is, the TZ environment variable of the
> application calling syslog() will affect the timestamp placed in the
> log.

aha! there you go, mine doesn't but maybe yours does?

Gord
--
tic toc





Re: Future timestamps in /var/log/secure

2010-02-26 Thread Brielle Bruns
If someone wants to do testing, I believe I can fairly easily build a Xen 
CentOS domU once I get home (30 mins).  Contact me offlist and we'll figure it 
out.

--Original Message--
From: gordon b slater
To: wade.peac...@sunwave.net
Cc: nanog@nanog.org
ReplyTo: gordsla...@ieee.org
Subject: Re: Future timestamps in /var/log/secure
Sent: Feb 26, 2010 12:23 PM

On Fri, 2010-02-26 at 10:51 -0800, Wade Peacock wrote:
> I was thinking timezone but we are PST (-8:00) so I can not explain
> the
> +12:00 difference.

whois gives India? 12 hrs maybe? From a brief recon of it looks a bit,
shall we say,  "soft" - get your hat on just in case.

I can confirm that changing my time on the ssh client machine end does
not reproduce this on my Debain machines, no matter where the entries
are logged to.

Sorry I don't have any RH/Centos I can test with at this time of day,
even virtualised - anyone ?

Gord

--
incoming!




-- 
Brielle Bruns
http://www.sosdg.org  /  http://www.ahbl.org

Re: Future timestamps in /var/log/secure

2010-02-26 Thread gordon b slater
On Fri, 2010-02-26 at 10:55 -0800, Wade Peacock wrote:
> the proftpd line happened to be the next line in the log.  the
> next simular ssh lines looks like (duplicate removed)
> 
> Feb 26 10:08:48 mx sshd[22165]: Did not receive identification string from 
> UNKNOWN
> Feb 26 10:09:27 mx sshd[22261]: Failed password for root from 219.137.192.231 
> port 54111 ssh2

is it possible that a local user changed the time (maybe with a GUI app)
around the time of these attempts?

(failed attempts like this are normal for a machine hooked to the
internet without ACLs BTW, the problem is the strange timestamp <

Re: Future timestamps in /var/log/secure

2010-02-26 Thread gordon b slater
On Fri, 2010-02-26 at 10:51 -0800, Wade Peacock wrote:
> I was thinking timezone but we are PST (-8:00) so I can not explain
> the
> +12:00 difference.

whois gives India? 12 hrs maybe? From a brief recon of it looks a bit,
shall we say,  "soft" - get your hat on just in case.

I can confirm that changing my time on the ssh client machine end does
not reproduce this on my Debain machines, no matter where the entries
are logged to.

Sorry I don't have any RH/Centos I can test with at this time of day,
even virtualised - anyone ?

Gord

--
incoming!




Re: Future timestamps in /var/log/secure

2010-02-26 Thread William Pitcock
On Fri, 2010-02-26 at 11:29 -0700, Brielle Bruns wrote:
> Isn't the timestamps inserted by syslog rather then the reporting 
> program itself?

The syslog message sent to the local unix socket (/dev/log
or /dev/syslog) may contain a timestamp, in which case, that timestamp
may be used instead of the local time.  As the syslog protocol defines
that timestamps are localtime, without any specification of what
timezone localtime actually is, the TZ environment variable of the
application calling syslog() will affect the timestamp placed in the
log.

William




Re: Future timestamps in /var/log/secure

2010-02-26 Thread Wade Peacock

the proftpd line happened to be the next line in the log.  the
next simular ssh lines looks like (duplicate removed)

Feb 26 10:08:48 mx sshd[22165]: Did not receive identification string from 
UNKNOWN
Feb 26 10:09:27 mx sshd[22261]: Failed password for root from 219.137.192.231 
port 54111 ssh2




Been a long time since I've dealt with this stuff, but it looks like the
shell for proftpd has a different TZ from the one running the other
stuff.  (syslogd runs in the shell of the caller, right?)





Re: Future timestamps in /var/log/secure

2010-02-26 Thread Wade Peacock

It is classic syslogd
syslogd -v


syslogd 1.4.1

I was thinking timezone but we are PST (-8:00) so I can not explain the
+12:00 difference.



Isn't the timestamps inserted by syslog rather then the reporting
program itself?

What syslog do you use - classic (ie: sysklogd) or a modern one like
rsyslog? It almost looks like the timezone got changed from local to GMT
or similar, then swapped back (as odd as it may sound).

Perhaps time to file a bug report with the author of the syslog daemon
you use?






Re: Future timestamps in /var/log/secure

2010-02-26 Thread gordon b slater
On Fri, 2010-02-26 at 11:29 -0700, Brielle Bruns wrote:

> Isn't the timestamps inserted by syslog rather then the reporting 
> program itself?
> 
that's my understanding also (clarification: syslogs of your server have
timestamps of your syslegsserver's time, IMHO)
eg: on my Debain systems I don't split the logging to /var/log/secure, I
can usually handle a large log OK, but it's easy enough to get the
authpriv* stuff to log to /v/l/secure if needed. So, my point is,
syslogd.conf tells syslogd where to put them, and it stamps the time for
each entry.

> What syslog do you use - classic (ie: sysklogd) or a modern one like 
> rsyslog?  It almost looks like the timezone got changed from local to 
> GMT or similar, then swapped back (as odd as it may sound).


On a cautionary note, I've seen tz-change shenanigans to mask
unauthorised access before, so might be a good time to have quick poke
around with a tinfoil hat on, just in case. Don't have a  heart attack
tough, not yet :)

Gord

--
this .sig space reserved by ITU-T pending clarification of intentions





RE: Future timestamps in /var/log/secure

2010-02-26 Thread Joe


I happend upon this ( https://bugzilla.redhat.com/show_bug.cgi?id=193184 )
which seems to suggest/explain the occurrence. I know it was mentioned to be
in the CentOS distro, but I think this might have been adopted into that
distro as well since I see the same issues on a RedHat Distro. Not sure if
the article helps or hinders but good food for thought.

-Joe Blanchard

-Original Message-
From: Brielle Bruns [mailto:br...@2mbit.com] 
Sent: Friday, February 26, 2010 1:29 PM
To: nanog@nanog.org
Subject: Re: Future timestamps in /var/log/secure


On 2/26/10 11:20 AM, Wade Peacock wrote:
> I found a while ago in /var/log/secure that for an invalid ssh login 
> attempt the ssh Bye Bye line is in the future. I have searched the web 
> and can not find a reason for the future time in the log.
>
> Here is a sample. Repeated lines are shown once in first part
>
>
> Feb 26 17:50:38 mx sshd[19115]: Received disconnect from
> 210.212.145.152: 11: Bye Bye
> Feb 26 17:50:38 mx sshd[19118]: Received disconnect from
> 210.212.145.152: 11: Bye Bye
> Feb 26 09:52:39 mx proftpd[17297]: mx.example.com
> (208.xxx.xxx.xxx[208.xxx.xxx.xxx]) - FTP no transfer timeout, 
> disconnected
>
> Can anyone explain the future time stamp on the Bye Bye lines?
>
> OS is Centos 5.4, FYI
>



Isn't the timestamps inserted by syslog rather then the reporting 
program itself?

What syslog do you use - classic (ie: sysklogd) or a modern one like 
rsyslog?  It almost looks like the timezone got changed from local to 
GMT or similar, then swapped back (as odd as it may sound).

Perhaps time to file a bug report with the author of the syslog daemon 
you use?


-- 
Brielle Bruns
The Summit Open Source Development Group
http://www.sosdg.org/ http://www.ahbl.org




Re: Future timestamps in /var/log/secure

2010-02-26 Thread Larry Sheldon
On 2/26/2010 12:29 PM, Brielle Bruns wrote:
> On 2/26/10 11:20 AM, Wade Peacock wrote:
>> I found a while ago in /var/log/secure that for an invalid ssh login
>> attempt the ssh Bye Bye line is in the future. I have searched the web
>> and can not find a reason for the future time in the log.
>>
>> Here is a sample. Repeated lines are shown once in first part
>>
>>
>> Feb 26 17:50:38 mx sshd[19115]: Received disconnect from
>> 210.212.145.152: 11: Bye Bye
>> Feb 26 17:50:38 mx sshd[19118]: Received disconnect from
>> 210.212.145.152: 11: Bye Bye
>> Feb 26 09:52:39 mx proftpd[17297]: mx.example.com
>> (208.xxx.xxx.xxx[208.xxx.xxx.xxx]) - FTP no transfer timeout, disconnected
>>
>> Can anyone explain the future time stamp on the Bye Bye lines?
>>
>> OS is Centos 5.4, FYI
>>
> 
> 
> 
> Isn't the timestamps inserted by syslog rather then the reporting 
> program itself?
> 
> What syslog do you use - classic (ie: sysklogd) or a modern one like 
> rsyslog?  It almost looks like the timezone got changed from local to 
> GMT or similar, then swapped back (as odd as it may sound).
> 
> Perhaps time to file a bug report with the author of the syslog daemon 
> you use?

Been a long time since I've dealt with this stuff, but it looks like the
shell for proftpd has a different TZ from the one running the other
stuff.  (syslogd runs in the shell of the caller, right?)

-- 
"Government big enough to supply everything you need is big enough to
take everything you have."

Remember:  The Ark was built by amateurs, the Titanic by professionals.

Requiescas in pace o email
Ex turpi causa non oritur actio
Eppure si rinfresca

ICBM Targeting Information:  http://tinyurl.com/4sqczs
http://tinyurl.com/7tp8ml




Re: Future timestamps in /var/log/secure

2010-02-26 Thread Brielle Bruns

On 2/26/10 11:20 AM, Wade Peacock wrote:

I found a while ago in /var/log/secure that for an invalid ssh login
attempt the ssh Bye Bye line is in the future. I have searched the web
and can not find a reason for the future time in the log.

Here is a sample. Repeated lines are shown once in first part


Feb 26 17:50:38 mx sshd[19115]: Received disconnect from
210.212.145.152: 11: Bye Bye
Feb 26 17:50:38 mx sshd[19118]: Received disconnect from
210.212.145.152: 11: Bye Bye
Feb 26 09:52:39 mx proftpd[17297]: mx.example.com
(208.xxx.xxx.xxx[208.xxx.xxx.xxx]) - FTP no transfer timeout, disconnected

Can anyone explain the future time stamp on the Bye Bye lines?

OS is Centos 5.4, FYI





Isn't the timestamps inserted by syslog rather then the reporting 
program itself?


What syslog do you use - classic (ie: sysklogd) or a modern one like 
rsyslog?  It almost looks like the timezone got changed from local to 
GMT or similar, then swapped back (as odd as it may sound).


Perhaps time to file a bug report with the author of the syslog daemon 
you use?



--
Brielle Bruns
The Summit Open Source Development Group
http://www.sosdg.org/ http://www.ahbl.org



Future timestamps in /var/log/secure

2010-02-26 Thread Wade Peacock
I found a while ago in /var/log/secure that for an invalid ssh login attempt the ssh Bye Bye line is in the 
future. I have searched the web and can not find a reason for the future time in the log.


Here is a sample. Repeated lines are shown once in first part

grep "210.212.145.152" /var/log/secure

Feb 26 09:43:13 mx sshd[18117]: Did not receive identification string from 
210.212.145.152
Feb 26 09:50:33 mx sshd[19100]: Invalid user 0admin from 210.212.145.152
Feb 26 09:50:36 mx sshd[19106]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh 
ruser= rhost=210.212.145.152

Feb 26 09:50:38 mx sshd[19102]: Failed password for invalid user 0admin from 
210.212.145.152 port 39902 ssh2
Feb 26 17:50:38 mx sshd[19113]: Received disconnect from 210.212.145.152: 11: 
Bye Bye

grep -A1 -B1 "sshd\[19118\]: Received disconnect from 210.212.145.152: 11: Bye 
Bye" /var/log/secure

Feb 26 17:50:38 mx sshd[19115]: Received disconnect from 210.212.145.152: 11: 
Bye Bye
Feb 26 17:50:38 mx sshd[19118]: Received disconnect from 210.212.145.152: 11: 
Bye Bye
Feb 26 09:52:39 mx proftpd[17297]: mx.example.com (208.xxx.xxx.xxx[208.xxx.xxx.xxx]) - FTP no transfer 
timeout, disconnected


Can anyone explain the future time stamp on the Bye Bye lines?

OS is Centos 5.4, FYI

--
Wade Peacock
Network Administrator

Sun Country Cablevision Ltd
Sunwave Internet Department
Tel: (250) 832-9711 or (250) 546-9667
Web: http://www.sunwave.net
Email: wade.peac...@sunwave.net
Support Email: supp...@sunwave.net