Code

Opened 3 months ago

Last modified 2 weeks ago

#21777 new Uncategorized

Make request exception handling more robust to subsequent exceptions

Reported by: patrakov@… Owned by: nobody
Component: Core (Other) Version: 1.6
Severity: Normal Keywords:
Cc: numerodix@… Triage Stage: Accepted
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX: no

Description

In django/core/handlers/base.py, there is the following piece of code:

except: # Handle everything else.

# Get the exception info now, in case another exception is thrown later.
signals.got_request_exception.send(sender=self.class, request=request)
response = self.handle_uncaught_exception(request, resolver, sys.exc_info())

Contrary to the comment, the exception info is saved too late. If, during the got_request_exception signal handling another exception occurs (and gets ignored), it will overwrite sys.exc.info(), and this subsequent exception will get logged, instead of the original one.

I hit this while playing with MySQL's SSCursor (for exporting a lot of data to CSV). Some exception happened in my application, then Django's default got_request_exception handler kicked in and attempted to rollback. This failed with a ProgrammingError, because not all rows were consumed, and this ProgrammingError went into the traceback e-mail instead of the original exception.

Attachments (0)

Change History (6)

comment:1 Changed 3 months ago by anonymous

  • Needs documentation unset
  • Needs tests unset
  • Patch needs improvement unset

My diagnosis was incomplete. It is not only that exc_info is saved too late. It is also needed to put a try ... except around the signals.got_request_exception.send(...) so that handle_uncaught_exception() is actually called.

comment:2 Changed 7 weeks ago by numerodix

  • Cc numerodix@… added

comment:3 Changed 6 weeks ago by anubhav9042

It would be really nice if you could add the code where you came around with this problem....

comment:4 Changed 6 weeks ago by anonymous

Yes, I understand that it would be a good idea to add a reproducer. However, the original code that led me to this report is under NDA, so I have to make another reproducer. Unfortunately, I will be able to do that only after March, 14th. Sorry for that.

comment:5 Changed 4 weeks ago by patrakov@…

OK, here is the simplest possible example code.

bug21777/urls.py:

from django.conf.urls import patterns, include, url

urlpatterns = patterns('',
    url(r'^$', 'bug21777.views.buggyview'),
)

Relevant part of bug21777/settings.py, enough to reproduce the bug:

SECRET_KEY = 'dummy'

DEBUG = False
TEMPLATE_DEBUG = False
ALLOWED_HOSTS = ['*']
ADMINS = (('admin', 'admin@example.com'),)

EMAIL_BACKEND = 'django.core.mail.backends.console.EmailBackend'

INSTALLED_APPS = (
    'bug21777',
)

MIDDLEWARE_CLASSES = (
)

ROOT_URLCONF = 'bug21777.urls'
WSGI_APPLICATION = 'bug21777.wsgi.application'

bug21777/views.py:

from django.core.signals import got_request_exception

def buggyview(request):
    raise ValueError("Let's pretend this is a bug in my application")

def handler(signal, sender, **kwargs):
    # The handler is buggy, too
    raise KeyError("Let's pretend that the handler itself is confused by the original exception")


got_request_exception.connect(handler)

Test with ./manage.py runserver

Note: here it is important to understand the assumptions not expressed in the code above. In my case, the handler was in some sense confused by the original exception, not just "buggy by itself". So the original exception in the view represents the primary problem, and the exception in the handler is just a nasty consequence.

If you modify the handler so that it is non-buggy, and load the site root URL, then you'll notice that Django sends the admin a nice e-mail with a traceback pointing to the actual buggy view function, and with ValueError. This is good. I have not put it into the above example, but in production we also log all such errors to Apache logs, using logging.StreamHandler.

With the buggy handler, as written above, the e-mail is not sent, no debug output mentions the original ValueError anywhere, and the KeyError related to the confused handler gets logged to stderr. This makes it very hard to debug the original problem in the view. In my opinion, the ideal situation would be if both exceptions were properly logged. Especially since the comment mentions the possibility of "another exception" and expresses the intention to avoid overwriting the original exception info.

comment:6 Changed 2 weeks ago by anonymous

  • Triage Stage changed from Unreviewed to Accepted

Yup, there's totally a codepath where an exception can escape get_response.

Add Comment

Modify Ticket

Change Properties
<Author field>
Action
as new
The owner will be changed from nobody to anonymous. Next status will be 'assigned'
as The resolution will be set. Next status will be 'closed'
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.