[Zope-dev] Logs stamped with wrong time

[Steve Alexander]

Dieter Maurer wrote:
> 
> Steve Alexander writes:
>  > Zope 2.2 CVS checkout August 21.
>  >
>  > I'm in the BST timezone, which is GMT+1.
>  >
>  > All the entries in Z2.log are one hour behind where they should be.
>  >
>  > 127.0.0.1: - - [23/Aug/2000:15:15:39 +0100] "POST
>  > /fmr/mail_test/manage_edit HTTP/1.0" 200 10139
>  > "http://zope.cat-box.net/fmr/mail_test/manage_main" "Mozilla/4.61 [en]
>  > (WinNT; I)"

> ZServers writes log time as GMT.

Well, it sort of does :-)

It writes the time in  GMT, followed by a string to represent the
timezone it ought to be writing it in.

So, if the time here is 9am GMT+1, a log entry would be written as

  24/Aug/2000:08:00:00 +0100

  date+time in GMT     BST timezone


This is the wrong time though, as it is 8am BST which is 7am GMT, which
is one hour earlier than the time the request was made.

What is should be writing is either the time in GMT:

  24/Aug/2000:08:00:00 +0000

  date+time in GMT     GMT timezone

Or the time in the local zone

  24/Aug/2000:09:00:00 +0100

  date+time in BST     BST timezone

 
> I agree with you, that it should not.

I just checked, and my copy of Apache logs in local time (my last
example). So I agree that following the convention and logging in
localtime is best.

I also checked Zope 2.1.6, and the same bug is there.

However, either way, I'd prefer ZServer to log the time requests were
made, not time-tzdiff as it does now :-)

There's this problem for anyone in a timezone remote from GMT that any
analysis of their Z2.log will be skewed by their timezone difference.
Anyone in Australia been wondering why most of their locals appear to
log in during the very early morning?

Of course, this isn't an issue if you run behind Apache, and you analyse
the Apache logs instead.

--
Steve Alexander
Software Engineer
Cat-Box limited
http://www.cat-box.net