Rails製アプリは、１画面に結構な量の情報を表示しようものなら、すぐにパフォーマンスが悪くなってしまいます。基本を押さえておけばこういったことに陥らないのですが、Railsがあまりにもサクサク開発できちゃうもんですから、ついつい調子に乗って基本を忘れてしまいがち。自分を戒めるためにも、パフォーマンス・チューニングの基本をまとめておくことにします。

環境

Rails 3.2.14
Ruby 2.0
sqlite3（データベース）
WEBrick（httpサーバ）
Mac Book Air 2012 Mid （デュアルコア2.0GHz Intel Core i7）

チューニングするデモアプリ

いまいち冴えないビジュアルのこのデモアプリ『Bookshelf（本棚）』を使用します。テーブルの１セル（td）に１冊の本が納められているつもりです。

Bookshelf仕様

著者（Author）はN件の本（Book）を持つ
デモデータは本1,000件、著者も1,000件
セル（td）の中に各本のタイトル（太字下線）、著者名を表示する
各セル内をクリックすると、本の説明がアラートで表示される（Javascript）

チューニング前

チューニングを始める前に、最初の状態でどれぐらいのパフォーマンスなのか見ておきましょう。これは、簡易プロファイラを導入して計測することにします。

📄Gemfile

source 'https://rubygems.org'

gem 'rails', '3.2.14'
gem 'sqlite3'
gem 'jquery-rails'

group :development do
  gem 'rack-mini-profiler' # 簡易プロファイラ
end

group :development, :test do
  gem 'faker'
end

group :assets do
  gem 'sass-rails',   '~> 3.2.3'
  gem 'coffee-rails', '~> 3.2.1'
  gem 'uglifier', '>= 1.0.3'
end

rack-mini-profilerとは便利な簡易プロファイラで、控えめな表示でゴキゲンなプロファイル情報を提供してくれる素敵なgemです。このgemを入れておくと以下の画面のように小さなウインドウが表示されるようになります。

設定要らずなので楽チンですね。このプロファイラのおかげで、画面をレンダリングするのに４秒以上も掛かっていることが分かりました。

チューニング１：includes

さあそれではチューニングしていきましょう！

まずは、一体何に時間がかかってるのかを知らなければなりません。実はこのプロファイラの小さなウインドウですが、クリックすることで詳細を確認することができるんです。「4220.4ms」と書いたところをクリックしてみると・・・

わわ！なんか一杯「1 sql」って出てきてます。どうやらbooks/_bookパーシャルをレンダリングする際にSQLを発行しているようですね。このSQLは一体何なんでしょう？「1 sql」リンクをクリックするとSQLの詳細が確認できます。

authorを取得するSQLみたいですね。_bookパーシャルというのは本１冊分に相当するViewですが、この中に何か要因があるのでしょうか？_bookパーシャルの中を見てみましょう。

📄_book.html.erb

<div class="book" data-description="<%= book.description %>">
  <div class="title">
    <%= link_to book.title, book %>
  </div>
  <div class="author"><%= book.author.name %></div>
</div>

プロファイラの表示を見るに、このソースの５行目にてSQLが発行されているようです。それらしいところは「book.author.name」という記述でしょう。つまりこれはauthorモデルが『遅延ローディング』されているということです。bookモデルからauthorモデルにアクセスして初めて、authorsテーブルに対するSQLを発行しているのです。いわゆる「N+1件問題」ですね。

念のため、この画面を表示しているBooksコントローラ、さらにはBookモデルのソースも見ておきましょう。

📄BooksController

class BooksController < ApplicationController
  # GET /books
  # GET /books.json
  def index
    @books = Book.all

    respond_to do |format|
      format.html # index.html.erb
      format.json { render json: @books }
    end
  end
…

📄Book

class Book < ActiveRecord::Base
  belongs_to :author
  attr_accessible :author_id, :description, :title
end

コントローラでは、Book.allで本を全件取得しています。Bookモデルでは、特に何もしていません。この画面の仕様上、Bookに紐付くAuthorは最初にまとめて取得しておいた方が効率が良さそうです。

それぞれのファイルを編集します。

📄books_controller.rb

class BooksController < ApplicationController
  # GET /books
  # GET /books.json
  def index
    @books = Book.with_author

    respond_to do |format|
      format.html # index.html.erb
      format.json { render json: @books }
    end
  end
...

📄book.rb

class Book < ActiveRecord::Base
  belongs_to :author
  attr_accessible :author_id, :description, :title

  scope :with_author, -> do
    includes(:author)
  end
end

with_authorというスコープを作成しました。includes(:author)と記述することで、Bookモデルを取得時に親であるAuthorも合わせて取得してくれるようになります。

それでは、再度画面を開いてみましょうか。

ビンゴォ！

あれだけ長かったSQL表示が無くなり、２つに減りましたね。パフォーマンスも劇的に改善しました。いやー気持ちいい！

N+1件問題はエラーではないので、ついつい見逃しがちな問題です。Railsの便利さゆえに、知らず知らずのうちに引き起こしてしまう問題なのかもしれません。このrack-mini-profilerを導入さえしておけば、その手の問題をこまめにチェックすることができるのでオススメです。

次回はさらにチューニングを進めていきたいと思います。

今回使用したソースコード

githubに使用したソースコードを置いておきます。試してみたい方はどうぞ。

https://github.com/itmammoth/ome-tuning

タグ「V0_initial」が最初の状態、「V1_pt」がチューニング後の状態です。

Railsアプリを『浅く』パフォーマンス・チューニングしてみる（その１）

環境