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


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

環境

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

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

bookshelf

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

Bookshelf仕様

ER

  • 著者(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を入れておくと以下の画面のように小さなウインドウが表示されるようになります。

rack-mini-profiler

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

チューニング1:includes

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

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

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

無駄SQLauthorを取得するSQLみたいですね。_bookパーシャルというのは本1冊分に相当する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>

プロファイラの表示を見るに、このソースの5行目にて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も合わせて取得してくれるようになります。

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

チューニング1後のプロファイラ

ビンゴォ!

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

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

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

 

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

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

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

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

関連する記事


「Railsアプリを『浅く』パフォーマンス・チューニングしてみる(その1)」への2件のフィードバック

コメントは受け付けていません。