Django Debug Toolbarでパフォーマンスチューニング

はじめに

現在、Djangoで開発を行っている学生です。
就活を行うにあたって開発の意識を変えている最中です。
そこで、パフォーマンスチューニングを行いたいと考えこの記事を書いて行きます。
もし、おかしな点などあれば教えていただけると幸いです。
対象者は、すでにDjangoでアプリケーションを開発したことある方です。

Django Debug Toolbarとは

公式ドキュメントは以下です。
https://django-debug-toolbar.readthedocs.io/en/latest/installation.html
Django Debug Toolbarは、Djangoアプリケーションの開発におけるデバッグを助けてくれるツールで、
開発中のWebページに関する詳細なデバッグ情報を見ることができます。
このツールは以下のような多岐にわたる機能を備えています。

• リクエストの履歴、各リクエストの統計
• Python、Django、およびインストールされているアプリのバージョン
• CPU等のリソースがリクエストを処理するのにかかった時間、ブラウザに表示されるまでの時間等
• 設定ファイルで設定されている値
• リクエストごとのパフォーマンスデータ
• SQLクエリ
• テンプレートの呼び出し情報
• キャッシュの使用状況

主な機能

1. SQLクエリの分析:

   • 実行されたSQLクエリのリストとそれぞれの実行時間を表示します。これにより、過剰に呼び出されているクエリや非効率なクエリを特定できます。

2. リクエスト/レスポンスの詳細:

   • リクエストヘッダ、セッションデータ、クッキー情報など、HTTPリクエストとレスポンスに関する詳細情報を確認できます。

3. テンプレートのデバッグ:

   • 使用されているテンプレートとそのコンテキスト変数のリストを提供します。テンプレートのレンダリングにかかった時間も計測され、最適化の参考になります。

4. キャッシュの利用状況:

   • Djangoのキャッシュフレームワークを通じて行われたキャッシュの呼び出しを追跡し、キャッシュの効率性を向上させるための情報を提供します。

5. シグナルの監視:

   • Djangoのシグナルディスパッチシステムを通じて送信されるシグナルの詳細を確認できます。

Django Debug Toolbarを使っていく！

パッケージのインストール

以下でインストールすることで使用できます。

pip install django-debug-toolbar

一応pip以外の方法として公式では、以下のように記述されています。なので、debug_toolbarディレクトリのコピーを取得してパスに追加で行けるみたいです。

If you aren’t familiar with pip, you may also obtain a copy of the debug_toolbar directory and add it to your Python path.

Django Debug Toolbar用の設定追加

ここは公式のをほぼまんま訳しただけの記述になるので公式をみてもらった方が確実かと思います。
やることとしては以下の５つです。

1. Check for Prerequisites：　前提条件の確認
2. Install the App: Django Debug Toolbarアプリケーションをの追加
3. Add the URLs：　URLsに指定のURLを追加する
4. Add the Middleware：　ミドルウェアの追加
5. Configure Internal IPs：　内部IPアドレスの設定

ではそれぞれやって行きます。

前提条件の確認

ここはDjangoプロジェクトを立ち上げていじってない人は特に変更はありません。
一応の確認くらいですね。
INSTALLED_APPSにdjango.contrib.staticfilesが含まれていることと、STATIC_URL = "static/"が設定されていることを確認しましょう。

settings.py

INSTALLED_APPS = [
    # ...
    "django.contrib.staticfiles",
    # ...
]

STATIC_URL = "static/"

次に、TEMPLATESのAPP_DIRSがTrueになっていることを確認すれば大丈夫です。

settings.py

TEMPLATES = [
    {
        "BACKEND": "django.template.backends.django.DjangoTemplates",
        "APP_DIRS": True,
        # ...
    }
]

Django Debug Toolbarアプリケーションをの追加

INSTALLED_APPSにdebug_toolbarを追加します。

settings.py

INSTALLED_APPS = [
    # ...
    "debug_toolbar",
    # ...
]

URLsに指定のURLを追加する

Django Debug Toolbar用URLをプロジェクト用urls.pyに追加します。この例では__debug__プレフィックスを使用していますが、アプリケーションの URL と衝突しない任意のプレフィックスを使用できます。

yourproject/urls.py

from django.urls import include, path

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

ミドルウェアの追加

Django Debug Toolbarは、ほとんどがミドルウェアに実装されています。
以下のようにsettings.pyのMIDDLEWAREに追加します。

settings.py

MIDDLEWARE = [
    # ...
    "debug_toolbar.middleware.DebugToolbarMiddleware",
    # ...
]

公式より以下の注意書きがあります。
MIDDLEWARE の順序は重要です。 デバッグ ツールバー ミドルウェアをできるだけ早くリストに含める必要があります。 ただし、応答のコンテンツをエンコードする他のミドルウェア (GZipMiddleware など) の後に来る必要があります。

The order of MIDDLEWARE is important. You should include the Debug Toolbar middleware as early as possible in the list. However, it must come after any other middleware that encodes the response’s content, such as GZipMiddleware.

Djangoのミドルウェアは、リクエストとレスポンスの処理過程で特定の動作を行うためのフレームワークです。
MIDDLEWAREの設定にリストされている順番は、それぞれのミドルウェアがリクエストやレスポンスに対して行う操作の順序を決定します。
なので、順序が重要になってきます。
特に、DebugToolbarMiddlewareは他のミドルウェアよりも早くリストに含める必要がありますが、レスポンスのコンテンツをエンコードするミドルウェアの後に配置する必要があります。

DebugToolbarMiddlewareを配置する最適な位置は、リストの先頭におけ！というわけではなく、既存のミドルウェアの後、特にレスポンスのコンテンツを変更する可能性のあるミドルウェアの後になります。例えば、SessionMiddleware, AuthenticationMiddleware, MessageMiddlewareなどの前に置くと、これらが依存するセッションや認証情報などを正確に追跡できない可能性があります。

自分の場合以下のようになります。

settings.py

MIDDLEWARE = [
    'django.middleware.security.SecurityMiddleware',
    'django.contrib.sessions.middleware.SessionMiddleware',
    'django.middleware.common.CommonMiddleware',
    'django.middleware.csrf.CsrfViewMiddleware',
    'django.contrib.auth.middleware.AuthenticationMiddleware',
    'django.contrib.messages.middleware.MessageMiddleware',
    'django.middleware.clickjacking.XFrameOptionsMiddleware',
    'debug_toolbar.middleware.DebugToolbarMiddleware',  # 追加
]

また、GZipMiddlewareについて書かれているので軽くGPTに聞いてみました。GZipMiddlewareはレスポンスの内容をgzip圧縮するため、デバッグツールバーがこの処理後に動作する必要があります。
これは、デバッグツールバーがレスポンスの内容を解析し、修正を加えることができるようにするためです。

GZipMiddlewareとは？
GZipMiddlewareはDjangoのミドルウェアの一つで、レスポンスの内容をgzip形式で圧縮します。
この圧縮は、Webページのデータを小さくすることで、送信時間を短縮し、パフォーマンスを向上させることができます。
しかし、レスポンスが圧縮された状態で他のミドルウェアによって解析や変更を受けると問題が発生することがあるため、DebugToolbarMiddlewareのようなミドルウェアはGZipMiddlewareの後に配置する必要があります。

内部IPアドレスの設定

最後に、IPアドレスが DjangoのINTERNAL_IPSにリストされている場合にのみ表示されます。 これは、ローカル開発の場合、INTERNAL_IPSに127.0.0.1を追加する必要があることを意味します。この設定が設定モジュールにまだ存在しない場合は、作成する必要があります。

ALLOWED_HOSTSとは別になるので注意してください。
（自分はアホだったので勘違いして動かない😭ってなってました笑）

settings.py

INTERNAL_IPS = [
    # ...
    "127.0.0.1",
    # ...
]

動作確認

開発環境でrunserverでサーバーを起動しhttp://127.0.0.1:8000/にアクセスしてみてください。
以下のように右側に表示されていれば動作確認OKです。

パフォーマンスチューニング（SQLクエリの最適化）

今回はちょっと気になっていたSQLクエリについてみていこうと思います。
今後キャッシュやレンダリングなどをみた時に元気があればここに追記して行きます。

SQLクエリ関連のボトルネックの見つけ方

SQLクエリだけをみるのはボトルネックを見つけることにはならないですが、今回はSQLクエリのパフォーマンスだけをみて行きます。
本来であれば色々調査した上でどこで遅くなっているのかを探すべきですよね。すみません。。
あまり詳しくないのでGPTに聞いてみたら以下の５つを教えてくれました。

• クエリの実行時間
• クエリの発行回数
• リソースの使用率
• インデックスの利用状況
• 待機統計情報

今回は、インターンで知ったN+1問題を探してみたいと思います。
なので、クエリの発行回数に注目して行きます。
右側のパネルのSQLを選択するとみれるようになります。
気になっていたページをみてみたら以下のスクショのような結果でひどかったです。

SQL queries from 1 connection
default 16.54 ms (189 queries including 180 similar and 90 duplicates )

189回クエリを発行していて180件が類似し、90件が重複しているという典型的なN+1問題が発生しています。

詳細を見る

以下のスクショの部分に注目して行きます。

90 similar queries. Duplicated 3 times.

90回似たものが発行され、３回重複しているとあります。
+を押すとSQL文やどこで使われているのかをみることができます。

実際にコードを見る

表示されていたのは以下のTemplatseの部分でした。
with句の部分ですね。確かどうしたらいいのかわからず強引に実装した部分です。

<div class="sp-box">
    <div class="evaluation-box">
    <div class="evaluation"><!--星の数作成-->
    {% with range=''|center:class.avg_star_score %}
    {% with sub_range=''|center:class.sub_avg_star_score %}
    {% for x in range %}★{% endfor %}{% for x in sub_range %}☆{% endfor %}
    {% endwith %}
    {% endwith %}</div>

さらに詳しく見て行きます。
評価の平均を取得していますが、ここで毎回クエリを発行していますし、平均と白塗りのためにもう一度発行して先ほどのTemplatesの部分だけで2回発行です。
また、これが全ての表示される授業分行われるのでN＋1いや、2N+2問題なんですかね。
と冗談はさておきどう改善するか考えて行きます。

classname/models.py

class ClassName(models.Model):
    # model定義

    def avg_star_score(self):
        evaluations = ClassEvaluation.objects.filter(classdetail__classname=self)
        evaluation  = evaluations.aggregate(Avg('score'))
        if evaluation["score__avg"]:
            return evaluation["score__avg"]
        else:
            return 0
    def sub_avg_star_score(self):
        evaluations = ClassEvaluation.objects.filter(classdetail__classname=self)
        evaluation  = evaluations.aggregate(Avg('score'))
        
        if evaluation["score__avg"]:
            return math.ceil(5-evaluation["score__avg"])
        else:
            return 5

SQLクエリの最適化のアプローチ方法

試したことを順に書いていきます。
おそらく最適解まで長くなりますが、ご了承ください。

ManyToManyFieldにおけるprefetch_related

Templates内で何回も呼ばれるものがあります。
例えば以下のようなschool_yearというManyToManyFieldでclassに紐づけられている値を表示していますが、これがclass分school_yearを取得するクエリが発行されます。
classが1000個あれば1000回クエリが発行されることになってしまいます。

class_list.html

{% for school_year in class.school_year.all %}
    <div class ="school_year tag{{ school_year }}">
        {{school_year}}
    </div>
{% endfor %}

これはN+1問題ですね。
これを解決するのはかなり簡単で、以下のようにprefetch_relatedを使用するだけで解決できました。

views.py

object_list = ClassName.objects.all()
object_list = object_list.prefetch_related('school_year')

上記の問題は以下の記事を参考にしました。
https://zenn.dev/shimakaze_soft/articles/99452bc12af6b0

annotate()

先ほど見つけた部分を解決していきたいと思います。
以下のやつですね。

classname/models.py

class ClassName(models.Model):
    # model定義

    def avg_star_score(self):
        evaluations = ClassEvaluation.objects.filter(classdetail__classname=self)
        evaluation  = evaluations.aggregate(Avg('score'))
        if evaluation["score__avg"]:
            return evaluation["score__avg"]
        else:
            return 0
    def sub_avg_star_score(self):
        evaluations = ClassEvaluation.objects.filter(classdetail__classname=self)
        evaluation  = evaluations.aggregate(Avg('score'))
        
        if evaluation["score__avg"]:
            return math.ceil(5-evaluation["score__avg"])
        else:
            return 5

これはわざわざメソッドとして呼ばずにできる方法を見つけました。
annotate()を使用する方法です。
annotate()メソッドは各オブジェクトに即席のカラムを追加するような役割があります。
なので、任意のobjectにくっつけちゃおうってできます。

object_list = ClassName.objects.annotate(avg_score=Coalesce(Avg('classdetails__evaluation_classdetail__score'),0.0))

avg_scoreに取得した評価の平均を入れます。
また、使用しているCoalesceはNULLじゃない最初の要素を返します。評価が存在しない場合Noneが帰ってくるため0.0を返すようにしています。
上記のようにすることで毎回呼び出さずに一括で取得できるようになります。
参考：
https://docs.djangoproject.com/en/5.0/topics/db/aggregation/
https://docs.djangoproject.com/en/5.0/ref/models/database-functions/

ただ。。ここで問題が。。

JOINされたテーブルを全取得してしまう問題

先ほどのannotate()を使用するまでは良かったんです。
ただ、仮にclassが1000件あるとします。
変更前は、pagenatorを使用していて１ページに30件ずつ表示していました。
ここで、Templatesでクエリを発行していたため先ほどのannotate()を使用して取得した部分が30件分しか発行されていなかったんです。
ですが、annotate()でまとめて取得した結果1000件分を全取得してしまう問題にあたります。これによりパフォーマンスが結果として変更前と同等か劣化してしまっていました。
調べてて知りましたが、pagenatorで分けた後でもannotate()が使えました！
ということで以下のようにして一旦完成です！

views.py

pages = pages.object_list.annotate(avg_score=Coalesce(Avg('classdetails__evaluation_classdetail__score'),0.0))
pages = pages.annotate(sub_avg_score=5-Coalesce(Avg('classdetails__evaluation_classdetail__score'),0.0))
pages = pages.annotate(evaluation_count=Count('classdetails__evaluation_classdetail'))
pages = pages.prefetch_related('school_year')
pages = pages.prefetch_related('classroom')

二つの最適化を行った結果

以下にスクショ貼りましたが、以下のような変化がありました。

• クエリ数189から11の-178
• 実行時間16.54msから9.78msの-6.76ms

実行時間に関しては、平均を取っていないため環境によって違いが出そうですが、一旦はこれで終わりたいと思います。

最適化前

最適化後