読者です 読者をやめる 読者になる 読者になる

Rails Webook

自社のECを開発している会社で働いています。Rails情報やサービスを成長させる方法を書いていきます

Railsでbulletを使ってN+1問題を発見しDBアクセスのパフォーマンスを向上させる

Rails gem パフォーマンス

bulletとは、N+1問題や使われていないEager Loadingを発見するためのツールです。
これらの問題があると無駄なSQLクエリが実行されるので、パフォーマンスを落としてしまいます。
気をつけていてもN+1問題は発生してしまう可能性があるので、bulletを導入して自動で発見できるようにしてみます。

※ N+1問題やEager Loadingについてよくわからない方は、N+1問題 / Eager Loading とはを参照ください。

確認環境

  • Ruby 2.1.2
  • Rails 4.1
  • bullet 4.14.0

目次

  1. Railsプロジェクトの作成
  2. Bulletのインストール方法
  3. Bulletのホワイトリストの設定
  4. Bulletをテストで実行

1. Railsプロジェクトの作成

まずはRailsプロジェクトを作成します。

rails new bullet_test
cd bullet_test

次にbulletの挙動を確認するために、N+1問題を発生させるために必要なソースを作成します。

rails g scaffold Post title:string content:text user_id:integer
rails g model User name:string

Modelに関連を追加します。

# app/models/user.rb
class User < ActiveRecord::Base
  has_many :posts
end

# app/models/post.rb
class Post < ActiveRecord::Base
  belongs_to :user
end

Postの一覧画面でUserモデルも表示するようにします。

# app/views/posts/index.html.erb
    ...
    <% @posts.each do |post| %>
      <tr>
        <td><%= post.title %></td>
        <td><%= post.content %></td>
        <!-- 修正箇所開始 -->
        <td><%= post.user.name %></td>
        <!-- 修正箇所完了 -->
        <td><%= link_to 'Show', post %></td>
        <td><%= link_to 'Edit', edit_post_path(post) %></td>
        <td><%= link_to 'Destroy', post, method: :delete, data: { confirm: 'Are you sure?' } %></td>
      </tr>
    <% end %>
    ...

seeds.rbに初期データを追加します。

# db/seeds.rb
10.times do |i|
  user = User.create name: "ユーザー名#{i}"
  user.posts.create title: "タイトル#{i}", content: "本文#{i}"
end

マイグレーションを実行し、データを投入します。

rake db:migrate
rake db:seed

では、rails sでサーバーを起動し、http://localhost:3000/postsにアクセスしてみてください。
f:id:nipe880324:20141108134446p:plain:w480

このときの、サーバーのログを確認すると次のようになっていて、Postの表示数(10回)+1回のSQlが実行されているので、N+1問題が発生しています。

Started GET "/posts" for 127.0.0.1 at 2014-11-08 12:58:51 +0900
Processing by PostsController#index as HTML
  Post Load (0.3ms) SELECT "posts".* FROM "posts"
  User Load (0.3ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 1]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 2]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 3]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 4]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 5]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 6]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 7]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 8]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 9]]
  User Load (0.1ms) SELECT  "users".* FROM "users"  WHERE "users"."id" = ? LIMIT 1  [["id", 10]]
  Rendered posts/index.html.erb within layouts/application (56.1ms)
Completed 200 OK in 107ms (Views: 101.4ms | ActiveRecord: 2.2ms)


2. Bulletのインストール方法

では、N+1問題を自動的に発見するためにbulletをインストールしていきましょう。

Gemfileにbulletを追加します。

# Gemfile

group :development do
  gem 'bullet'
end

Bundlerを実行します。

bundle install

bulletは明示的に設定を記載しないと何もしないので、設定を記載します。

# config/environments/development.rb

Rails.application.configure do
  ...

  config.after_initialize do
    Bullet.enable  = true   # bullet を有効にする

    # 以下はN+1問題を発見した時のユーザーへの通知方法
    Bullet.alert   = true   # ブラウザのJavaScriptアラート
    Bullet.bullet_logger = true # Rails.root/log/bullet.log
    Bullet.console = true   # ブラウザの console.log の出力先
    #Bullet.growl   = true   # Growl
    #Bullet.xmpp = { :account  => 'bullets_account@jabber.org',
    #                :password => 'bullets_password_for_jabber',
    #                :receiver => 'your_account@jabber.org',
    #                :show_online_status => true }
    Bullet.rails_logger = true # Railsのログ
    #Bullet.bugsnag      = true # 総合デバッガツールbugsnag
    #Bullet.airbrake     = true # Airbrake
    #Bullet.raise        = true # Exceptionを発生
    Bullet.add_footer   = true # 画面の下部に表示
    # include paths with any of these substrings in the stack trace,
    # even if they are not in your main app
    #Bullet.stacktrace_includes = [ 'your_gem', 'your_middleware' ]
  end
end


では、サーバーを再起動し、一覧画面にアクセスし、BulletがN+1問題を検出していることを確認しましょう。
まず、Bullet.alert = trueにより次のようにJavaScriptのアラートが表示されます。
f:id:nipe880324:20141108134453p:plain:w320


さらに、Bullet.add_footerにより画面左下部にも表示されています。
f:id:nipe880324:20141108134458p:plain:w480


画面に表示する系統の問題点として、JSONなどの非同期処理の場合だとうまく表示されないので、Bullet.raise = trueなどにしておくことをお勧めします。

そして、Bullet.rails_logger = truedevelopment.logにも表示されます。

# log/development.log

N+1 Query detected
  Post => [:user]
  Add to your finder: :include => [:user]
N+1 Query method call stack
  /Users/nipe0324/rails_samples/bullet_test/app/views/posts/index.html.erb:18:in `block in _app_views_posts_index_html_erb__4222087890434289677_70113588353160'
  /Users/nipe0324/rails_samples/bullet_test/app/views/posts/index.html.erb:14:in `_app_views_posts_index_html_erb__4222087890434289677_70113588353160'

最後に、Bullet.bullet_logger = truebullet.logにも表示されます。

# log/bullet.log

2014-11-08 13:20:47[WARN] user: nipe0324
http://localhost:3000/posts
N+1 Query detected
  Post => [:user]
  Add to your finder: :include => [:user]
N+1 Query method call stack
  /Users/nipe0324/rails_samples/bullet_test/app/views/posts/index.html.erb:18:in `block in _app_views_posts_index_html_erb__4222087890434289677_70113588353160'
  /Users/nipe0324/rails_samples/bullet_test/app/views/posts/index.html.erb:14:in `_app_views_posts_index_html_erb__4222087890434289677_70113588353160'


では、N+1問題を解決しましょう。
次のように記載されているので、Post取得時にincludes(:user)を追記しましょう。

N+1 Query detected
  Post => [:user]
  Add to your finder: :include => [:user]
# app/controllers/posts_controller.rb

  # GET /posts
  # GET /posts.json
  def index
    @posts = Post.all.includes(:user)
  end

画面を再表示させるとJSのアラートも、画面下部にも何も表示さていないと思います。
f:id:nipe880324:20141108134446p:plain:w480




3. Bulletのホワイトリストの設定

次のようにホワイトを記載することで、N+1問題を無視させることも可能です。

Bullet.add_whitelist :type => :n_plus_one_query, :class_name => "Post", :association => :comments
Bullet.add_whitelist :type => :unused_eager_loading, :class_name => "Post", :association => :comments
Bullet.add_whitelist :type => :counter_cache, :class_name => "Country", :association => :cities

4. Bulletをテストで実行

まず、bulletをtestでも使えるようにします。

# Gemfile

group :development, :test do
  gem 'bullet'

  gem 'rspec-rails'
end

次に、インストールします。

bundle install


テスト環境でもbulletを有効化させます。

# config/environments/test.rb

Rails.application.configure do
  ...

  # bullet for detecting N+1
  config.after_initialize do
    Bullet.enable = true
    Bullet.bullet_logger = true
    Bullet.raise  = true # N+1問題が発見された時にErrorを発生させる
  end
end

次に各テストにBulletのAPIを実行させます。

# spec/rails_helper.rb
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


以上です。