3rdRailによるRailsプログラミング入門

第10回 3rdRailでプロファイリングしよう

富田 陽介
Banana Systems株式会社

2009/12/11

Railsアプリケーション開発を支援する統合開発環境「3rdRail」を使って、開発、デバッグ、プロファイリングの手法をマスターしよう(編集部)

 これまで9回に渡り、3rdRailを使って「つぶやき」アプリケーションを作成してきました。

 最終回となる今回は、3rdRailのプロファイリング機能を使って、「つぶやき」の実行性能を測定してみましょう。

 また、プロファイル結果からアプリケーションの改修ポイントを洗い出します。

 Railsアプリケーションでよく使われる外部ライブラリ「will_paginate」を利用して、機能を拡充する方法も紹介します。

アプリケーションのプロファイリング

 アプリケーションのプロファイリングとは、主にアプリケーションの実行性能を維持あるいは向上させるために実施する調査のことを指します。調査の対象は、認識されている課題や目標によってさまざまですが、一般的には、アプリケーション実行時のCPU、メモリの利用状況や、各々の処理の応答時間などが対象となります。

 プロファイリングによって、アプリケーション実行時の性能特性やボトルネックに見通しを立てることができたら、必要に応じて、開発済みのアプリケーションの改修を行っていきます。このような調査から改修の一連の流れをまとめてプロファイリングと呼ぶこともあります。

プロファイリングの準備――ダミーデータの作成

 これまで作成してきた「つぶやき」アプリケーションは、比較的シンプルなものですので、このままの状態でプロファイリングを行っても、あまり意味のある結果が得られません。

 そこで、今回は「大量の『ひとこと』レコードが作成されている場合、どのような処理がボトルネックになるか」という観点でプロファイリングしてみます。まず、Railsコンソールで以下のようなコードを実行し、1万件のレコードを作成してみましょう。

>> 10000.times { Hitokoto.create(:user_id => 1, :hitokoto => 'テスト') }
=> 10000

3rdRailのプロファイリング機能

 では、この状態で「ひとこと」一覧画面へアクセスされたときの実行性能をプロファイリングしてみます。

 「ひとこと」一覧画面のビューである[Railsエクスプローラー]−[tsubuyakiプロジェクト]−[コントローラー]−[Hitokotos]−[ビュー]−[index]までツリーを展開し、これを右クリックして[プロファイル]−[サーバーでプロファイル作成]をクリックします。

 プロファイル作成時にはR Optimizerという、3rdRail組み込みのプロファイル用パースペクティブが利用されます。上記の手順でプロファイル作成を始めると、下図のように、パースペクティブ切り替えの確認ダイアログが表示されますので、[はい]ボタンを押してパースペクティブを切り替えましょう。

画面1 R Optimizerに切り替える
R Optimizerに切り替える

 プロファイル・オプション指定画面が表示されます。ここでは、統計情報を可視/不可視化するためのフィルタ設定や、CPU利用状況記録の開始/終了オプションが指定できます。

 今回は、すぐにプロファイルを開始したいので、画面2のように3つのチェックボックスすべてにチェックを入れます。

画面2 プロファイル・オプション指定画面
プロファイル・オプション指定画面

 プロファイルが開始されると、R Optimizerパースペクティブに切り替わり、下図のような画面が表示されます。

画面3 R Optimizer画面構成(画像をクリックすると拡大します)
R Optimizer画面構成

 この画面の、主な構成要素は次のとおりです。

  • R Optimizer:プロファイルを行うプロジェクトツリーを概観できるビュー(左上)
  • コンソール:プロファイル実行状況のメッセージが表示されるコンソール(左下)
  • CPU/実行フロー:プロファイル結果が表示されるビュー(右上)
  • エディタ/ブラウザ:Webブラウザ画面やソースコードなどを確認するためのビュー(右下)

 この時点では、プロファイルは進行中ですので、右上のプロファイル結果のビューには、プロファイル終了ボタンが表示されています。

 プロファイル開始から数秒経つと、右下のブラウザビューに「ひとこと」一覧画面が表示され、先ほどテスト登録した1万件の「ひとこと」が表示されます。

 この表示を確認した(ブラウザビュー右側の読み込み中アイコンのアニメーションが終了した)ところで、右上のビューに表示されているプロファイル終了ボタンを押しましょう。プロファイル結果が集計され、各スレッドのCPU利用状況がグラフ表示されます。

画面4 CPUプロファイラー集計結果(画像をクリックすると拡大します)
CPUプロファイラー集計結果

 プロファイリングの結果、アプリケーションサーバを起動してから「ひとこと」一覧を表示し終わるまでに、10個のスレッドが起動され、すべてのスレッドで39328msのCPU時間が消費されていたことが分かりました。

 今回は、これらのスレッドの中から、もっともCPU利用率の高いスレッドを対象に、そのスレッドの内部でCPU利用率の高い処理を追いかけていきたいと思います。

 まず、表示されているスレッドの中から、もっともCPUビジー率の高いものを選択し、これをダブルクリックします。すると、[実行フロー]タブに切り替わり、このスレッドの処理実行フローがツリー表示されます。

 [実行フロー]タブでは、多くのCPU時間が費やされるメソッド呼び出しが、赤い時計のアイコン付きの「ホットスポット」という名前で表示されます。処理全体のボトルネックになっている部分を知るのであれば、このホットスポットに着目しながら実行フローを追いかけていくのが効率的でしょう。

 では、ホットスポットアイコンと利用されているCPU時間に着目しながら、[実行フロー]ツリーを展開していってみましょう。ツリーの階層が深くなると読みにくくなってきますので、タブ部分をダブルクリックして、このタブを全画面表示しておくと便利です。

 ここでは、ActionView::Rendarable#render以下でビューを作成する際に呼び出される数々のメソッドが、レコード数(あるいはその定数倍)回呼び出されており、CPU時間が大量に費やされていることが分かりました。

画面5 実行フローツリー全展開(画像をクリックすると拡大します)
実行フローツリー全展開

 なお、[実行フロー]タブでは、ツリー表示のほかに、メソッド呼び出しの経路情報をビジュアルに表示する集約表示や、メソッド実行時間や呼び出し回数を一覧できる表形式表示が利用できます。必要に応じて使い分けると良いでしょう。

画面6 集約表示(画像をクリックすると拡大します)
集約表示
画面7 表形式表示(画像をクリックすると拡大します)
表形式表示
 
1/2
next

Index
3rdRailでプロファイリングしよう
Page1
アプリケーションのプロファイリングとは
プロファイリングの準備――ダミーデータの作成
3rdRailのプロファイリング機能
  Page2
プロファイル結果を使用したアプリケーションの改修
Railsアプリケーションでの外部ライブラリの利用
will_paginateライブラリのインストール
will_paginateライブラリの利用

index 3rdRailによるRailsプログラミング入門

 Ruby/Rails関連記事
プログラミングは人生だ
まつもと ゆきひろのコーディング天国
 ときにプログラミングはスポーツであり、ときにプログラミングは創造である。楽しいプログラミングは人生をより実りあるものにしてくれる
生産性を向上させるRuby向け統合開発環境カタログ
Ruby on Rails 2.0も強力サポート
 生産性が高いと評判のプログラミング言語「Ruby」。統合開発環境を整えることで、さらに効率的なプログラミングが可能になる
かんたんAjax開発をするためのRailsの基礎知識
Ruby on RailsのRJSでかんたんAjax開発(前編)
 実はAjaxアプリケーション開発はあなたが思うよりも簡単です。まずはRuby on Railsの基礎知識から学びましょう
Praggerとnetpbmで作る画像→AA変換ツール
Rubyを使って何か面白いものを作ってみよう!
 一般的な画像をアスキーアートに変換するツールを作ってみる。さらに出力にバリエーションを持たせてみよう
コードリーディングを始めよう
Railsコードリーディング〜scaffoldのその先へ〜(1)
 優れたプログラマはコードを書くのと同じくらい、読みこなす。優れたコードを読むことで自身のスキルも上達するのだ
  Coding Edgeフォーラムフィード  2.01.00.91


Coding Edge フォーラム 新着記事
@ITメールマガジン 新着情報やスタッフのコラムがメールで届きます(無料)

注目のテーマ

>

Coding Edge 記事ランキング

本日 月間