Measure your queries

A slow view is usually a slow query, and the per-view timing won’t tell you which of the two it is. Turn on database timing and it will.

STATSD_TRACK_DATABASE = True

The middleware wraps every configured connection through Django’s connection.execute_wrapper() for the duration of the request, then unwraps it. Code that runs outside a request is left alone.

# GET /orders/ with STATSD_TRACK_DATABASE on

myproject.view.get.myproject.views.orders.hit
myproject.view.get.myproject.views.orders.process_request
myproject.view.get.myproject.views.orders.process_response
myproject.view.get.myproject.views.orders.process_view
myproject.view.get.myproject.views.orders.sql.default
myproject.view.get.myproject.views.orders.total
myproject.view.http_codes.2xx
myproject.view.http_codes.hit
myproject.view.site.hit

The interesting line is the fifth. sql.default is nested inside the view’s own name, so you get query time per view. A single figure for the whole site would leave you guessing which view to open. default is the alias from your DATABASES setting, which means a project with a read replica reports sql.default and sql.replica side by side.

The timing covers execution. Building the queryset in Python happens before any of this and lands in the enclosing view timing instead, so a view that is slow with a fast sql.default is telling you the problem isn’t the database.

What it costs

# Mean ms per GET /orders/, 300 requests each

STATSD_TRACK_DATABASE off  0.193
STATSD_TRACK_DATABASE on   0.203
overhead                   +0.010 ms (+5.0%)

Ten microseconds a request. The percentage looks larger than it is because the demo view does almost nothing: measured against a view that takes 50 ms, those same ten microseconds are two hundredths of a percent. Leave it on if you want the numbers.

A note on 3.0

This is new in 3.0 and off by default. Earlier versions shipped a cursor subclass that never worked on Python 3, so they collected no query timings at all whatever the documentation said at the time.