[Django] #20752: Error signals are not reliable, especially when dealing with database errors
Django
errors
------------------------------+------------------------------------------
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Severity: Normal | Keywords: signals errors databaseError
Triage Stage: Unreviewed | Has patch: 0
Easy pickings: 0 | UI/UX: 0
------------------------------+------------------------------------------
In core.handlers.base, unhandled exceptions are processed as such:
{{{
except: # Handle everything else, including
SuspiciousOperation, etc.
# 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())
}}}
Which delivers the error signal to the various handlers (database
transaction resets, things like Sentry etc).
However, the code that dispatches signals aborts the dispatch if any of
the handlers fail (to try..except block):
{{{
for receiver in self._live_receivers(_make_id(sender)):
response = receiver(signal=self, sender=sender, **named)
responses.append((receiver, response))
return responses
}}}
This is perfectly reasonable in most cases, but is problematic when
dealing with top-level error handling, as this prevents the unhandled
error from reaching handlers that just want to report it.
This is very noticeable in cases where "something bad" happens to the
database connection, as the first handler is always the database rollback
handler, which only catches DatabaseError, which excludes a lot of errors
that can and do crop up in production
{{{
def _rollback_on_exception(**kwargs):
from django.db import transaction
for conn in connections:
try:
transaction.rollback_unless_managed(using=conn)
except DatabaseError:
pass
}}}
I think that it will be better to have the error signal dispatcher defer
except raising until after all the handlers were called (or just swallow
them all).
Alternatively, a different signal for error reporting is possible, but I
think that's a little confusing.
Thoughts?
--
Ticket URL: <https://code.djangoproject.com/ticket/20752>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by anonymous):
* needs_better_patch: => 0
* needs_tests: => 0
* needs_docs: => 0
Comment:
Oh, just saw that the defer thing is implemented in send_robust(). Maybe
just switch it from send() to send_robust() then?
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:1>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by tal@…):
* has_patch: 0 => 1
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:2>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Changes (by shai):
* needs_better_patch: 0 => 1
* needs_tests: 0 => 1
* easy: 0 => 1
Comment:
`send_robust()` implies (correctly) that errors are expected. But the
current patch proposes to just silence them, and that seems wrong to me.
Also, if you see a real problem, can you provide a test that exemplifies
it (and can be used to verify that the solution is correct)?
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:3>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by tal@…):
I was on the fence on send_robust(): I generally dislike mechanisms that
just swallow exceptions, because it makes bugs slip through the cracks. On
the other hand, some signal handlers (db rollback) are actually extremely
likely to raise an exception if something bad happened to the underlying
connection, which is what we were seeing.
You can simulate something like this by closing the underlying
connections. You can simulate it by doing something like:
{{{
from django.db import connection
connection.connection.close()
}}}
At a view or a middleware.
Some alternatives to send_robust:
1) implement something that will aggregate the exceptions and just raise a
"SignalHandlersException" container at the end. No exceptions are lost,
but I question the overall value of it in this scenario.
2) Print out exceptions to stderr, which is what django actually ends up
doing when the error signal handler go rogue.
I'm leaning towards option 2.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:4>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Comment (by tal@…):
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:5>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by ianawilson):
I like option 2 as well, but to take it just one step further, what do you
think of doing a `logger.error()` call with the stacktrace? Seems to me
that this gives the most control and flexibility to developers.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:5>
Django
errors
Reporter: tal@… | Owner: nobody
Type: Bug | Status: new
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by tal@…):
shai: while I agree with you on silencing errors being wrong, it does seem
like a problem with send_robust, as it's actually pretty sensible to rely
on the existing "robust" dispatch.
I can also have send_robust emit a call to logger.error (as proposed by
Ian) as a part of this patch, although it might be a little out of scope
:)
What do you think? Right now we're working around this issue by doing some
setattr magic:
{{{
def make_unhandled_signal_safe():
from django.core import signals as core_signals
setattr(core_signals.got_request_exception, 'send',
core_signals.got_request_exception.send_robust)
}}}
and we would very much like to get rid of it :)
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:6>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: Core (Other) | Version: 1.5
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => assigned
* owner: nobody => schacki
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:7>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by schacki):
Please find my patch attached. I have changed the core handler in a way
such that:
- the initial error is logged as expected, so the root cause of the
trouble is visible and not covered by any other exceptions
- all connected handlers are completely executed as expected, so no
unexpected side-effects from one handler to the other
- any exceptions from the handlers are logged to the error log, so no
errors pass silently.
I have also tried to add unit tests. Unfortunately, I have not managed, to
really read the logging output. Any help is appreciated.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:8>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Keywords: signals errors | Triage Stage:
databaseError | Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by schacki):
I have just sent this pull request:
https://github.com/django/django/pull/1778
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:9>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Changes (by ptone):
* version: 1.5 => master
* component: Core (Other) => HTTP handling
* easy: 1 => 0
* stage: Unreviewed => Accepted
Comment:
I agree there is some room to improve the robustness of the handler here
in the case of "something bad happened".
Signal receiver's shouldn't be doing anything fancy when getting the
"got_request_exception" signal (basically heeding the warning in the
docstring of "handle_uncaught_exception", but the handler itself should be
robust against any poorly written signal handler.
Another related place the handler could be more robust is in
"handle_uncaught_exception" itself. While hopefully rare, someone could
have attempted to install some fancy 500 handler which itself raises some
unforseen exceptoin - so maybe a try except is needed there as well, with
some logging, and then returning a minimal 500 ala:
{{{
return http.HttpResponseServerError('<h1>Server Error (500)</h1>',
content_type='text/html')
}}}
Also it is not clear to me why the more robust sending of the signal step
shouldn't just be rolled into handle_uncaught_exception. Those two steps
occur together every single time in the handler, so I'm not sure why they
need to be separate steps - sending the signal could easily be considered
as "part of" handling the uncaught exception.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:10>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Changes (by ptone):
* cc: preston@… (added)
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:11>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Comment (by schacki):
I have changed the code as follows:
1. Refactored the got_request_exception handling into
handle_uncaught_exception. This makes to code much cleaner and the process
more transparent
2. The inital exception, that triggered the handle_uncaught_exception is
the main focus. I.e. this exception is logged first, this exception is
raised if settings.DEBUG_PROPAGATE_EXCEPTIONS is True. This makes
debugging and analyzing the root cause of all the trouble much easier
(which was one of the reasons, why this ticket was raised), nevertheless
all follow-up errors are still logged.
3. Implemented proposal from ptone, to make the resolve500 more robust.
4. Commented the code in handle_uncaugh_exception to make the process and
ideas behind it more transparent.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:12>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
* cc: schacki (added)
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:13>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Comment (by schacki):
Hi all, may I ask on the status here. Anything I could/should? Thanks (was
not aware that I was not logged in while writing my previous message)
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:14>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Comment (by ptone):
schacki - there aren't any steps to do you haven't already, thank you for
the patch. I myself have not been able to make time to give it another
review, I hope to be able to late this week, or early next. You can always
try to recruit any member of the Django community to review the patch (not
just core members), more eyes is always better. Thank you for your
patience.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:15>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Comment (by anubhav9042):
The PR looks good to me. I am not marking it as RFC though, because it
would be better if core-dev does that.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:16>
Django
errors
Reporter: tal@… | Owner: schacki
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError | Needs documentation: 0
Has patch: 1 | Patch needs improvement: 1
Needs tests: 1 | UI/UX: 0
Easy pickings: 0 |
-------------------------------------+-------------------------------------
Comment (by aaugustin):
The PR doesn't apply any more.
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:17>
Django
errors
Reporter: tal@… | Owner: (none)
Type: Bug | Status: new
Component: HTTP handling | Version: dev
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError |
Easy pickings: 0 | UI/UX: 0
Changes (by Mariusz Felisiak):
* owner: schacki => (none)
* status: assigned => new
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:18>
Django
errors
Reporter: tal@… | Owner: (none)
Component: HTTP handling | Version: dev
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError |
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Changes (by Ülgen Sarıkavak):
* cc: Ülgen Sarıkavak (added)
--
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:19>
Django
errors
Reporter: tal@… | Owner:
| YashRaj1506
Type: Bug | Status: assigned
Severity: Normal | Resolution:
Keywords: signals errors | Triage Stage: Accepted
databaseError |
Has patch: 1 | Needs documentation: 0
Needs tests: 1 | Patch needs improvement: 1
Changes (by YashRaj1506):
* owner: (none) => YashRaj1506
Ticket URL: <https://code.djangoproject.com/ticket/20752#comment:20>