0

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?

1 Answer 1

3

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.

6
  • Thanks, I figured it out some time ago but I don't have any writes to stdout anyway. I thought that maybe Python or mod_wsgi writes there something when daemon is terminated, but it might be an interaction with development server running on the same Apache instance, in different WSGI daemon but within the same WSGIApplicationGroup %{GLOBAL}. I might be completely wrong here, though. Feb 16, 2011 at 12:19
  • You may not have explicit 'print' statements, but the traceback above indicates that the logging module is using stdout and is attempting to flush it on shutdown. Upgrade to mod_wsgi 3.X and stop using 2.X and the problem will go away. The restriction was lifted in 3.0 because people didn't want to address why their code was using stdin/stdout even though doing so means you don't have a portable WSGI application. See 'blog.dscpl.com.au/2009/04/…'. Feb 16, 2011 at 15:03
  • @Graham: Thanks, I already read that blog entry - I made sure that there's no stdout handler in my logging configuration but the problem didn't go away. Out of sudden it went away a few hours ago, when I redirected sys.stdout to sys.stderr, but this is more a hack than a solution - I still don't understand what was (and is) wrong. Here is next question on my way of understanding the root cause: stackoverflow.com/questions/5021424/… Feb 16, 2011 at 20:07
  • 1
    The traceback shows 'self.stream.flush()'. The value of 'self.stream' must be 'sys.stdout' somehow. Feb 16, 2011 at 23:07
  • You are probably right, I was misled by the other strange tracebacks. I'll investigate this more thorough because there should be no sys.stdout Feb 17, 2011 at 19:02

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .