RubyOnRails を使ってみる 【第 10 回】 パフォーマンスチューニング
著者：masuidrive
はじめに
Rails が日本で流行り初めて約 2 年。 特に去年は技術系雑誌やニュースサイトなどでも Rails の名前を見ることが非常に多い 1 年でした。 しかしその一方で、信頼性や速度に対する情報不足、プログラマの確保の難しさなどから、実際にサービス構築まで踏み込めないケースもよく聞かれます。
Rails で作ったサービスを公開する上では、安定性とパフォーマンスは抜きにして語れない話題です。 安定性については、自分が過去に作ったサービスや、海外のRailsで作られたサービスを引き合いに出して、納得してもらえるのですが、 Rails のパフォーマンスがどの程度のものなのか、数字を出して示している資料は、ほとんど見つかりませんでした。
そこでここでは Rails のパフォーマンスチューニングを通じて、実際に Rails のパフォーマンスを見てみましょう。
パフォーマンスを計測しよう
遅いと言われることが多い Rails ですが、実際にどれぐらいの速度が出るのか、 Rails アプリケーションのパフォーマンスを計測してみましょう。
パフォーマンスを計測するには、ターゲットアプリケーションが必要です。 Ajax scaffold を使って簡単なアプリケーションを作ってみましょう。
$ sudo gem install ajax_scaffold_generator mongrel --include-dependencies
$ rails sample1
$ cd sample1
$ echo "require File.join(File.dirname(__FILE__), 'boot'); Rails::Initializer.run { |config| config.action_controller.session_store = :active_record_store }" > config/environment.rb
$ vi config/database.yml ←適当な設定をする
$ rake db:sessions:create
$ ./script/generate model person name:string address:text note:text
$ rake db:migrate
$ rake db:migrate RAILS_ENV=production
$ ./script/generate ajax_scaffold --force person addressbook続いてテストデータを投入します。 Rakefile に下記のレシピを追加してください。
task :test_data do
require './config/environment'
(1..40).each do |index|
Person.create :name => "テスト#{index}", :address => "住所#{index}"*10, :note => "ノート#{index}"*10
end
endこのテストデータを Development (開発) 環境と Production (実行) 環境に投入して、サーバを Production 環境で起動します。 今回は Rails の起動に mongrel を使っています。 この Rails の起動方法によっても Rails のパフォーマンスは大きく変わってきます。 サーバとパフォーマンスについては、舞波さんの優しいRailsの育て方 運用サーバ速度比較で比較されているので、こちらも参考にしてください。
$ rake test_data
$ rake test_data RAILS_ENV=production
$ mongrel_rails start --environment=production何もオプションを付けずに mongrel を実行すると、デバッグがしやすいように Development 環境で実行されるため、パフォーマンスが大幅に低下します。 パフォーマンスチューニングの際には必ず Production 環境を指定して実行してください。
続いて、別のコンソールを開き、ログを表示させます。
$ tail -f log/production.logさて、起動したアプリケーションにブラウザからアクセスしてみましょう。 「http://localhost:3000/addressbook/list」をブラウザで開きます。
Ajax Scaffold Generatorで作ったサンプル
同時に、先ほど別に開いたコンソールに、下記のようなログが出力されています。 このログには色々な情報が記載されていますので、まずはこれを読んでみましょう。
Processing AddressbookController#list (for 127.0.0.1 at 2007-05-11 06:45:29) [GET]
Session ID: 2e8657b2292c23148677c36dcef2a49c
Parameters: {"action"=>"list", "controller"=>"addressbook"}
Rendering within layouts/addressbook
Rendering addressbook/list
Start rendering component ({:action=>"component", :params=>{"action"=>"list", "controller"=>"addressbook", "page"=>1, "sort_direction"=>"asc", "sort"=>nil, "scaffold_id"=>"person"}, :controller=>"/addressbook"}):
Processing AddressbookController#component (for 127.0.0.1 at 2007-05-11 06:45:29) [GET]
Session ID: 2e8657b2292c23148677c36dcef2a49c
Parameters: {"action"=>"component", "id"=>nil, "controller"=>"addressbook", "scaffold_id"=>"person", "sort"=>nil, "sort_direction"=>"asc", "page"=>1}
Rendering addressbook/component
Completed in 0.05320 (18 reqs/sec) | Rendering: 0.04846 (91%) | DB: 0.00312 (5%) | 200 OK [http://localhost/addressbook/list]
End of component rendering
Completed in 0.05583 (17 reqs/sec) | Rendering: 0.05558 (99%) | DB: 0.00000 (0%) | 200 OK [http://localhost/addressbook/list]これは 1 アクセス分のログです。 ブラウザからアクセスされ起動されたメソッドとパラメータが Processing 行以降に書かれ、カッコ内の部分がそれぞれの実行時間になります。
Ajax Scaffold はちょっと複雑になっていて、list アクションが呼ばれると、内部で component アクションを呼び出して処理を委譲してしまいます。 そのため 1 アクセスで二つの Processing が出力されています。
このアクセスでは /addressbook/list を実行するのに 0.05583 秒かかり、 そのうち HTML を生成する View 部分が 0.05246 (0.05558-0.00312) 秒で、 データベースの実行時間が 0.00312+0.000000 秒で 0.00312 秒になります。 内部で component を使っている場合、 View 部分は最後の Completed の行の時間から他の Completed 行の DB を引いた時間、 DB は全ての Complated の行を足した時間になります。
最後の「Completed in 0.05583 (17 reqs/sec) 」から読むと、 このサーバでは 1 秒間に 17 リクエスト処理ができることになります。
httperf を使って Rails の性能を計測する
しかし、このログが出している実行時間は Rails 内部の実行時間のみです。 実際には Web サーバの処理などがこれに加算されます。 外部からアクセスした場合の実際の性能を計るには、HTTP のベンチマークソフトを使います。 最も有名な HTTP ベンチマークソフトは、Apache httpd に付属している、ab (apache bench) ですが、 最近ではこれより高性能な httperf がよく使われています。 多くのディストリビューションでパッケージとして配布されていますので、 それを利用してインストールしてください。 Mac OS X の場合は、MacPorts でインストールすることができます。
httperf を使って、先ほどのアプリの実際の性能を計測してみます。
$ httperf --server=localhost --port=3000 --uri=/addressbook/list --num-conns=100 --num-calls=1httperf の使い方を簡単に見ていきましょう。 –server –port –uri の 3 つのオプションでアクセスするページを指定しています。 –num-calls では Keep Alive 時に 1 接続で何回アクセスするかを指定し、 –num-conns で総接続数を指定します。 今回は http://localhost:3000/addressbook/list に 100 接続で 100 アクセスします。
httperf の出力結果は下記のようになります。
httperf --client=0/1 --server=localhost --port=3000 --uri=/addressbook/list --send-buffer=4096 --recv-buffer=16384 --num-conns=100 --num-calls=1
httperf: warning: open file limit > FD_SETSIZE; limiting max. # of open files to FD_SETSIZE
Maximum connect burst length: 1
Total: connections 100 requests 100 replies 100 test-duration 31.146 s
Connection rate: 3.2 conn/s (311.5 ms/conn, <=1 concurrent connections)
Connection time [ms]: min 276.1 avg 311.5 max 577.7 median 289.5 stddev 47.6
Connection time [ms]: connect 0.1
Connection length [replies/conn]: 1.000
Request rate: 3.2 req/s (311.5 ms/req) ← *
Request size [B]: 76.0
Reply rate [replies/s]: min 3.2 avg 3.2 max 3.2 stddev 0.0 (6 samples)
Reply time [ms]: response 309.4 transfer 1.9
Reply size [B]: header 276.0 content 44166.0 footer 0.0 (total 44442.0)
Reply status: 1xx=0 2xx=100 3xx=0 4xx=0 5xx=0
CPU time [s]: user 6.25 system 24.41 (user 20.1% system 78.4% total 98.4%)
Net I/O: 139.6 KB/s (1.1*10^6 bps) ← *このログのうち、Rails のパフォーマンスチェックに使う指針は 「Request rate: 3.2 req/s (311.5 ms/req)」になります。 これは、1秒間の処理リクエスト数が 3.2 回で、1 リクエスト当たり 311.5 ミリ秒かかっていることを示しています。 要するにこのサーバでは、1 秒当たり 3.2 回以上のリクエストを受け取ると処理能力を超えてしまい、 ユーザからすると「レスポンスが悪く、重いサービス」ということになってしまいます。
またもうひとつの指針として「転送速度」があります。 先ほどのログの最後の部分「Net I/O: 139.6 KB/s (1.1*10^6 bps)」がそれを示しています。 これはこのページに連続アクセスした場合、139.6Kbytes/sec (1.1Mbps) のデータ転送量になることを示しています。
転送速度がネットワークの速度よりも速い場合は、 アプリケーションのチューニングの前にネットワークの増強が必要です。 例えばサーバを家の ADSL に設置していて、上りが 1Mbps しか出ない場合には、 ユーザからのアクセス速度はネットワークに制限されることになります。
さて、この値を見ると、先ほど確認した Rails のログの 「Completed in 0.05583 (17 reqs/sec)」と差違が生じていることに気づかれましたか。 Rails のログでは、Web サーバの部分や Rails 内部の一部の速度が含まれていないためです。
Web サーバ部のパフォーマンスを計測する
では、ログに現れていない部分のパフォーマンスを少し詳しく調べてみましょう。 まずは Web サーバ部分のパフォーマンスです。 Web サーバのみのパフォーマンスを計測するために、先のページを静的な HTML にした後、サーバに設置して、それの速度を計測してみましょう。
まずは、wget で現在のページを静的な HTML にします。
$ wget http://localhost:3000/addressbook/list --output-document=public/static_list.htmlそしてそれを静的ファイルとして public ディレクトリに置き、httperf で計測します。
$ httperf --server=localhost --port=3000 --uri=/static_list.html --num-conns=100 --num-calls=1
(中略)
Request rate: 274.3 req/s (3.6 ms/req)
(中略)
Net I/O: 11904.0 KB/s (97.5*10^6 bps)
(中略)静的ファイルだけだと、274.3 アクセス/秒で処理されています。 これを転送量に直すと 97.5Mbps 出ているので、静的ファイルを公開する上では、十分なスペックでしょう。
フレームワーク部分のパフォーマンスを計測する
続いて何もしないで同じサイズのファイルを返すアクションを作り、速度を計測してみましょう。 これでフレームワーク部分のオーバーヘッドが計測できます。 先ほどと同じように wget でファイルをダウンロードし、それを view に設置して速度を計測します。 今度は public フォルダ以下ではなく、app/views 以下に置くことで、フレームワークを通って処理されます。
$ ./script/generate controller ab_static
$ wget http://localhost:3000/addressbook/list --output-document=app/views/ab_static/list.rhtml
$ httperf --server=localhost --port=3000 --uri=/ab_static/list --num-conns=100 --num-calls=1
(中略)
Request rate: 3.8 req/s (264.5 ms/req)
(中略)
Net I/O: 164.3 KB/s (1.3*10^6 bps)ここでは、48.3 リクエスト/秒まで落ちています。 転送速度では 13.6Mbps です。 静的なファイルのリクエスト時間が 3.6 ミリ秒で、今回が 264.5 ミリ秒ですから、260.9 ミリ秒がフレームワークの処理時間になります。 正確には app/views/ab_static/list.rhtml の出力時間を含みますが、これは非常に少ないので、ここでは無視します。
フレームワーク部分の高速化
まずは、フレームワークの処理時間を速くすることはできないでしょうか？ 個々のアクションの高速化も大切ですが、 全てのアクションで実行されるフレームワーク部分の高速化は、 全体のパフォーマンスに非常に大きな影響をもたらします。 この部分を速くする方法はないのでしょうか？
実は、不要な機能を停止したり、複雑になってしまう部分をシンプルにすることで、 ある程度高速化することができます。
セッションをオフにする
今回はログイン機能などを使っていないので、セッション機能をオフにしましょう。 app/controllers/application.rb の session 行を下記のように書き換えます。
class ApplicationController < ActionController::Base
# Pick a unique cookie name to distinguish our session data from others'
session :session_key => '_sample1_session_id'
end
↓ session 行を変更
class ApplicationController < ActionController::Base
# Pick a unique cookie name to distinguish our session data from others'
session :disabled => true
endそして、計測してみましょう。
$ httperf --server=localhost --port=3000 --uri=/ab_static/list --num-conns=100 --num-calls=1
(中略)
Request rate: 168.8 req/s (5.9 ms/req)
(中略)
Net I/O: 7326.1 KB/s (60.0*10^6 bps)264.5 ミリ秒から 5.9 ミリ秒へ高速化されました。 「addressbook/list」へアクセスしてベンチマークをとっても、 「14.3 req/s (70.0 ms/req)」と、ほぼ同じだけ高速化されました。
実はこのように、フレームワークの処理におけるセッションの処理は、非常に重い処理のひとつです。 セッションありのアクセスの場合、処理時間の 97% がセッションの処理に当てられていたことになります。
特に今回の実験では SQLite3 でセッションの保存を行っているため、ディスク IO がネックになっているものと思われます。 MySQL で別のサーバでセッションを保存している場合には、ここまでの差は出ない場合もあります。
Rails ではセッションの利用をコントローラごとやアクションごとに指定できます。 例えば、トップページのアクションでセッションが要らない場合はそこだけ無効にするなど、 こまめにセッションを無効にすることで、パフォーマンスを上げることができます。
高速なセッションストアを使う
しかし、これではセッションを保存するアプリケーションを速くすることができません。 実はセッションの保存が遅い理由のひとつが保存方法です。 標準ではデータベースに保存するときに ActiveRecord 経由で保存されます。 SQLSessionStore というプラグインを使えば、ActiveRecord を経由せず直接SQLを使ってセッションを保存することができます。
このプラグインの導入は非常に簡単なので試してみましょう。 まずはプラグイン本体をインストールします。
$ cd vender/plugins
$ svn co http://railsexpress.de/svn/plugins/sql_session_store/trunk sql_session_store
$ cd ../..そして、セッションの保存方法を変更するために、 config/environement.rb の config.action_controller.session_store をコメントアウトし、 セッションの保存先を SqlSessionStore に変更します。
また、今までのテストでは、データベースに SQLite3 を使っていましたが、 SqlSessionStore ではサポートされていないので、 このテストのみデータベースを MySQL へ変更して行います。
まずは比較のため、MySQL で ActiveRecordStore を使ったベンチマークを計測しておきます。
$ httperf --server=localhost --port=3000 --uri=/ab_static/list --num-conns=100 --num-calls=1
(中略)
Request rate: 164.7 req/s (6.1 ms/req)次に config/environment.rb を下記のように修正し、SqlSessionStore を有効にします。
# 下記をコメントアウトし
config.action_controller.session_store = :active_record_store
↓
# config.action_controller.session_store = :active_record_store
# ファイルの最後に下記の 2 行を追加します。
ActionController::CgiRequest::DEFAULT_SESSION_OPTIONS.update(:database_manager => SqlSessionStore)
SqlSessionStore.session_class = MysqlSessionそして、セッションを保存するテーブルを SQLSessionStore 用に変更します。
$ ./script/generate sql_session_store mysql
$ rake db:migrate RAILS_ENV=productionさて、もう一度計測してみましょう。
$ httperf --server=localhost --port=3000 --uri=/ab_static/list --num-conns=100 --num-calls=1
(中略)
Request rate: 184.1 req/s (5.4 ms/req)MySQL で ActiveRecordStore を使った場合には 6.1 ミリ秒でしたが、SqlSessionStore を使うと 5.4 ミリ秒と 12% 高速化されました。 ここではあまり差が開きませんでしたが、同時に多くのセッションを扱うようになれば、この差は開いていくものと思われます。
セッションを使わないのであればオフに、使うのであれば SQLSessionStore を使うことで、速度を上げることができます。
必要のないプラグインを削除する
今回はサンプルアプリケーションなので、プラグインの導入は必要最低限しか行っていませんが、 本格的なアプリケーション構築の場合、かなりの数のプラグインを導入することがあります。 プラグインによっては、インストールしておくだけで速度が低下するものがあります。
速度を気にするケースの場合、プラグインの導入前後でベンチマークをとってみることをおすすめします。
View を高速化
さて、セッションを無効、もしくは高速なセッションに切り替えることで、フレームワーク部の速度向上が図れることが分かりました。 続いて、アプリケーションの中を見てみましょう。 アプリケーションの中のチューニングにまず役に立つのは Rails のログです。 「パフォーマンスを計測しよう」の章で確認した Rails のログをもう一度見てみます。
そこでも説明しましたが、Rendering と呼ばれる HTML の生成部分に 40 ミリ秒以上かかっていることが分かります。 このアプリケーションでは実行時間のほとんどが HTML の生成にかかることが分かります。
Rails では、View を中心とした高速化の手法として、キャッシュ機構を内蔵しています。 これを使えば同じ HTML を二度生成することなく、その分の処理がまるごと省けるので、かなりの高速化が見込めます。 しかし、キャッシュの導入は、適用範囲やキャッシュの破棄などにより、プログラムが複雑になりがちです。 特に HTML の構造がたびたび変更されるときには、そのたびにキャッシュの範囲を再設計する必要があるなど手間がかかってしまいます。 できれば最後の手段に取っておきたい手法です。
render が犯人
では、それ以外に View を高速化する方法を探ってみます。 ログからもう少し情報を探れないか、ログの出力レベルを :debug にします。 config/environment.rb を下記のように変更します (見やすいように改行を入れてあります)。
require File.join(File.dirname(__FILE__), 'boot');
Rails::Initializer.run { |config|
config.action_controller.session_store = :active_record_store
}
↓ 1 行追加
require File.join(File.dirname(__FILE__), 'boot');
Rails::Initializer.run { |config|
config.action_controller.session_store = :active_record_store
config.log_level = :debug
}一度、ブラウザから「/addressbook/list」にアクセスして、ログを見てみましょう。 そうすると、今度は前回に比べ、下記のようなログが同時に出力されています。
Rendering addressbook/component
Rendered addressbook/_column_headings (0.00200)
Rendered addressbook/_messages (0.00075)
Rendered addressbook/_person (0.00170)
Rendered addressbook/_person (0.00136)
(中略)
Rendered addressbook/_person (0.00137)
Rendered addressbook/_person (0.00155)
Rendered addressbook/_pagination_links (0.00035)これは、実際に HTML をレンダリングしたログです。 _ (アンダースコア) で始まるファイルは partial です。 Ajax Scaffold では、ページを 5 つの partial に分けてそれを呼び出してレンダリングしています。
ひとつひとつの partial はさほど遅くないのですが、 特に「_person」の数が多く、これによる速度低下が激しいようです。 なんとかこれを速くする方法はないでしょうか？
実は Rails の render 命令は結構遅く、 特にひとつの View の中で大量に呼び出すと、それだけでかなりのコストになってきます。 実際に app/views/addressbook/component.rhtml の 37 行目を下記のように展開してみましょう。
<%= render :partial => 'person', :collection => @people, :locals => { :hidden => false } %>
↓ 展開
<% hidden = false; @people.each do |person| %>
# app/views/addressbook/_person.rhtml の内容を直接書く
<% end %>これで Rails ログを見てみると 「Completed in 0.04629 (21 reqs/sec)」と、 元の 0.05558 秒に比べて 9 ミリ秒 (17%) も速くなっています。
httperf でも見てみましょう。
Request rate: 14.5 req/s (69.2 ms/req)
(中略)
Net I/O: 614.6 KB/s (5.0*10^6 bps)上記のように、やはり同じ程度速くなっています。 しかし、これではあまりに可読性が落ちてしまうので、 ERB の命令を使って partial ファイルをヘルパーメソッド化して使いましょう。
app/helpers/addressbook_helper.rb を下記のようにします。
module AddressbookHelper
extend ERB::DefMethod
def_erb_method('render_person(person, hidden)', "#{RAILS_ROOT}/app/views/addressbook/_person.rhtml")
endそして、先ほどの render 部分を、次は下記のように書き換えます。
<%= @people.collect{|person|render_person(person, false)}.join %>これで、可読性をあまり落とさず、なおかつ render 命令を省くことで高速化できます。 なおこの場合、変数スコープは元の View と同じになっていますので、気をつけてください。
さいごに
最近では twitter というサービスが Rails で作られていることが話題になっています。 twitter は高いトラフィックをさばいていることから、 「Rails でもこういうトラフィックに対応したサイトを構築できる」という評判が出始めており、 Rails でのサービス構築の大きな後押しになるのではないかと思っています。
今回の記事では、あまり個別の高速化には触れずに、多くのケースで手軽に使える手法や、パフォーマンスチェックの手法について書いてきました。 しかし、あまり高速化しすぎると、Rails の特徴である DRY や可読性の高いソースが失われてしまうので、そこはバランスが重要です。
著者について
masuidrive (Yuichiro MASUI) http://masuidrive.jp/ BLOG: masuidrive on rails
昔は PukiWiki のメンテナとして活動してましたが、今は 10 分 Rails ムービーの方が有名かも。
1998 年ぐらいから本格的に Ruby を使い始めてましたが、なかなか表だって使う機会がなかったのですが、 Rails がリリースされて以来、すっかり Rails 漬けの生活を送っています。 去年は Rails で Ruby な仕事しかせず、幸せな毎日を送ってました。
昨年まではフリーランスでしたが、2007 年 4 月から株式会社ワイズノット/OSRI で働いています。