この記事の要点

Django が実行した SQL は django.db.backends ロガーを DEBUG にすれば出せる ただしDEBUG = True のときしか出力されない。本番で出したいなら別の手段が要る 1 本だけ見たいなら print(queryset.query)。実行せずに SQL 文字列を確認できる 実行済みの一覧は django.db.connection.queries（実行時間付き） N+1 を探すなら django-debug-toolbar。同じクエリの重複を数えてくれる

方法 1: settings.py で全 SQL をログに出す

# settings.py
LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "sql": {"format": "[%(asctime)s] %(message)s"},
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "sql",
        },
    },
    "loggers": {
        "django.db.backends": {
            "handlers": ["console"],
            "level": "DEBUG",        # ここを DEBUG にすると SQL が出る
            "propagate": False,
        },
    },
}

実行すると、かかった秒数付きで次のように出力されます。

(0.001) SELECT "app_user"."id", "app_user"."name" FROM "app_user" WHERE "app_user"."active"; args=(True,)

重要な制約: このロガーは settings.DEBUG = True のときしか動きません。Django が SQL を記録するかどうかを DEBUG で切り替えているためです。本番で確認したい場合は、後述のデータベース側のログを使ってください。

方法 2: 特定のクエリの SQL だけ見る

qs = User.objects.filter(active=True).order_by("-created_at")[:10]

print(qs.query)        # 実行せずに SQL 文字列を得る
# SELECT "app_user"."id", ... FROM "app_user" WHERE "app_user"."active" = True
#   ORDER BY "app_user"."created_at" DESC LIMIT 10

# パラメータを分けて見たいとき
print(qs.query.sql_with_params())

# 実行計画まで見たいとき（PostgreSQL / MySQL）
print(qs.explain())
print(qs.explain(analyze=True))

qs.query の出力は値が埋め込まれた見た目になり、そのまま DB に貼っても動かない場合があります。原因調査には十分ですが、正確な発行内容は次の connection.queries で確認してください。

方法 3: 実行済みクエリの一覧

from django.db import connection, reset_queries

reset_queries()                     # 計測開始

users = list(User.objects.all())
for u in users:
    print(u.profile.nickname)       # ここで N+1 が起きる

print(len(connection.queries))      # 発行された本数
for q in connection.queries:
    print(q["time"], q["sql"][:120])

connection.queries も DEBUG = True のときだけ蓄積されます。長時間動くプロセスではメモリを食い続けるので、区切りごとに reset_queries() を呼びます。

N+1 問題を見つける

from django.db import connection, reset_queries
from contextlib import contextmanager

@contextmanager
def count_queries(label):
    reset_queries()
    yield
    print(f"{label}: {len(connection.queries)} 本")

with count_queries("最適化なし"):
    for u in User.objects.all():
        print(u.profile.nickname)        # 1 + N 本

with count_queries("select_related"):
    for u in User.objects.select_related("profile"):
        print(u.profile.nickname)        # 1 本（JOIN される）

with count_queries("prefetch_related"):
    for u in User.objects.prefetch_related("orders"):
        print(len(u.orders.all()))       # 2 本（別クエリでまとめて取得）

関係	使うもの
ForeignKey / OneToOneField（1 対 1・多対 1）	select_related()
逆参照 / ManyToManyField（1 対多・多対多）	prefetch_related()

方法 4: django-debug-toolbar

pip install django-debug-toolbar

# settings.py
INSTALLED_APPS += ["debug_toolbar"]
MIDDLEWARE.insert(0, "debug_toolbar.middleware.DebugToolbarMiddleware")
INTERNAL_IPS = ["127.0.0.1"]

# urls.py
from django.urls import include, path
import debug_toolbar

urlpatterns += [path("__debug__/", include(debug_toolbar.urls))]

画面の右側にパネルが出て、SQL の本数・実行時間・重複回数・実行計画が一覧できます。「同じクエリが 50 回」といった表示が出れば N+1 です。開発環境専用なので、INSTALLED_APPS への追加は if DEBUG: で囲んでください。

本番で SQL を確認したいとき

DEBUG = True を本番で有効にしてはいけません。設定値やソースコードが画面に露出します。本番ではデータベース側のログを使います。

-- MySQL: 遅いクエリだけ残す
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 1;      -- 1 秒以上
SHOW VARIABLES LIKE 'slow_query_log_file';

-- PostgreSQL: postgresql.conf
-- log_min_duration_statement = 1000  （ミリ秒）
-- SELECT pg_reload_conf();

アプリ側で残したい場合は、connection.execute_wrapper() で自前のフックを差し込む方法もあります。こちらは DEBUG に依存しません。

import logging
import time
from django.db import connection

logger = logging.getLogger("sql")

def log_slow(execute, sql, params, many, context):
    start = time.monotonic()
    try:
        return execute(sql, params, many, context)
    finally:
        elapsed = time.monotonic() - start
        if elapsed > 0.5:                       # 0.5 秒以上だけ記録
            logger.warning("slow %.3fs %s", elapsed, sql[:500])

# ミドルウェアやビューの中で
with connection.execute_wrapper(log_slow):
    list(User.objects.all())

SQL には検索条件として個人情報が入り得ます。ログに残す前に、出力先の権限と保存期間を決めておいてください。

関連

• django — 親カテゴリ
• ログ出力方法 — アプリのログ全般
• ログのローテート設定
• データベースへの接続と操作
• filterの検索オプション
• 素のSQLを直接実行する方法