Bug 105019

Sorry, that log snippit was from a sorted log. Here is an example from the
original log:

dialup-63.215.175.96.dial1.portland1.level3.net - - [21/Sep/2003:19:06:18 -0500]
"GET /breyernumber1000.shtml HTTP/1.1" 200 21865
"http://ponylagoon.muerte.net/breyernumber.shtml" "Mozilla/4.0 (compatible; MSIE
6.0; MSNIA; Windows 98; MSNIA)"
dialup-63.215.175.96.dial1.portland1.level3.net - - [22/Sep/2003:00:06:44 +0000]
"GET /molds/trakehner.shtml HTTP/1.1" 200 3985
"http://ponylagoon.muerte.net/breyernumber1000.shtml" "Mozilla/4.0 (compatible;
MSIE 6.0; MSNIA; Windows 98; MSNIA)"

Notice the jump from September 21 to September 22. A few lines further on we go
the other direction:

dialup-63.215.175.96.dial1.portland1.level3.net - - [22/Sep/2003:00:09:00 +0000]
"GET /breyernumber10000.shtml HTTP/1.1" 200 28603
"http://ponylagoon.muerte.net/breyernumber.shtml" "Mozilla/4.0 (compatible; MSIE
6.0; MSNIA; Windows 98; MSNIA)"
dialup-63.215.175.96.dial1.portland1.level3.net - - [21/Sep/2003:19:09:22 -0500]
"GET /breyernumber999999.shtml HTTP/1.1" 200 20282
"http://ponylagoon.muerte.net/breyernumber.shtml" "Mozilla/4.0 (compatible; MSIE
6.0; MSNIA; Windows 98; MSNIA)"

Does this happen consistently, all the time? Or does it only start
happening after the server has been running a while?

It would be useful if you could adjust the LogFormat ("combined" by
default) and add:

%P

at the very end, to log the child process ID at the end of each line.  
This should reveal whether only certain processes are forgetting their
timezone setting, for instance.

When you find a log entry with a bad timezone, you can then do:

cp /proc/<pid>/environ /tmp/saved-environ

to capture the environment of that child process, and attach that here.

It happens pretty quickly. I started getting them within 10 minutes of
restarting with your log change. It is not the case that a child will
always be one way or the other. I have an example of one PID going
from fine to bad, though not yet the other way. Here is the
environment for one which has gone bad. I don't see any reference to
timezone, but I don't see any in my login environment either.

HOSTNAME=hairball.muerte.net
TERM=xterm
SHELL=/bin/bash
HISTSIZE=1000
QTDIR=/usr/lib/qt-3.1
USER=root
LS_COLORS=no=00:fi=00:di=00;34:ln=00;36:pi=40;33:so=00;35:bd=40;33;01:cd=40;33;01:or=01;05;37;41:mi=01;05;37;41:ex=00;32:*.cmd=00;32:*.exe=00;32:*.com=00;32:*.btm=00;32:*.bat=00;32:*.sh=00;32:*.csh=00;32:*.tar=00;31:*.tgz=00;31:*.arj=00;31:*.taz=00;31:*.lzh=00;31:*.zip=00;31:*.z=00;31:*.Z=00;31:*.gz=00;31:*.bz2=00;31:*.bz=00;31:*.tz=00;31:*.rpm=00;31:*.cpio=00;31:*.jpg=00;35:*.gif=00;35:*.bmp=00;35:*.xbm=00;35:*.xpm=00;35:*.png=00;35:*.tif=00;35:
USERNAME=root
PATH=/sbin:/usr/sbin:/bin:/usr/bin:/usr/X11R6/binMAIL=/var/spool/mail/rootPWD=/etc/cron.daily
INPUTRC=/etc/inputrc
LANG=en_US
SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass
HOME=/root
SHLVL=2
BASH_ENV=/root/.bashrc
LOGNAME=root
LESSOPEN=|/usr/bin/lesspipe.sh %s
DISPLAY=:0.0
G_BROKEN_FILENAMES=1
XAUTHORITY=/root/.xauthFEzvuL_=/sbin/initlog

In addition I do not have an /etc/localtime or
/usr/share/zoneinfo/localtime file. My hardware clock is set to GMT.

hairball/usr/share/zoneinfo$ date
Mon Nov  3 14:28:46 CST 2003
hairball/usr/share/zoneinfo$ date -u
Mon Nov  3 20:28:48 UTC 2003

Then I'm confused, if you don't have TZ set or an /etc/localtime, how
is your timezone configured?  There is some other way?

You work at RedHat. Shouldn't you know this better than me? :)

hairball/etc/sysconfig$ cat clock
ZONE="America/Chicago"
UTC=true
ARC=false

This stuff gets used in /etc/rc.d/rc.sysinit.

I know of two ways of configuring a timezone in a Linux system:
/etc/localtime and $TZ.  If you're not using either, then I need to
learn about a new way!  Or else your timezone is not really configured
properly, and that's the source of the problems.

rc.sysinit does not configure a timezone, it doesn't use $ZONE.

What is the output of 

$ strace date

...and the output of "env", both from a fresh root login.

Sorry, I looked at too many things before I did that last comment and
forgot what exactly I saw. There _is_ an /etc/localtime. It's just not
a symplink to something in /usr/share/zoneinfo, it's a regular file
(which is in the proper format).

hairball~$ file /etc/localtime
/etc/localtime: timezone data

OK, good.  What modules are being used on the server? 

The next thing to do is to look at where particular children forget
the timezone by tracking the pids, and seeing if this is triggered by
a request for a particular file, for instance.

The module configuration is as installed by the rpm.

I meant: are you using php, perl, ??? scripts, along with the shtml? 
To investigate this further I'd need a larger segment of log file
which shows the good->bad transitions for a few processes to see
whether a particular request is triggering it.

Both php and perl are in use. Perl is used only rarely and the last
restart I mentioned showed the problem before any perl scripts could
have been called.

I'll work on getting you transition logs, but since I have several
virtual servers, all logging to different files, this will take a bit
of time...

I take it there is nothing obvious added to httpd-2.0.40-21.3 which
could cause this problem?

No.  One more question: is your /etc/localtime world-readable?

ls -l /etc/localtime

Yes.
hairball~$ ls -l /etc/localtime
-rw-rw-r--    1 root     root         1279 Nov  7 05:19 /etc/localtime

Remember that the TZ variable is global to the process.  If a mod_perl
or PHP script sets that variable, it will I think  affect logs written
out by Apache in the future.

Also, you might check for SetEnv lines in the apache config.

Personally I think keeping logs in GMT is a good idea...

Thanks for the report.  This is a mass bug update; since this release
of Red Hat Linux is no longer supported, please either:

a) try and reproduce the bug with a supported version of Red Hat
Enterprise Linux or Fedora Core, and re-open this bug as appropriate
after changing the Product field, or,

b) if relevant, try and reproduce this bug using the current version
of the upstream package, and report the bug upstream.

c) report the bug to the Fedora Legacy project who may wish to
continue maintenance of this package.