RSpec実行時にBulletをかけて、N+1をテストで防ぐ

BulletというRailsでは広く使われているN+1検出用のGemがあります。N+1は起こらないにこしたことはないんですが、通常の設定ではViewの一部に警告されるだけで見落してしまいがちです。それをRSpec実行時にかけて、なおかつN+1が検出されたらテストをfailさせようという話です。

概要

  • N+1クエリの実行は避けたい
  • Bulletを入れてN+1を検出しても見落してしまいがち
  • RSpec実行時にN+1が検出されたらテストをfailさせよう

Bullet is何?

Bulletとは

Rails用のGemでSQLのN+1クエリを検出するためのものです。

N+1とは、1対多のような関係のときリレーションしているレコードからデータを取得しようとして全件取得の1回と、さらに各1件ごとに1クエリ発行されるようなパフォーマンスのよくないデータ取得になってしまう問題です。

例えば、Userが複数のAchievement(実績)を持っていたとき、全実績の一覧にユーザー名を一緒にいれた一覧を作りたいとします。何も考えずにRailsとActiveRecordでやると

achievements = Archievement.all
achievements.each do |achievement|
  p achievement.user.name
end

こうすると、Achievementの数だけuser.nameを取得するクエリが走ります。つまりAchievementがn件あったとして、1(Achievement.all) + n * 1(achievement.user)になります。このAchievementが1万件あったらツライですね。

この問題はSQLの書き方で防げますが、RailsではViewの中でeachを回したりすることもありうっかり見落すこともあります。これを検出してくれるのがBulletというGemです。

なぜやるか

Bulletは通常ではViewで警告が表示されます。乱暴にやれば無視できてしまいますし、最近ではRailsはViewをもたずAPIサーバーとして使われることも珍しくありません。その場合Viewをもたないのでログを見て気づくしかありません。

そこでRSpecでのテスト実行時にN+1を検出して、テストをfailさせることで気づくこともできますし、CIなどでテストがパスしないとMergeできない運用にしていれば混入も防げるでしょう。

期待すること

設定を追加することで、RSpec実行時にN+1が検出されること。また検出されたらテストをfailすること。もちろん何をどうしたら良いかのSuggestがあり、修正したらテスト通ること。そして例外的な対応ができたら尚良し、というところですね。

実際やったこと

前提

まず前提として、User has_many Achievementsという構造で、Achievements一覧のビューにUserの名前も出したいとします。

モデルはこういう感じです。

# app/models/user.rb
class User < ApplicationRecord
  has_many :achievements
end

# app/models/achievement.rb
class Achievement < ApplicationRecord
  belongs_to :user
end

そして、routesは

Rails.application.routes.draw do
  resources :achievements
end

なので、コントローラは

class AchievementsController < ApplicationController
  def index
    @achievements = Achievement.all
  end
end

としてビュー(app/views/achievements/index.html.erb)は

<% @achievements.each do |achievement| %>
  <div>
    <p>title: <%= achievement.title %></p>
    <p>user: <%= achievement.user.nickname %></p>
  </div>
<% end %>

としますね。

各AchievementにひもづくUserのnicknameを出しています。

先程解説したように、Achievement.allにeachしてuserをとってきているので、achievementの件数の数だけuserを取得するSQLが走っています。つまりN+1が発生してしまってる状態ですね。

RSpecによるテスト

ひとまず最小のテストを用意してみます。 今回はRequest Specです。

require 'rails_helper'

RSpec.describe "Achievements", type: :request do
  describe "GET /achievements" do
    subject { get "/achievements" }

    before do
      FactoryBot.create_list(:achievement, 3)
    end

    it "returns 200" do
      subject
      expect(response.status).to eq 200
    end
  end
end

ここでは深く触れませんが、FactoryBotを使ってテストデータを作れるようにしておきます。

早速このテストをまわしてみます。

$ bin/rspec -fd spec/requests/achievements_request_spec.rb

Achievements
  GET /achievements
   returns 200

Finished in 0.80934 seconds (files took 0.19557 seconds to load)
1 example, 0 failures

みたいな感じでテストが通ると思います。まずはテスト成功ですね。

今はまだN+1があろうがなかろうが、テストはそこまで見ていないため結果としてリクエストが成功して200が返るためテストが通ります。

Bulletの導入

ここでBulletを導入します。

Gemfileに

group :development, :test do
  gem "bullet"
end

と書いておきます。BulletのREADMEではdevelopmentしか指定がないので注意です。今回はtest環境でも使いたいので、:testの指定が必要です。

他は基本的にはBulletのREADMEどおりですが

# config/environments/test.rb
Rails.application.configure do
  # ...中略
  config.after_initialize do
    Bullet.enable = true
    Bullet.bullet_logger = true
    Bullet.raise = true # raise an error if n+1 query occurs
  end
end

# spec/rails_helper.rb
RSpec.configure do |config|
  # ...中略
  if Bullet.enable?
    config.before(:each) do
      Bullet.start_request
    end

    config.after(:each) do
      Bullet.perform_out_of_channel_notifications if Bullet.notification?
      Bullet.end_request
    end
  end
end

の2ファイルをこのように変更します。

設定はこれだけです。

テストがfailするか確認する

これでテストでもBulletの検知が入り、N+1が検出されればテストがパスしないようになったはずなので再び回してみます。

$ bin/rspec -fd spec/requests/achievements_request_spec.rb

Achievements
  GET /achievements
    returns 200 (FAILED - 1)

Failures:

  1) Achievements GET /achievements returns 200
     Failure/Error: subject { get "/achievements" }
     
     Bullet::Notification::UnoptimizedQueryError:
       user: aqui
       GET /achievements
       USE eager loading detected
         Achievement => [:user]
         Add to your query: .includes([:user])
       Call stack
         # (...略)

Finished in 0.45614 seconds (files took 0.34697 seconds to load)
1 example, 1 failure

Failed examples:

rspec ./spec/requests/achievements_request_spec.rb:11 # Achievements GET /achievements returns 200

はい。こんな感じでテストがコケます。良いですね。想定どおりコケるテストは良いテストです。

内容を良くみるとBulletのエラーで

USE eager loading detected
  Achievement => [:user]
  Add to your query: .includes([:user])

と言われていますね。解決方も提案されているわけです、素晴しい。

修正して確認する

それでは、指示どおり修正してみます。

今回の場合はAchievementsを取得する際に一緒にUserのTableも連結してデータを取得すればいいわけですね。なのでコントローラを修正します。

class AchievementsController < ApplicationController
  def index
    @achievements = Achievement.includes(:user).all
  end
end

という感じでincludes(:user)をつけてあげます。

これで再度テストを回せば

$ bin/rspec -fd spec/requests/achievements_request_spec.rb

Achievements
  GET /achievements
   returns 200

Finished in 0.84002 seconds (files took 0.17456 seconds to load)
1 example, 0 failures

はい、テスト通りました! 大成功です。

これで

  1. BulletによるN+1クエリの検出がテストでも検知されること
  2. N+1が検出されたらテストがfailすること
  3. N+1が検出されなければテストがパスすること

は担保されていますので、あとはテストともに安心して開発していけばいいわけですね。

今回やらなかったこと

Bulletは基本的にちゃんと検出してくれますが、それでもやはり誤検出もあります。もしくはN+1とわかっているがどうしようもないケースもあるかもしれません(本当に?)。

そういう時のためにwhitelistで警告をさせないものを指定できます。
Bullet READMEのwhitelistを参照すると良いでしょう。

感想

今回は、N+1をBulletとRSpecを用いて防ぐ方法を紹介してみました。前述のとおり、最近のRailsはビューを使わずAPIを通してJSONを提供するサーバーとして使われることも多いため、特に有用だと思います。

ビューがあるとしてもやはりテストの段階で検出し、防げるにこしたことはありませんね。とりあえず動くからでやってしまってあとから対応するのはツライです。「時間ができたときやる」の時間なんてものはいつまでたっても来ないのが人の常です。

しかし、これでも防げない場合があって、それはそもそもテストが書かれていない場合。こればかりはどうしようもないですね。それも合わせてテスト、ちゃんと書いていきましょう。

『天穂のサクナヒメ』レビュー - 全てが調和した完成度の高い素晴しいゲームでした来た道、行く道 LifeJourney[39.1/2020-11](月次振り返り)