On Friday, November 5, 2010, Fraser <[email protected]> wrote: > 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.
How long after the restart? When doing a graceful restart, there may be a small window where an existing Apache child process hasn't properly stopped accepting new requests when waiting for existing requests to complete. This may be made worse by keep alive connections with existing child server process not being able to shutdown and with it accepting new request on the existing connection. In that latter situation especially you can technically see this issue. Try turning off keep alive and see if the problem persists. Besides that, not much you can do in Apache as Apache doesn't provide a way of extending graceful restart mechanism to what it regards as 'other' child processes. Putting nginx in front can help if you are concerned about lack of keep alive as then it will handle it. Having nginx in front brings a lot of other benefits as well. BTW, what else is running on this server? Is it just the WSGI application or is it handling static files, or non Python dynamic web applications as well? Graham > 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. > > -- 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.
