N+1問題を検知するgem 「bullet」を使ってみる

個人開発をしているだけの時はあまり意識していなかったのですが、実際の開発現場で
何千、何万件というデータを扱う場合シビアになる「N +1問題」。それを自動で検知してくれるgem 「bullet」の使い方を紹介します。

「N＋1」問題を引き起こすデータの作成

まずは「N＋1問題」を引き起こすデータを作成していきます。

• モデルの構成

user.rb

class User < ApplicationRecord
  has_many :tasks, dependent: :destroy
end

task.rb

class Task < ApplicationRecord
  belongs_to :user
end

・データ作成

100.times do |i|
  user = User.create(name:"name_#{i}")
  100.times do |j|
    Task.create(name: "task_#{j}",user_id:user.id)
  end
end
# 一万件のTaskを作成

一万件のデーターを作成するのにかかった時間を待っているだけでも「N＋1」問題の大変さがわかりました・・・。

・「N＋1問題」を起こすコードを作成する

tasks_controller.rb

class TasksController < ApplicationController
  def index
    @tasks = Task.all
  end
end

tasks/index.html.haml

- @tasks.each do |task|
  - task.user.name # 無駄に画面の表示されてしまうので '-'で

上記のページをroot_pathに設定しlocalhost:3000にアクセス。その後development.logを確認するととんでもない量のログが書き込まれていることが確認できる。

Processing by TasksController#index as HTML
  Rendering layout layouts/application.html.erb
  Rendering tasks/index.html.haml within layouts/application
  [1m[36mTask Load (29.6ms)[0m  [1m[34mSELECT "tasks".* FROM "tasks"[0m
  ↳ app/views/tasks/index.html.haml:1
  [1m[36mUser Load (0.1ms)[0m  [1m[34mSELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?[0m  [["id", 4], ["LIMIT", 1]]
  ↳ app/views/tasks/index.html.haml:2
  [1m[36mCACHE User Load (0.0ms)[0m  [1m[34mSELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?[0m  [["id", 4], ["LIMIT", 1]]
  ↳ app/views/tasks/index.html.haml:2
  
  # この後も延々とlogが続きます...

bulletのインストール

では、gem bulletを使っていきます。

group :development do
  gem 'bullet'
end

bundle exec rails g bullet:install 

この時、テスト環境にインストールするかどうか尋ねられますので回答。

Would you like to enable bullet in test environment? (y/n)

development.rbに「bullet」の設定が書き込まれます

development.rb

Rails.application.configure do
  config.after_initialize do
    Bullet.enable        = true #　Bulletのgemを利用可能にする。 
    Bullet.alert         = true　　# ブラウザにJSのアラートを出す。
    Bullet.bullet_logger = true # Rails.root/log/bullet.log にbulletのログファイルを出す。
    Bullet.console       = true # consoleに警告を出す。
  # Bullet.growl         = true # Growlがインストールされているときに、ポップアップの警告を出す。
    Bullet.rails_logger  = true # railsのログに警告を出す。
    Bullet.add_footer    = true # 画面左下にメッセージを出す。
  end


end

改めてlocalhost:3000にアクセスすると・・・

alertをtrueにしているのでこちらの警告画面がブラウザに表示されます。

[1m[36mCACHE User Load (0.0ms)[0m  [1m[34mSELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?[0m  [["id", 4], ["LIMIT", 1]]
  ↳ app/views/tasks/index.html.haml:2
Rendered tasks/index.html.haml within layouts/application (Duration: 27729.6ms | Allocations: 15657512)
Completed 200 OK in 27768ms (Views: 27500.9ms | ActiveRecord: 253.9ms | Allocations: 15666649)

# ここから'bullet'の警告
GET /
USE eager loading detected
  Task => [:user]
  Add to your query: .includes([:user])
Call stack

ターミナルにもbulletの警告が出ています。その中で

Add to your query: .includes([:user])

「N＋1問題」を起こさないようなアドバイスもしてくれています。なのでアドバイス通り「includes(:user)」をcontrollerの中で行っておきましょう。

tasks_controller.rb

class TasksController < ApplicationController
  def index
    @tasks = Task.all.includes(:user)
  end
end

再度localhost:3000へアクセス

Completed 200 OK in 2568ms (Views: 2562.6ms | ActiveRecord: 64.6ms | Allocations: 2301281)

先程は出ていた警告が出なくなりました!