はじめに
こんにちは、ITANDI株式会社でノマドクラウドの開発をしている河合です。
前職では半導体業界の技術営業に従事しており、エンジニア未経験でITANDIに入社さていただきました。休日は、サウナと映画鑑賞(サスペンス系)を楽しんでいます。
ノマドクラウドとは、ITANDIが提供している不動産仲介会社用CRM(顧客管理)のことです。
バックエンドはRails、フロントはhaml、Vueなど、インフラはAWS、エラー監視としてSentryを使っています。
本日は、Railsのbenchmarkを使ってN+1問題を解決したことについて記事を書こうと思います。
背景
SentryでN+1アラートが発生しました。以下のSQLクエリが複数回呼ばれており、リクエストされてから、テンプレートのレンダリングが終了するまで809.37msかかっていました。(テーブル名は変更してあります)
SELECT `hoge_histories`.* FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0
そこで、N+1問題を解決し、レンダリングまでの時間を減らすことを目標に本課題に取り組みます。
何をもって課題を解決したとするか？
レンダリングまでの時間を計測する
Railsでは、benchmarkというメソッドがあります。このメソッドを以下のように記述し、いくつかの解決策を試しつつ、レンダリング終了までにかかった時間を計測しようと思います。
# controllerのアクション内に記述 def edit benchmark('----- benchmar_controllerk#present ------') do @hoge_base = @login_account.hoge_bases.find(params[:id]) end end # view(haml)の先頭に記述 - benchmark('----- benchmar_viewk#present ------') do %h4 Hogeフロー設定 - if @hoge_base.hoge_histories.reservation.present? ....省略....
試してみる解決策
以下の条件分岐がviewで複数回(10箇所以上)定義されていました。アラートに表示されていたSQLクエリとも合致するため、ここが原因のようです。
そこで、この条件分岐に変更を加えることで本課題を解決したいと思います。具体的には、以下の2つの解決策を試してみます。
- SQLキャッシュにアクセスするようにする
- インスタンス変数を参照するようにする
# view(haml)内のコードを一部抜粋 - if @hoge_base.hoge_histories.reservation.present? ....省略.... - if @hoge_base.hoge_histories.reservation.empty? ....省略....
解決策を試す
現状を知る
まずは条件分岐に修正を加えず、レンダリング終了までにかかった時間を計測しました。その結果、561.2msかかりました。
present?とempty?メソッドでは、発行されるSQLクエリが若干異なるため、無駄にDBアクセスしていることが分かります。
----- benchmar_controllerk#present ------ (2.8ms) HogeHistory Load (0.9ms) SELECT `hoge_histories`.* FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 CACHE HogeHistory Load (0.0ms) SELECT `hoge_histories`.* FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 ....省略.... HogeHistory Exists? (0.5ms) SELECT 1 AS one FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 LIMIT 1 CACHE HogeHistory Exists? (0.0ms) SELECT 1 AS one FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 LIMIT 1 ----- benchmar_viewk#present ------ (558.4ms)
SQLキャッシュにアクセスするようにする
present?をexists?メソッドに変更しました。その結果、161.4msになりました。
発行されるSQLクエリが統一されたため、SQLキャッシュにアクセスしてくれるようになりました。また、Exists?は該当のレコードが1つでも存在すれば、その時点でDBへのアクセスを中断し、結果を返すためLoadと比べて若干早い気がしました。
----- benchmar_controllerk#exists ------ (2.5ms) HogeHistory Exists? (0.4ms) SELECT 1 AS one FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 LIMIT 1 CACHE HogeHistory Exists? (0.0ms) SELECT 1 AS one FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 LIMIT 1 ....省略.... ----- benchmar_viewk#exists ------ (158.9ms)
インスタンス変数を参照するようにする
インスタンス変数に、@hoge_base.hoge_histories.reservationの結果を格納し、インスタンス変数に対してpresent?を実行するようにしました。その結果、137.0msになりました。
SQLキャッシュへのアクセス及び、Recordsetからインスタンスオブジェクトの作成にかかる時間が短縮されたため、若干早くなった気がします。
----- benchmar_controllerk#instance_variable ------ (3.0ms) HogeHistory Load (0.7ms) SELECT `hoge_histories`.* FROM `hoge_histories` WHERE `hoge_histories`.`hoge_base_id` = 1 AND `hoge_histories`.`status` = 0 ....省略.... ----- benchmark_view#instance_variable ------ (107.0ms)
SQLキャッシュやインスタンス変数を参照することで起きる弊害
SQLキャッシュやインスタンス変数を参照していると、DBの値が書きかわった時に、データの不整合が起きる可能性があると思います。
値の保持期間を見極め、必要があればreloadメソッド等で、DBから最新の値を取ってくる処理も必要だなと思いました。sidekiqなどのジョブスケジューラでも、SQLキャッシュを有効にしていることがあるため、今後気をつけようと思います。
まとめ
- present?やexists?などSQLクエリを発行するメソッドを使う時は、発行されるクエリを確認し、無駄なDBアクセスを防ぐこと
- SQLキャッシュとインスタンス変数では、インスタンス変数を参照する方が若干処理が早いこと
- DBから取得した値を扱う時は、保持期間を意識し、データの不整合が起きないよう注意すること
感想
本日は、Railsのbenchmarkを使ってN+1問題を解決しました。
単にN+1問題を解決しようとするのではなく、処理にかかる時間を計測しながら取り組むことによって、今後の改善感度の指標や達成感にもつながると思います。(厳密な処理速度等を算出する場合は、もっとちゃんと計測する必要があると思います...)
エンジニアとしてまだまだ未熟ですが、これからも頑張っていこうと思います。
