A WSGI app I am writing sometimes causes mod_wsgi to segfault. I spent some time narrowing the problem and found that the following simple script will trigger the segfault:
def application(environ, start_response): global save save = start_response status = '200 OK' output = 'Hello World!' environ['wsgi.errors'].write('hello') response_headers = [('Content-type', 'text/plain'), ('Content-Length', str(len(output)))] start_response(status, response_headers) return [output]
This is just a "hello, world" script with two modifications: it saves the start_response callback and it writes to the error log without a terminating newline. The first request for this script returns the "Hello World!" response to the browser just fine, but the "hello" message does not appear in Apache's log. A segfault occurs the second time I make a request for the script.
If I do not store the start_response callback, or I add a newline to the error message, or I call environ['wsgi.errors'].flush() before returning, no problem occurs. This suggests to me that mod_wsgi is supposed to flush the error stream before the request is finished, but that is not happening, and the flush is occurring after the request has been destroyed. In a gdb post-mortem session, I noticed that a certain PyObject* had the address "0xb", an invalid address, which suggests that perhaps the destroyed request object had already been reused for another object.
In reality, my app is slightly misbehaved in that it really should not store the start_response callback. That was accidental and I will fix it. However, no WSGI app should be able to trigger a segfault this way.
OS: OpenSuse 10.2 inside a Linux VServer Apache: 2.2.3 Python: 2.5 and 2.5.1 (problem occurred with both versions) mod_wsgi: 1.0c2
Comment #1
Posted on Aug 10, 2007 by Quick RhinoThere is various bits of code to prevent crashes if save_response is cached beyond life of request, but seems I missed this one spot. :-(
In Log_dealloc(), should be checking self->expired as well as self->r before logging.
if (self->s) {
if (self->r && !self->expired) {
Py_BEGIN_ALLOW_THREADS
ap_log_rerror(APLOG_MARK, WSGI_LOG_LEVEL(self->level),
self->r, "%s", self->s);
Py_END_ALLOW_THREADS
}
else {
...
}
...
}
Only question now is whether I log the remainder in the main server log rather than against the request, which may cause confusion, or simply discard the remainder. Per WSGI specification doing the latter is fine, as flush() has to be called to ensure that log messages are actually logged.
In other words, probably better to do:
if (self->s && !self->expired) {
...
}
Thanks for picking up on this one.
Comment #2
Posted on Aug 10, 2007 by Quick RhinoWhoops, that latter change doesn't take into consideration freeing the remainder and would leak memory. Change needs to ensure that free(self->s) is performed if s is non null even if expired.
Comment #3
Posted on Aug 12, 2007 by Quick RhinoThis is has been fixed in revision 413 of subversion repository.
Took path of actually flushing log explicitly at end of the request. Any residual data still in log object related to a request when log object is deleted is simply discarded. By rights there shouldn't be any data, as application should not be using wsgi.errors after request has executed, response returned and any generator had close() called on it.
Status: Fixed
Labels:
Type-Defect
Priority-High
Milestone-Release1.0