Python – Apache, mod_wsgi, Django – strange 500 errors

apache-2.2djangologgingmod-wsgipython

I have a Django site which works well most of the time, memory usage is stable and I wouldn't have to worry if not some strange problems, which were occasional until yesterday and cause site to go down for the whole last night.

Configuration:

  • Debian Lenny
  • Apache 2.2 prefork
  • mod_wsgi 2.5
  • Python 2.5.2
  • Django 1.2.5

Tracebacks I get:

[error] mod_wsgi (pid=7390): Exception occurred within sys.exitfunc().
[error] Traceback (most recent call last):
[error]   File "/usr/lib/python2.5/atexit.py", line 24, in _run_exitfuncs
[error]     func(*targs, **kargs)
[error]   File "/usr/lib/python2.5/logging/__init__.py", line 1354, in shutdown
[error]     h.flush()
[error]   File "/usr/lib/python2.5/logging/__init__.py", line 731, in flush
[error]     self.stream.flush()
[error] IOError: sys.stdout access restricted by mod_wsgi

The above one is often generated when I restart Apache or touch .wsgi file, so I'm not concerned about it that much. The following ones are more interesting:

[error] [client ..] mod_wsgi (pid=8184): Exception occurred processing WSGI script '.../django.wsgi'.
[error] [client ..] Traceback (most recent call last):
[error] [client ..] File ".../django/core/handlers/wsgi.py", line 248, in __call__
[error] [client ..]   response = self.get_response(request)
[error] [client ..] File ".../django/core/handlers/base.py", line 140, in get_response
[error] [client ..]   receivers = signals.got_request_exception.send(sender=self.__class__, request=request)
[error] [client ..] File "...django/dispatch/dispatcher.py", line 172, in send
[error] [client ..]   response = receiver(signal=self, sender=sender, **named)
[error] [client ..] File "...django/db/transaction.py", line 299, in _commit_on_success
[error] [client ..]   res = func(*args, **kw)
[error] [client ..] File ".../apps/utils/middleware.py", line 28, in exception_handler
[error] [client ..]   'url': request.get_full_path()
[error] [client ..] File "/usr/lib/python2.5/logging/__init__.py", line 1015, in error
[error] [client ..]   apply(self._log, (ERROR, msg, args), kwargs)
[error] [client ..] File "/usr/lib/python2.5/logging/__init__.py", line 1101, in _log
[error] [client ..]   self.handle(record)
[error] [client ..] File "/usr/lib/python2.5/logging/__init__.py", line 1111, in handle
[error] [client ..]   self.callHandlers(record)
[error] [client ..] File "/usr/lib/python2.5/logging/__init__.py", line 1148, in callHandlers
[error] [client ..]   hdlr.handle(record)
[error] [client ..] File "/usr/lib/python2.5/logging/__init__.py", line 655, in handle
[error] [client ..]   self.emit(record)
[error] [client ..] File "../apps/py26_logging/handlers.py", line 394, in emit
[error] [client ..]   self.stream.flush()
[error] [client ..] ValueError: I/O operation on closed file

One word of explanation: because I use logrotate for log rotation, I "backported" logging.WatchedFileHandler from Python 2.6 to the project, which is placed in apps/py26_logging/handlers.py, but my guess is that it's not the WatchedFileHandler that causes this and that it only suffers from the more general problem – because for 95% of time it works perfectly.

Anyway, Apache restart cures the problem immediately (until next time of course).

ServerDensity, which I use for server monitoring, shows a stable memory usage (flat line) with at least 500mb of free memory at any time, number of processes is also stable and in general nothing unusual happens in stats when my app goes crazy.

I tried reproducing the problem with ApacheBench, but I didn't manage to fail any single request unless I used 100 simultaneous ones:

Concurrency Level: 100
Complete requests: 10000
Failed requests: 1
(Connect: 0, Receive: 0, Length: 1, Exceptions: 0)
Write errors: 0
Non-2xx responses: 1

I don't have to mention that this was way beyond the usual load and ServerDensity stats spiked up a lot.

Does someone of you see a familiar pattern here?

Best Answer

I can just comment on the IOError: sys.stdout access restricted by mod_wsgi error. Something in your Django-App writes stuff to sys.stdout which is restricted by mod_wsgi. Usually no output ever happens to sys.stdout in a WSGI application. You could use WSGIRestrictStdout Off in your global Apache configuration (not vhost) as a band-aid. For a permanent and clean solution, get rid of any print or whatever writes to sys.stdout. For more details look at the mod_wsgi documentation.

Related Topic