rack-lineprofを使ってRailsアプリを行単位でプロファイリングする手順

Ruby

rblineprofは計測対象のファイルに計測用のコードを埋め込むことで行単位のプロファイリングが行えるgemです。
rblineprofの利用方法については【Ruby】rblineprofで行単位の計測を行う方法で紹介していますのであわせてご覧になってください。

rblineprofにはRackミドルウェア版であるrack-lineprofというgemがあります。
RailsをはじめとしたRackアプリケーションの計測をしたい場合はrblineprofよりもrack-lineprofのほうが簡単に設定できます。
rack-lineprofではrblineprofのように計測用のコードを埋め込む必要はありません。

今回はrack-lineprofの利用方法について紹介します。

下準備: サンプルアプリケーションの作成

今回は例として、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

画面の確認

localhost:3000/studentsにアクセスして以下のような生徒一覧の画面が表示されればOKです。

rack-lineprofの導入手順

ここからはrack-lineprofの導入手順について紹介します。

rack-lineprofのインストール

Gemfileを修正し、rack-lineprofをインストールします。

Gemfile

group :development do
  gem 'rack-lineprof'
end
$ bundle

Rackミドルウェアに追加する

Rackミドルウェアにlineprofを追加します。

Railsアプリケーションの場合は以下のようになります。

config/environments/development.rb

Rails.application.configure do
  config.middleware.use Rack::Lineprof
end

ミドルウェアスタック一覧にuse Rack::Lineprofが表示されればOKです。

$ rails middleware | grep Lineprof

use Rack::Lineprof

rack-lineprofを利用した計測方法

rack-lineprofには2つの利用方法があります。

方法1: クエリパラメータを付与する方法

エンドポイントに?lineprof=[計測したいファイル名]というクエリパラメータを追加してアクセスをすると計測結果が確認できます。

たとえば、生徒の一覧画面(http://localhost:3000/students)を表示する際のビュー(app/views/students/index.html.erb)を計測する場合はhttp://localhost:3000/students?lineprof=app/views/students/index.html.erbとなります。
計測結果には『処理にかかった時間』と『呼び出し回数』が表示されます。処理の遅いところは文字がハイライトされます。

http://localhost:3000/students?lineprof=app/views/students/index.html.erbにアクセスした結果は以下の通りです。

もし、学生の一覧画面(http://localhost:3000/students)を表示する際のコントローラ(app/controllers/students_controller.rb)を計測する場合はhttp://localhost:3000/students?lineprof=students_controller.rbとなります。

たとえば以下のようにコントローラを修正します。

students_controller.rb

def index
  @students = Student.all

  sleep 1

  5.times do
    sleep 0.1
  end

  100.times do
    sleep 0.001
  end
end

コントローラ修正後、http://localhost:3000/students?lineprof=students_controller.rbにアクセスした結果は以下の通りです。

方法2: ミドルウェアのオプションを利用する方法

rack-lineprofに用意されているprofileオプションを利用することでクエリパラメータを省略できます。

たとえば、profileオプションを利用してapp/views/students/index.html.erbを計測する場合は以下のようにします。

config/environments/development.rb

Rails.application.configure do
  config.middleware.use Rack::Lineprof, profile: 'app/views/students/index.html.erb'
end

上記の設定後http://localhost:3000/studentsにアクセスすると、http://localhost:3000/students?lineprof=app/views/students/index.html.erbと同様の計測ができます。

まとめ

今回のまとめ
  • rack-lineprofはlineprofのRackミドルウェア版
  • rack-lineprofは行単位で処理時間と呼び出し回数を計測できる
  • エンドポイントに『?lineprof=[ファイル名]』を追加するか、profileオプションにファイル名を指定することで計測ができる

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

参考