Debugging Sentry locally in a Django project
Sentry is an error tracking platform that is commonly used with Django projects. Instrumenting your application with such a tool can sometimes cause unintended side effects (more on that later). In these cases it can be useful to debug the Sentry SDK while developing locally.
Initializing Sentry without a DSN
The Sentry documentation recommends to initialize the SDK in settings.py
. I usually add a check for whether the environment variable SENTRY_DSN
is set before initializing the SDK (in my case I only set this on staging or production). This is to prevent the overhead of having Sentry running in local development or when running tests.
It is however totally fine to initialize the SDK without setting the dsn
value. Sentry will still instrument the application and capture errors, but it does not send them to the server, which is exactly what we want.
Optional: Adding a custom Transport
class
Without a DSN, Sentry does not set a transport so no data is sent. You can add a custom transport that allows you to inspect what data is sent to the server, or add a breakpoint to analyze the call stack:
Case study: duplicate queries in a Django view with Sentry enabled
In this project there is a view that rendered a Django template which looked like this:
The articles
variable is a queryset that is passed to the render context of that template. So far nothing special, but this particular queryset executed a query that timed out (due to statement timeout being set) and raised an OperationalError
.
Query duplication
Sentry successfully captured this error (in production), but when I logged into Sentry and analyzed the trace, I could see that this slow query was not executed once but was duplicates 25 times!
How was this possible? The articles
variable was only referenced once in the template. Locally I could not reproduce this behavior with Sentry disabled, so my hunch was that Sentry unintentially caused this in production. So I started debugging this request with Sentry enabled in development.
Stack trace
Sentry includes a stack trace with the exception and serializes this data, in other words, converts it into strings to send back to the server.
Traceback (most recent call last):
File "/app/.venv/lib/python3.12/site-packages/django/db/backends/utils.py", line 105, in _execute
return self.cursor.execute(sql, params)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/psycopg/cursor.py", line 97, in execute
raise ex.with_traceback(None)
psycopg.errors.QueryCanceled: canceling statement due to statement timeout
In this particular stack trace there were many calls to Django’s template rendering functions, a lot of them containing a django.template.context.Context
instance in the scope. In fact, there were exactly 25 occurrences of this context
variable… Here are a few of those:
File "/app/.venv/lib/python3.12/site-packages/django/template/response.py", line 92, in rendered_content
return template.render(context, self._request)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/django/template/backends/django.py", line 107, in render
return self.template.render(context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/django/template/base.py", line 171, in render
return self._render(context)
^^^^^^^^^^^^^^^^^^^^^
django.template.context.Context
Sentry creates a string representation for each variable in the scope of a stack frame, by calling repr()
on it. This means that there were 25 repr()
calls on this context
variable that was passed around the call stack.
The django.template.context.Context
class is a dictionary-like object used to pass data from views to templates. It has a custom __repr__()
method where it effectively calls repr()
on all the objects it contains:
Because the articles
queryset was passed as a context variable to the template, repr()
was called 25 times on articles
as well.
repr()
and QuerySets
A QuerySet is evaluated when you call repr()
on it. There have a been a couple discussions whether this is desirable and should be changed. While I’m of the belief that calling repr()
on an object should not cause side effects, the current behavior in querysets can be useful for developers. For instance, to quickly view the results while using a Django shell.
QuerySet cache
QuerySets are lazy, but will use cached results after the first time it is evaluated. Because the query for the articles
failed due to timeout, no results were cached in the queryset. And every subsequent repr()
call by the Sentry SDK on the context
variable resulted in a new query!
Conclusion
Ultimately, the problem was the slow query that caused the error. But the combination of instrumenting the application with Sentry and Django’s quirky behavior with repr()
and QuerySets, exacerbated the issue by executing the problematic query multiple times.
Note that if the query was successful and there was a different error that was raised while rendering the template, calling repr()
would not result in duplicate queries as it would then use the result cache to generate a string representation.
Workaround
The Sentry SDK already has a workaround to prevent executing a query when calling repr()
on a queryset if it’s not yet evaluated. However, this workaround only checks for queryset objects directly, and doesn’t include django.template.context.Context
objects.
To change the repr()
for these Context objects, I create a custom_repr function: