60:Django ORMでどんなSQLが発行されているか気にしよう¶
プログラミング迷子: ORMを使えばSQLを知らなくても良い?
後輩W:新しい機能を実装したらレスポンスがすごい遅い……。
先輩T:どんなSQLが発行されてるか確認してみた?
後輩W:どうやったらわかるんですか?
先輩T: Django Debug Toolbar を使うといいよ。あるいは settings.LOGGING にこんな設定を書いて、DBのSQL発行をログ出力しよう。
LOGGING = { 'version': 1, 'handlers': { 'console': { 'class': 'logging.StreamHandler', }, }, 'loggers': { 'django.db.backends': { 'handlers': ['console'], 'level': 'DEBUG', 'propagate': False }, }, }
後輩W:ブラウザでアクセスしたら何十行もSQLが出てきました。
先輩T:それはSQLを発行しすぎみたいだね。SQLを発行している実装コードを確認してみよう。
後輩W:これは何か問題があるんですか?
先輩T:そうだね、SQL発行ごとにデータベースと通信してデータをやりとりするので、意図せずSQL発行が多くなってるのは問題があるよ。こういうのを N+1問題 って言うんだ。
後輩W:そうなんですね……。そういうのはORMでうまくやってくれるんだと思ってました……。
残念ながら、ORMは「SQLを知らなくても使える便利な仕組み」ではありません。 簡単なクエリであればSQLを確認する必要はなく、多くの要件は簡単なクエリの発行で済むかもしれません。 だからといって、ORMがどんなSQLを発行しているか気にしないままでいると、落とし穴にはまってしまいます。
ORMを使ってクエリを作成していると、どんなSQLが発行されているか見えづらくなります。 Pythonの辞書データを使う感覚でDBへのクエリを発行すると、同じSQLが何度も発行されたり、Pythonプログラムとデータベースとの間でデータが往復していたりして、その分アプリは遅くなっていきます。 このような問題はORMで大量のデータを扱ったことがない場合に発生します。
具体的な失敗¶
データベースに格納されているマスターデータ(本のジャンルや企業の営業所名)などの、めったに変更されないけれどよく参照するデータを1リクエスト中に何度も取得している
SELECTで数十万件のIDをデータベースから取得して、それを少し加工してから次のSQLに渡している
期待するデータを得ようとORMで複雑なコードを書いた結果、複雑なSQLが組み立てられてしまい、DBでの処理コストが非常に高い
SELECTで数件のIDを取得して、プログラム側のループ処理でIDそれぞれについて別のテーブルから該当するデータを取得しており、件数に比例してクエリ実行回数が増加する
1番目の問題は、たとえばログ出力に以下のようなSQL発行が短時間のうちに繰り返されている状態です。
DEBUG [2019-12-13 03:23:56,373] django.db.backends (0.000) SELECT "genre"."id", "genre"."name", "genre"."created_at" FROM "genre";
...
DEBUG [2019-12-13 03:23:56,374] django.db.backends (0.000) SELECT "genre"."id", "genre"."name", "genre"."created_at" FROM "genre";
...
DEBUG [2019-12-13 03:23:56,375] django.db.backends (0.000) SELECT "genre"."id", "genre"."name", "genre"."created_at" FROM "genre";
...
2番目と3番目は 62:SQLから逆算してDjango ORMを組み立てる で説明します。 4番目は 61:ORMのN+1問題を回避しよう で説明します。
本項では、そもそも問題に気づくためにはどうすればよいか説明します。
ベストプラクティス¶
以下のポイントを守りましょう。
ORMを使ったクエリを新しく書いたら、ORMが生成するSQLを確認する
1回のSELECTで書けるクエリが複数回に分けて実行されていたら、1つにまとめることを検討する
1つのリクエスト中に何度も同じSQLが発行されていたら、1回で済むように修正する
(中略)詳細は書籍 自走プログラマー をご参照ください