We are seeing an issue where performing a graceful restart of Apache
results in a 503 response for a small number of requests made
immediately following the restart.

I enabled debug-level logging within Apache, and see the following
entries relating to one of the WSGI daemons in question:

[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Shutdown
requested 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Stopping
process 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Destroying
interpreters.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Cleanup
interpreter ''.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Shutdown
requested 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Stopping
process 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Destroying
interpreters.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Cleanup
interpreter ''.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Terminating
Python.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12455): Python has
shutdown.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Shutdown
requested 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Stopping
process 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Destroying
interpreters.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Cleanup
interpreter ''.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Terminating
Python.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12451): Python has
shutdown.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Shutdown
requested 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Stopping
process 'myprocname'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Destroying
interpreters.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Destroy
interpreter 'hostname:port|'.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Terminating
Python.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12444): Python has
shutdown.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Cleanup
interpreter ''.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Terminating
Python.
[Thu Nov 04 10:15:01 2010] [info] mod_wsgi (pid=12443): Python has
shutdown.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12740): Starting
process 'myprocname' with uid=48, gid=502 and threads=1.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12741): Starting
process 'myprocname' with uid=48, gid=502 and threads=1.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12742): Starting
process 'myprocname' with uid=48, gid=502 and threads=1.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12727): Starting
process 'myprocname' with uid=48, gid=502 and threads=1.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12727): Initializing
Python.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12727): Attach
interpreter ''.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12740): Initializing
Python.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12741): Initializing
Python.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12741): Attach
interpreter ''.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12742): Initializing
Python.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12742): Attach
interpreter ''.
[Thu Nov 04 10:15:02 2010] [info] mod_wsgi (pid=12740): Attach
interpreter ''.
[Thu Nov 04 10:15:06 2010] [error] [client XXX.XXX.XXX.XXX] (2)No such
file or directory: mod_wsgi (pid=12523): Unable to connect to WSGI
daemon process 'myprocname' on '/var/wsgi/wsgi.12667.55.10.sock' after
multiple attempts.
[Thu Nov 04 10:15:06 2010] [info] mod_wsgi (pid=12523): Destroying
interpreters.
[Thu Nov 04 10:15:06 2010] [info] mod_wsgi (pid=12523): Cleanup
interpreter ''.
[Thu Nov 04 10:15:06 2010] [info] mod_wsgi (pid=12523): Terminating
Python.
[Thu Nov 04 10:15:06 2010] [info] mod_wsgi (pid=12523): Python has
shutdown.

>From these logs, it looks like is that the request is trying to
connect to the old WSGI socket, which has already been destroyed. This
doesn't seem correct/ideal behaviour.

I'm not very familiar with the inner workings of Apache or mod_wsgi,
but my guess is that this may be caused by one of the following
scenarios:

1. An "old" Apache process is trying to handle a request following a
graceful restart. My understanding is that a graceful restart should
result in new Apache process being created and the old ones only being
used to complete requests already in progress before being destroyed.

2. The request is being handled by a newly spawned Apache process, but
somehow it has a reference to the old (and now defunct) mod_wsgi
socket.

Has anyone else experienced this and come up with a workaround, or is
this a bug within Apache/mod_wsgi?

Thanks,

Fraser

P.S. Environment is RHEL5 with Apache 2.2.3 and mod_wsgi 3.3.

-- 
You received this message because you are subscribed to the Google Groups 
"modwsgi" group.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to 
[email protected].
For more options, visit this group at 
http://groups.google.com/group/modwsgi?hl=en.

Reply via email to