Malformed header using paste.auth.cookie
Alberto Valverde
I'm trying to deploy a Pylons app on apache 2.2.3-4+etch4 (Debian
package), mod_wsgi 2.0 (tarball from code.google) on a 32bit i688
machine. Unfortunately Apache complaints about a malformed header the
app is sending.
I've tracked the cause to be when paste.auth.cookie's middleware tries
to set the Set-Cookie header. If I comment out the line where this
header is appended to the list everything works.
The problem does not occur with neither CherryPy's nor Paste's WSGI servers.
The problematic header is this one:
'Set-Cookie'
'twauth=bwiLz4MSater2WRG6zPJV10dGbQyMDA4MDQyOTIyMTJSRU1PVEVfVVNFUj1hbGJlcnRv\n;
Path=/;'
And Apache's error log says:
[Tue Apr 29 21:51:40 2008] [error] [client 192.168.0.100] malformed
header from script. Bad header=; Path=/;: production.wsgi, referer:
http://example.com
Any clues?
Thank you Graham for all the hard work on mod_wsgi. :)
Alberto
Graham Dumpleton
Maybe you have done this already and how you got the above, but read
section 'Request and Response Headers' of:
http://code.google.com/p/modwsgi/wiki/DebuggingTechniques
Use the WSGI middleware wrapper to wrap the Pylons application entry
point so that both request environment and response headers are dumped
to the log file. Post the result here.
You may want to modify the example though and not use 'pprint' and instead use:
print >> errors, repr(('RESPONSE', status, headers))
By using repr() it will better show if there is any strange non
printable characters in the data, or newlines.
Graham
Graham Dumpleton
> 2008/4/30 Alberto Valverde <alb...@toscat.net>:
>
> >
> > Hi,
> >
> > I'm trying to deploy a Pylons app on apache 2.2.3-4+etch4 (Debian
> > package), mod_wsgi 2.0 (tarball from code.google) on a 32bit i688
> > machine. Unfortunately Apache complaints about a malformed header the
> > app is sending.
> >
> > I've tracked the cause to be when paste.auth.cookie's middleware tries
> > to set the Set-Cookie header. If I comment out the line where this
> > header is appended to the list everything works.
> >
> > The problem does not occur with neither CherryPy's nor Paste's WSGI servers.
> >
> > The problematic header is this one:
> >
> > 'Set-Cookie'
> > 'twauth=bwiLz4MSater2WRG6zPJV10dGbQyMDA4MDQyOTIyMTJSRU1PVEVfVVNFUj1hbGJlcnRv\n;
> > Path=/;'
> >
> > And Apache's error log says:
> >
> > [Tue Apr 29 21:51:40 2008] [error] [client 192.168.0.100] malformed
> > header from script. Bad header=; Path=/;: production.wsgi, referer:
> > http://example.com
According to httpd source code, it is complaining about the lack of a colon.
if (!(l = strchr(w, ':'))) {
char malformed[(sizeof MALFORMED_MESSAGE) + 1
+ MALFORMED_HEADER_LENGTH_TO_SHOW];
strcpy(malformed, MALFORMED_MESSAGE);
strncat(malformed, w, MALFORMED_HEADER_LENGTH_TO_SHOW);
if (!buffer) {
/* Soak up all the script output - may save an outright kill */
while ((*getsfunc) (w, MAX_STRING_LEN - 1, getsfunc_data)) {
continue;
}
}
ap_log_rerror(APLOG_MARK, APLOG_ERR|APLOG_TOCLIENT, 0, r,
"%s: %s", malformed,
apr_filepath_name_get(r->filename));
return HTTP_INTERNAL_SERVER_ERROR;
}
Need to see that output from debugging middleware to see what is in
header at that point. On first guess it would appear there is an
embedded newline in one of the response headers.
Graham
Alberto Valverde
Ok, I had to use a modified version the LoggingMiddleware in the wiki to
write to a file and flush it after every write since, for some reason,
errors didn't land in the vhosts ErrorLog.
I've pasted the output here http://pylonshq.com/pasties/797
Thanks!
Alberto
Graham Dumpleton
Which if you used repr(), is showing an embedded newline in the cookie
string. It showed in your original email as well, but wanted to make
sure that repr() was being used.
'twauth=bwiLz4MSater2WRG6zPJV10dGbQyMDA4MDQyOTIzNTFSRU1PVEVfVVNFUj1hbGJlcnRv\n;
Path=/;'
You can't have embedded newlines in values of response headers. You
thus need to work out how that embedded new line is getting in there.
BTW, if you can hang around I'd like to investigate with you the
problem of logging not appearing in VirtualHost error log file. I've
had one report of this before off list, but the back and forth in
trying to debug it wasn't too helpful as couldn't get them to give me
complete and clear answers to all the questions I was asking and
unfortunately it is the little details that help me work out problems.
Thus it is a bit hard when people leave out details because they don't
think it is relevant. :-(
Anyway, the separate potential logging issue is recorded as:
http://code.google.com/p/modwsgi/issues/detail?id=79
I'll create a set of simple test programs for you to run, if you don't
mind, and we will go from there.
Graham
Alberto Valverde
Yep, I used repr on both reports :)
> You can't have embedded newlines in values of response headers. You
> thus need to work out how that embedded new line is getting in there.
>
I'll dig into my code and paste.auth.cookie then, I'm glad the problem
is not somewhere at the C side of the equation.
> BTW, if you can hang around I'd like to investigate with you the
> problem of logging not appearing in VirtualHost error log file. I've
> had one report of this before off list, but the back and forth in
> trying to debug it wasn't too helpful as couldn't get them to give me
> complete and clear answers to all the questions I was asking and
> unfortunately it is the little details that help me work out problems.
> Thus it is a bit hard when people leave out details because they don't
> think it is relevant. :-(
>
Now that the details are fresh in my memory... one thing I found unusual
was that a a false assertion I threw inside LoggingMiddleware, both in
the request phase and in the response phase (ie, inside the
_start_response inner function) to check out if anything reached the
error log at all didn't came out either. Instead some warnings that my
app throws when starting up appeared. Maybe because the whole app is
being reloaded by apache/mod_wsgi after a the uncaught (and unrecorded)
AssertionError?
> Anyway, the separate potential logging issue is recorded as:
>
> http://code.google.com/p/modwsgi/issues/detail?id=79
>
> I'll create a set of simple test programs for you to run, if you don't
> mind, and we will go from there.
>
No prob, glad to help out. Send them in. Though I won't be able to run
them until a couple of hours 'cause it's bedtime here now :)
Alberto
Graham Dumpleton
> > problem of logging not appearing in VirtualHost error log file. I've
> > had one report of this before off list, but the back and forth in
> > trying to debug it wasn't too helpful as couldn't get them to give me
> > complete and clear answers to all the questions I was asking and
> > unfortunately it is the little details that help me work out problems.
> > Thus it is a bit hard when people leave out details because they don't
> > think it is relevant. :-(
> >
>
> Now that the details are fresh in my memory... one thing I found unusual
> was that a a false assertion I threw inside LoggingMiddleware, both in
> the request phase and in the response phase (ie, inside the
> _start_response inner function) to check out if anything reached the
> error log at all didn't came out either. Instead some warnings that my
> app throws when starting up appeared. Maybe because the whole app is
> being reloaded by apache/mod_wsgi after a the uncaught (and unrecorded)
> AssertionError?
>
>
> > Anyway, the separate potential logging issue is recorded as:
> >
> > http://code.google.com/p/modwsgi/issues/detail?id=79
> >
> > I'll create a set of simple test programs for you to run, if you don't
> > mind, and we will go from there.
> >
>
> No prob, glad to help out. Send them in. Though I won't be able to run
> them until a couple of hours 'cause it's bedtime here now :)
Will be a little while before I can get some examples together for
testing. I'll create a separate thread for it though with different
subject line, so keep an eye out for it.
Graham
Graham Dumpleton
Have also created issue:
http://code.google.com/p/modwsgi/issues/detail?id=81
This is to look at mod_wsgi generating a Python exception when badly
formatted names and values are supplied for response headers. Will
need to possibly look at what is allowed in CGI since WSGI derives
from that in some ways, plus needs to adhere to CGI conventions given
that CGI is one hosting mechanism.
Graham