Segfault when logging

[GoogleCodeExporter]

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

Original issue reported on code.google.com by shane.ha...@gmail.com on 10 Aug 2007 at 10:18

[GoogleCodeExporter]

There 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.

Original comment by Graham.Dumpleton@gmail.com on 10 Aug 2007 at 10:30

• Changed state: Accepted
• Added labels: Milestone-Release1.0, Priority-High
• Removed labels: Priority-Medium

[GoogleCodeExporter]

Whoops, 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.

Original comment by Graham.Dumpleton@gmail.com on 10 Aug 2007 at 10:44

[GoogleCodeExporter]

This 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.

Original comment by Graham.Dumpleton@gmail.com on 12 Aug 2007 at 4:56

• Changed state: Fixed