How would you configure Django's LOGGING to send slow SQL and request errors to separate handlers, and why might the SQL log stay empty in production?

seniorshould knowfreq 33%

answer

one logger per stream
a callback that reads duration
propagate false stops the echo
query logging depends on DEBUG

basics

~20 s

Attach an ERROR handler to django.request and a handler with a CallbackFilter on record.duration to django.db.backends at DEBUG with propagate False. In production the SQL file stays empty: Django only logs queries when DEBUG is True.

solid answer

~40 s

I give each stream its own logger: django.request at ERROR with a file handler for 5XX tracebacks, and django.db.backends at DEBUG with propagate: False and a handler filtered by a CallbackFilter whose callback returns getattr(record, "duration", 0) > 0.2, so only slow statements are kept and schema records without a duration don't break it. disable_existing_loggers stays False, and I avoid attaching AdminEmailHandler both to django.request and to django, which would double the emails. The catch is that Django wraps cursors for logging only when DEBUG is True or test tooling forces it, so in production no query records exist at all, whatever the level. For production slow queries I'd use the database's own slow-query log.

I give each stream its own logger: `django.request` at `ERROR` with a file handler for 5XX tracebacks, and `django.db.backends` at `DEBUG` with `propagate: False` and a handler filtered by a `CallbackFilter` whose callback returns `getattr(record, "duration", 0) > 0.2`, so only slow statements are kept and schema records without a duration don't break it. `disable_existing_loggers` stays `False`, and I avoid attaching `AdminEmailHandler` both to `django.request` and to `django`, which would double the emails. The catch is that Django wraps cursors for logging only when `DEBUG` is `True` or test tooling forces it, so in production no query records exist at all, whatever the level. For production slow queries I'd use the database's own slow-query log.

code

python · 9 lines

python

from django.utils.log import CallbackFilter


def slow_query(record):
    return getattr(record, "duration", 0) > 0.2


slow_only = CallbackFilter(slow_query)
# In LOGGING: "filters": {"slow_sql": {"()": "django.utils.log.CallbackFilter", "callback": slow_query}}

go deeper

for a junior

Recall that django.request carries request errors and django.db.backends carries SQL, and that each can get its own handler in LOGGING.

for a middle

Explain CallbackFilter, propagate False and the record attributes such as duration that make a slow-query filter possible.

for a senior

Know that query logging requires DEBUG, avoid duplicated emails and propagated floods, and choose database-side slow-query logs for production.

for a principal

Decide which diagnostic streams production must keep, what they may contain, such as SQL parameters, and where they are allowed to be shipped.

The goal

An orders service wants two separate streams: request errors (5XX responses with tracebacks) in one file that alerting watches, and slow SQL in another file that developers read when tuning. Everything else from Django should stay on the console. Django's logger hierarchy makes this a routing exercise, but one condition decides whether the SQL stream has any content at all.

Building blocks

django.request carries 5XX responses as ERROR records with the exception and the request attached.
django.db.backends carries one DEBUG record per SQL statement, with duration (seconds), sql, params and alias as record attributes.
django.utils.log.CallbackFilter(callback) wraps any function that takes the record and returns truthy to keep it, falsy to drop it.
RequireDebugTrue and RequireDebugFalse gate a handler on settings.DEBUG.

The configuration

python

def slow_query(record):
    return getattr(record, "duration", 0) > 0.2   # seconds


LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "filters": {
        "slow_sql": {"()": "django.utils.log.CallbackFilter", "callback": slow_query},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler"},
        "errors_file": {"class": "logging.FileHandler", "filename": "logs/errors.log", "level": "ERROR"},
        "sql_file": {"class": "logging.FileHandler", "filename": "logs/slow_sql.log", "filters": ["slow_sql"]},
    },
    "loggers": {
        "django": {"handlers": ["console"], "level": "INFO"},
        "django.request": {"handlers": ["errors_file"], "level": "ERROR"},
        "django.db.backends": {"handlers": ["sql_file"], "level": "DEBUG", "propagate": False},
    },
}

Design points:

propagate: False on django.db.backends. Without it, every query record also climbs to the django logger; the django logger's INFO level does not stop records that propagate from a child, so its handlers would print every query to the console.
django.request keeps propagating. Its errors land in errors.log and reach the django logger's console handler. If admin emails are wanted, add an AdminEmailHandler handler to django, and don't also attach one to django.request, or each error is mailed twice.
getattr in the callback. django.db.backends.schema is a child of django.db.backends; its records carry no duration, so record.duration would raise inside the filter.
disable_existing_loggers: False keeps every other Django logger working.

Why the SQL file stays empty in production

Django only logs queries when DEBUG is True: the database wrapper checks settings.DEBUG (or a flag test tooling sets, as with manage.py test --debug-sql) before wrapping cursors in the logging wrapper. With DEBUG = False application queries produce no django.db.backends records at all, regardless of the logger's level or handlers. (Migration DDL from the django.db.backends.schema child is logged regardless of DEBUG, but it carries no duration, so the slow-query filter drops it.) The configuration is correct and the file is empty.

That is deliberate: the wrapper times and records every statement, which costs time on every query. Options for production:

turn on slow-query logging in the database itself;
sample queries in application code or middleware around specific views;
use a profiling tool in a staging copy with DEBUG = True, never production.

Enabling DEBUG = True in production to get SQL logs is not an option: it exposes technical error pages and settings to visitors.

Checking the routing

Event	`errors.log`	`slow_sql.log`	console
view raises, 500	yes	no	yes (propagated)
404	no	no	no (a `WARNING`, below `django.request`'s `ERROR` level, so it is dropped at the logger)
350 ms query, `DEBUG = True`	no	yes	no (`propagate: False`)
350 ms query, `DEBUG = False`	no	no record exists	no
migration `ALTER TABLE`, `DEBUG = True`	no	no (no `duration`, filtered)	no

Pitfalls seen in real configs

A level on the handler but not the logger, or the reverse: both gate records, and the stricter one wins.
A relative filename resolved against the process's working directory, which differs between runserver and the production server.
Logging params into a file that is shipped elsewhere: SQL parameters can contain personal data and credentials.

## The goal An orders service wants two separate streams: **request errors** (5XX responses with tracebacks) in one file that alerting watches, and **slow SQL** in another file that developers read when tuning. Everything else from Django should stay on the console. Django's logger hierarchy makes this a routing exercise, but one condition decides whether the SQL stream has any content at all. ## Building blocks - `django.request` carries 5XX responses as `ERROR` records with the exception and the request attached. - `django.db.backends` carries one `DEBUG` record per SQL statement, with `duration` (seconds), `sql`, `params` and `alias` as record attributes. - `django.utils.log.CallbackFilter(callback)` wraps any function that takes the record and returns truthy to keep it, falsy to drop it. - `RequireDebugTrue` and `RequireDebugFalse` gate a handler on `settings.DEBUG`. ## The configuration ```python def slow_query(record): return getattr(record, "duration", 0) > 0.2 # seconds LOGGING = { "version": 1, "disable_existing_loggers": False, "filters": { "slow_sql": {"()": "django.utils.log.CallbackFilter", "callback": slow_query}, }, "handlers": { "console": {"class": "logging.StreamHandler"}, "errors_file": {"class": "logging.FileHandler", "filename": "logs/errors.log", "level": "ERROR"}, "sql_file": {"class": "logging.FileHandler", "filename": "logs/slow_sql.log", "filters": ["slow_sql"]}, }, "loggers": { "django": {"handlers": ["console"], "level": "INFO"}, "django.request": {"handlers": ["errors_file"], "level": "ERROR"}, "django.db.backends": {"handlers": ["sql_file"], "level": "DEBUG", "propagate": False}, }, } ``` Design points: 1. **`propagate: False` on `django.db.backends`.** Without it, every query record also climbs to the `django` logger; the `django` logger's `INFO` level does not stop records that propagate from a child, so its handlers would print every query to the console. 2. **`django.request` keeps propagating.** Its errors land in `errors.log` **and** reach the `django` logger's console handler. If admin emails are wanted, add an `AdminEmailHandler` handler to `django`, and don't also attach one to `django.request`, or each error is mailed twice. 3. **`getattr` in the callback.** `django.db.backends.schema` is a child of `django.db.backends`; its records carry no `duration`, so `record.duration` would raise inside the filter. 4. **`disable_existing_loggers: False`** keeps every other Django logger working. ## Why the SQL file stays empty in production Django only logs queries when `DEBUG` is `True`: the database wrapper checks `settings.DEBUG` (or a flag test tooling sets, as with `manage.py test --debug-sql`) before wrapping cursors in the logging wrapper. With `DEBUG = False` application queries produce no `django.db.backends` records at all, **regardless of the logger's level or handlers**. (Migration DDL from the `django.db.backends.schema` child is logged regardless of `DEBUG`, but it carries no `duration`, so the slow-query filter drops it.) The configuration is correct and the file is empty. That is deliberate: the wrapper times and records every statement, which costs time on every query. Options for production: - turn on slow-query logging in the **database** itself; - sample queries in application code or middleware around specific views; - use a profiling tool in a staging copy with `DEBUG = True`, never production. Enabling `DEBUG = True` in production to get SQL logs is not an option: it exposes technical error pages and settings to visitors. ## Checking the routing | Event | `errors.log` | `slow_sql.log` | console | |---|---|---|---| | view raises, 500 | yes | no | yes (propagated) | | 404 | no | no | no (a `WARNING`, below `django.request`'s `ERROR` level, so it is dropped at the logger) | | 350 ms query, `DEBUG = True` | no | yes | no (`propagate: False`) | | 350 ms query, `DEBUG = False` | no | no record exists | no | | migration `ALTER TABLE`, `DEBUG = True` | no | no (no `duration`, filtered) | no | ## Pitfalls seen in real configs - A `level` on the handler but not the logger, or the reverse: both gate records, and the stricter one wins. - A relative `filename` resolved against the process's working directory, which differs between `runserver` and the production server. - Logging `params` into a file that is shipped elsewhere: SQL parameters can contain personal data and credentials.

Why does the callback use getattr(record, "duration", 0) instead of record.duration?
The handler also receives records from `django.db.backends.schema`, a child logger that logs migration SQL with `sql` and `params` but no `duration`. Accessing `record.duration` would raise inside the filter; `getattr` with a default makes those records fail the test quietly.
What happens if django.db.backends keeps propagate at its default?
Each query record also travels up to the `django` logger's handlers. Parent logger levels don't filter propagated records, so a console handler on `django` without its own level prints every SQL statement, flooding the console in development.

saying these in an interview costs you the question

Setting django.db.backends to DEBUG logs SQL in production
Enable DEBUG = True in production to get query logs
A parent logger's level filters records propagated from children
Attaching AdminEmailHandler to both django and django.request is harmless
CallbackFilter drops a record when the callback returns True

How would you configure Django's LOGGING to send slow SQL and request errors to separate handlers, and why might the SQL log stay empty in production?

§ answer

basics

solid answer

code

§ go deeper

▾level notes4 levels

▾deep dive~3 min

The goal

Building blocks

The configuration

Why the SQL file stays empty in production

Checking the routing

Pitfalls seen in real configs

▾common follow-ups2 questions

▾red flags5 flags

The goal

Building blocks

The configuration

Why the SQL file stays empty in production

Checking the routing

Pitfalls seen in real configs

answer

go deeper