jvandal / modwsgi

Automatically exported from code.google.com/p/modwsgi
0 stars 0 forks source link

Exception raised by wsgi script causes 500 error with no log messages #158

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
What steps will reproduce the problem?

1. Create a foo.wsgi configuration that contains only one line:
   raise Exception('boo!')

2. Configure Apache to use foo.wsgi as your WSGIScriptAlias

3. Reload apache and browse your site. You get a 500 error with no
information about the cause.

4. Check your error log(s).  Nothing.

What is the expected output? What do you see instead?

  It would really help if errors in the WSGI script would be logged
somewhere, preferably the relevant apache error log. We had an ImportError
in our WSGI script that took us a long time to find because the traceback
wasn't displayed or logged anywhere.

What version of the product are you using? On what operating system?

  mod_wsgi 2.4, apache-2.2.11 on gentoo linux.

Please provide any additional information below.

Original issue reported on code.google.com by sli...@gmail.com on 8 Oct 2009 at 1:12

GoogleCodeExporter commented 8 years ago
Upgrade your version of mod_wsgi. That is an old version.

Error messages are logged. Where the errors are logged depends on how you have 
configured Apache. You 
have not supplied any information about your configuration, whether you are 
using embedded mode or 
daemon mode, whether WSGIScriptAlias is inside of a VirtualHost, whether 
ErrorLog directive is used inside of 
VirtualHost, whether LogLevel has been overridden from Apache default. Try and 
at least describe it if not 
provide cut down configuration. Ensue you show how ErrorLog directive is set.

Normally the errors messages related to a specific request will go to the error 
log associated with the 
VirtualHost, or that for main Apache server if none defined. There are some 
circumstances where errors can 
end up in main Apache server error log if still have ErrorLog in VirtualHost, 
so check both.

All the same, there aren't known to be any issues with logging, even with that 
old version. One mistake have 
seen people make and which is propagated by some blogs and recipes available 
and believed even to be done 
internal to some packages, is to reassign sys.stdout/sys.stderr to be something 
else such as file opened on 
/dev/null. If you have fiddled with sys.stderr in this way, logged error 
messages can go missing.

Suggest you create a hello world program which does the following and post 
response  in browser and what 
you get in the log file so can confirm what has been done in the interpreter 
environment. If you claim still 
nothing in error logs, with that test, then in Apache configuration set 
LogLevel to 'info' so can get additional 
information out of mod_wsgi about what it is doing and after fresh Apache 
restart and making request, post 
from error logs what is shown from before request to after.

import sys

print >> sys.stderr, "importing script"

def application(environ, start_response):
    status = '200 OK'

    print >> sys.stderr, "running application"
    print >> environ['wsgi.errors'], "running application"

    output = ''
    output += 'mod_wsgi.process_group="%s"\n' % environ['mod_wsgi.process_group']
    output += 'mod_wsgi.application_group="%s"\n' % environ['mod_wsgi.application_group']
    output += 'type(sys.stdout)="%s"\n' % str(type(sys.stdout))
    output += 'id(sys.stdout)="%s"\n' % str(id(sys.stdout))
    output += 'type(sys.stderr)="%s"\n' % str(type(sys.stderr))
    output += 'id(sys.stderr)="%s"\n' % str(id(sys.stderr))

    print >> environ['wsgi.errors'], output

    response_headers = [('Content-type', 'text/plain'),
                        ('Content-Length', str(len(output)))]
    start_response(status, response_headers)

    return [output]

Original comment by Graham.Dumpleton@gmail.com on 8 Oct 2009 at 2:36

GoogleCodeExporter commented 8 years ago
Any further information?

Original comment by Graham.Dumpleton@gmail.com on 11 Oct 2009 at 10:43

GoogleCodeExporter commented 8 years ago
sorry, was on vacation. will look into this further today.

Original comment by sli...@gmail.com on 12 Oct 2009 at 2:40

GoogleCodeExporter commented 8 years ago
I don't think upgrading mod_wsgi is an option on this box; I'm not the primary 
admin.
But I'll ask.

Here's the config info I left out, with some paths elided. The relevant
virtualhost config is like so:

<VirtualHost 10.51.24.2:80>
ServerName bikeraction-dev.thor.openplans.org

# Need to do this for the admin UI to find its stylesheets et al.
Alias /media/
/.../lib/python2.4/site-packages/Django-1.1-py2.4.egg/django/contrib/admin/media
/ 

# And serve our own static files efficiently.
Alias /site_media/ /.../src/fixcity/fixcity/media/ 

<Directory /.../src/fixcity/fixcity/wsgi/>
    Order allow,deny
    Allow from all
</Directory>

WSGIScriptAlias / /.../src/fixcity/fixcity/wsgi/fixcity.wsgi

# Use Daemon mode.
WSGIDaemonProcess bikeraction-dev processes=2 threads=5 
WSGIProcessGroup bikeraction-dev

CustomLog /var/log/apache2/bikeraction-dev-access_log common
ErrorLog /var/log/apache2/bikeraction-dev-error_log

</VirtualHost>

I have not modified LogLevel anywhere; I grepped for it and found
only this:
/etc/apache2/modules.d/00_default_settings.conf:LogLevel warn

I believe that's the stock arrangement on Gentoo Linux.

I did check the default error log, /var/log/apache2/error_log
and found nothing there at the times in question.

I tried your suggested hello world script. It displays this output in
the browser:

mod_wsgi.process_group="bikeraction-dev"
mod_wsgi.application_group="bikeraction-dev.thor.openplans.org|"
type(sys.stdout)="<type 'mod_wsgi.Restricted'>"
id(sys.stdout)="20517152"
type(sys.stderr)="<type 'mod_wsgi.Log'>"
id(sys.stderr)="20617808"

And the error log I configured in my VirtualHost directive contains this:

[Mon Oct 12 15:15:14 2009] [error] importing script
[Mon Oct 12 15:15:14 2009] [error] running application

If I then modify your wsgi script to raise an exception just after the
"running application" line, like so:

    ...
    print >> sys.stderr, "running application"
    print >> environ['wsgi.errors'], "running application"
    raise Exception("something went wrong")
    ...

... I still see "running application" in the error log, and the server
responds with the generic Internal Server Error page, and the
exception is not logged anywhere - neither in my virtualhost's error
log, nor in the main error_log.

Next I tried your suggestion about setting LogLevel to 'info'.  I did
this in my VirtualHost config. Result in my virtualhost's error log is
only this:

[Mon Oct 12 15:22:23 2009] [info] mod_wsgi (pid=30090): Create interpreter
'bikeraction-dev.thor.openplans.org|'.
[Mon Oct 12 15:22:23 2009] [error] importing script
[Mon Oct 12 15:22:23 2009] [error] running application

So, I still don't know whether this is a problem peculiar to this
installation or if there might be a bug in that version of mod_wsgi.
Next I'll try to reproduce this behavior on a different system and see
if I can use the latest mod_wsgi there.

Original comment by sli...@gmail.com on 12 Oct 2009 at 7:58

GoogleCodeExporter commented 8 years ago
Scratch all that! Grepping for a known exception, eg. my "something went wrong"
example above, revealed that they are being logged in a totally unexpected 
error log
which should only be logging messages for an unrelated virtual host,

Presumably this is a configuration error on our side, although I haven't 
spotted the
mistake yet.  Feel free to close this bug, sorry for the waste of time.

Original comment by sli...@gmail.com on 12 Oct 2009 at 8:18

GoogleCodeExporter commented 8 years ago
Do you have an appropriate NameVirtualHost definition for that IP/Port for 
VirtualHost?

What was the VirtualHost directive line and the ServerName directive line for 
the alternate host where logging 
appeared?

Might be asking a but too much, but if you ran that one Python site in embedded 
mode versus daemon mode, 
does it then end up in the correct error log?

There have been issues with daemon mode correctly identifying the right error 
log in the past, but believe 
those issues were fixed back in 1.X.

Original comment by Graham.Dumpleton@gmail.com on 12 Oct 2009 at 9:37

GoogleCodeExporter commented 8 years ago
It turns out there was another VirtualHost configured like <VirtualHost *:80> 
instead
of a specific IP address. Somehow this caused it to handle logging that should 
have
gone to other VirtualHosts.  Specifying the IP address resolved the issue.

Do you still want me to try embedded mode?

Original comment by sli...@gmail.com on 13 Oct 2009 at 1:29

GoogleCodeExporter commented 8 years ago
Sounds like there is an ordering issue then. No need to try anything else. I'll 
leave this open for the time being 
and will do some double checking about where multiple VirtualHost's could 
technically match.

Original comment by Graham.Dumpleton@gmail.com on 13 Oct 2009 at 2:11

GoogleCodeExporter commented 8 years ago
Haven't looked at this again, but not sure I can do anything about it if Apache 
configuration was such that 
Apache when resolving requests picks up wrong VirtualHost due to overlap. 
Closing but will keep an ear out for 
similar issues and look again later if warranted.

Original comment by Graham.Dumpleton@gmail.com on 22 Nov 2009 at 3:10