What could cause Apache's time/timezone to change intermittently?

Question

I run a server with some PHP-powered forums (Vanilla 1.1.5a) on it, and I've recently noticed posts going out of order on them. Some digging revealed that Apache seems to be changing the current timezone back and forth from +0000 to -0500 on a request without apparent pattern, which can be seen in log entries like these:

38.104.58.202 - - [15/Jun/2009:22:40:05 +0000] "GET /extensions/MembersList/library/paginate.js HTTP/1.1" 200 22880 "http://mysite.com/" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.1b99) Gecko/20090605 Firefox/3.5b99"
38.104.58.202 - - [15/Jun/2009:17:40:05 -0500] "GET /extensions/JQuery/jquery-1.2.6.min.js HTTP/1.1" 200 55804 "http://mysite.com/" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.1b99) Gecko/20090605 Firefox/3.5b99"

Though the time adjusted for the timezone difference is the same, it seems to be causing PHP's date function to return the local, unadjusted time (with ensuing timewarp chaos happening in the forum's data).

I'm also running a Django-based mod_python application on the same VirtualHost. The config looks like this:

<VirtualHost *:80>
  ServerAdmin webmaster@localhost        
  DocumentRoot /var/www/

<Directory />
    Options FollowSymLinks
    AllowOverride None
</Directory>
<Directory /var/www/>
    Options Indexes FollowSymLinks MultiViews
    AllowOverride None
    Order allow,deny
    allow from all
</Directory>

ScriptAlias /cgi-bin/ /usr/lib/cgi-bin/
<Directory "/usr/lib/cgi-bin">
    AllowOverride None
    Options +ExecCGI -MultiViews +SymLinksIfOwnerMatch
    Order allow,deny
    Allow from all
   </Directory>

    ErrorLog /var/log/apache2/error.log

# Possible values include: debug, info, notice, warn, error, crit,
# alert, emerg.
LogLevel warn

CustomLog /var/log/apache2/access.log combined

  Alias /doc/ "/usr/share/doc/"
  <Directory "/usr/share/doc/">
      Options Indexes MultiViews FollowSymLinks
      AllowOverride None
      Order deny,allow
      Deny from all
      Allow from 127.0.0.0/255.0.0.0 ::1/128
  </Directory>

  Alias /media/ "/usr/share/python-support/python-django/django/contrib/admin/media/"
  <Directory /usr/share/python-support/python-django/django/contrib/admin/media/>
              Options Indexes FollowSymLinks MultiViews
              AllowOverride None
              Order allow,deny
              allow from all
  </Directory>

  RedirectMatch ^/raid-scheduler$ "/raid-scheduler/"
  <Location "/raid-scheduler/">
       SetHandler python-program
       PythonHandler django.core.handlers.modpython
       SetEnv DJANGO_SETTINGS_MODULE raid_scheduler.settings
       PythonOption django.root /raid-scheduler
       PythonDebug On
   PythonPath "['/opt', '/opt/raid_scheduler'] + sys.path"
   </Location>
</VirtualHost>

Any ideas as to what might be causing this?

Solution 1

Could it be that some other request is setting TZ and it's being left lying around? Recording the getenv('TZ') at the start of every request would verify this, and putenv could be used to workaround it.

Solution 2

In Unix/Linux each process can operate in a different timezone. This is because depending on the content of $TZ variable that can be present in process's environment system time-related functions change their return values (this is neither PHP- or Apache-specific). Probably $TZ is getting modified inside one or more of your Apache processes. Both mod_php and mod_python are a part of Apache process, so they can freely modify $TZ.

Can you print getenv('TZ') to the log along with Apache process id via posix_getpid(), so it could be used to match with various user requests?

Comments

[jj33]

we used to run into this w/ $TZ and mod_perl...

[Peter Westlake]

I think that was exactly was going on. I'm going to dig around in my Django settings to see what's setting TZ, but using putenv to simply clear it at the start of each mod_php request seems to have put everything back in working order.