Bulletを利用してN+1問題を検出する方法

N+1問題とは、取得したN件のデータそれぞれに対してSQLが発行される現象のことをいいます。
N+1問題によるデータベースへの大量アクセスは、アプリケーションのパフォーマンスを低下させる原因の1つです。

今回はN+1問題を検出するBulletの利用方法について紹介します。

下準備: N+1問題の再現

N+1問題が発生するサンプルコードを作成します。
今回は『生徒一覧画面で生徒名と所属学部を表示する』というアプリケーションでN+1問題を再現させます。
rails sでアプリケーションの起動ができている前提で説明をします。

scaffoldでアプリのひな型を作成

scaffoldでStudentモデル（生徒）とDepartmentモデル（学部）に関するコードを一括作成します。

### scaffoldで関連コードを一括作成
$ rails g scaffold department name
$ rails g scaffold student name department:references

### マイグレーションの実行
$ rails db:migrate

N+1問題が発生する画面の作成

生徒一覧画面を作成します。
student.department.nameがN+1問題の発生する箇所です。

<h1>生徒一覧</h1>

<table>
  <thead>
  <tr>
    <th>生徒名</th>
    <th>学部</th>
  </tr>
  </thead>

  <tbody>
  <% @students.each do |student| %>
    <tr>
      <td><%= student.name %></td>
      <td><%= student.department.name %></td>
    </tr>
  <% end %>
  </tbody>
</table>

サンプルデータの作成

seedコマンドを利用してサンプルデータを作成します。

db/seeds.rb

Department.create(name:'経済学部')
Department.create(name:'外国語学部')
Department.create(name:'社会学部')
Department.create(name:'理工学部')

Student.create(name:'鈴木', department_id:1)
Student.create(name:'田中', department_id:2)
Student.create(name:'山田', department_id:3)
Student.create(name:'伊藤', department_id:4)

### seedデータをテーブルにインサート
$ rails db:seed


### seedデータのインサートをやり直したい場合
$ rails db:migrate:reset
$ rails db:seed

N+1問題が発生していることを確認

localhost:3000/studentsにアクセスすると以下のような生徒一覧の画面が表示されます。

アプリケーションログは以下の通りです。

Student Loadに関するSQLが1回実行されたあと、生徒N人の数だけDepartment Loadに関するSQLがN回実行されています。
このように、N+1回SQLが実行されるのでN+1問題と呼ばれています。

 Started GET "/students" for 172.24.0.1 at 2021-05-11 12:28:00 +0000
 Cannot render console from 172.24.0.1! Allowed networks: 127.0.0.0/127.255.255.255, ::1
 Processing by StudentsController#index as HTML
   Rendering students/index.html.erb within layouts/application
   Student Load (0.7ms)  SELECT `students`.* FROM `students`
   ↳ app/views/students/index.html.erb:15
   Department Load (0.7ms)  SELECT `departments`.* FROM `departments` WHERE `departments`.`id` = 1 LIMIT 1
   ↳ app/views/students/index.html.erb:18
   Department Load (0.7ms)  SELECT `departments`.* FROM `departments` WHERE `departments`.`id` = 2 LIMIT 1
   ↳ app/views/students/index.html.erb:18
   Department Load (0.6ms)  SELECT `departments`.* FROM `departments` WHERE `departments`.`id` = 3 LIMIT 1
   ↳ app/views/students/index.html.erb:18
   Department Load (0.6ms)  SELECT `departments`.* FROM `departments` WHERE `departments`.`id` = 4 LIMIT 1
   ↳ app/views/students/index.html.erb:18
   Rendered students/index.html.erb within layouts/application (Duration: 19.0ms | Allocations: 4259)

Bulletの導入手順

Bulletを利用する手順について紹介します。

Bulletのインストール

Bulletのgemを追加します。

Gemfile

group :development do
  gem 'bullet'
end

$ bundle

Bulletの設定を追加

Bulletを有効にするには設定を追加する必要があります。
BulletによるN+1問題の通知方法は設定のオプションで決定されます。

主なオプションは以下の通りです。

Bulletの設定の詳細はBulletのREADME#Configurationを参照してください。

Bulletの設定は以下のように追加します。

config/environments/development.rb

config.after_initialize do
  Bullet.enable = true

  Bullet.bullet_logger = true
  Bullet.rails_logger = true
  Bullet.add_footer = true
end

BulletによるN+1問題の検出結果を確認する

Bulletの設定後、localhost:3000/studentsにアクセスします。

add_footerによる通知は以下の通りです。

bullet_loggerやrails_loggerで表示されるログは以下の通りです。

user: root
GET /students
USE eager loading detected
  Student => [:department]
  Add to your query: .includes([:department])
Call stack
  /rails6_mysql8/app/views/students/index.html.erb:15:in  _app_views_students_index_html_erb__19342287393809088_21300'
  /rails6_mysql8/app/views/students/index.html.erb:12:in `_app_views_students_index_html_erb__19342287393809088_21300'

N+1問題を解決する

includesを利用するとN+1問題が解決できます。

students_controller.rb

def index
- @students = Student.all
+ @students = Student.includes(:department)
end

アプリケーションログをみてわかる通り、先ほどN回実行されていたDepartment LoadのSQLが改善されています。

Started GET "/students" for 172.24.0.1 at 2021-05-11 12:54:32 +0000
Cannot render console from 172.24.0.1! Allowed networks: 127.0.0.0/127.255.255.255, ::1
Processing by StudentsController#index as HTML
  Rendering students/index.html.erb within layouts/application
  Student Load (0.5ms)  SELECT `students`.* FROM `students`
  ↳ app/views/students/index.html.erb:12
  Department Load (0.6ms)  SELECT `departments`.* FROM `departments` WHERE `departments`.`id` IN (1, 2, 3, 4)
  ↳ app/views/students/index.html.erb:12
  Rendered students/index.html.erb within layouts/application (Duration: 7.8ms | Allocations: 2999)

今回のまとめ

Twitter(@nishina555)やってます。フォローしてもらえるとうれしいです！