stackprof_demo

stackprofを使ったRailsパフォーマンスプロファイリングのデモアプリケーションです。 意図的にボトルネックを仕込んだAPIエンドポイントを計測・分析するために使用します。

---

セットアップ手順

# 依存gemのインストール
bundle install

# データベースのマイグレーション
bin/rails db:migrate

# シードデータの投入（User: 50件, Post: 500件, Comment: 2500件）
bin/rails db:seed

# サーバー起動
bin/rails server

---

エンドポイント

GET /api/v1/posts

全Postの一覧をJSON形式で返します。

レスポンス例:

[
  {
    "id": 1,
    "title": "Post Title 1",
    "slug": "post-a1b2c3d4e5f6g7h8",
    "keywords": ["ruby", "rails", "performance"],
    "author": "User 3",
    "comment_count": 5
  }
]

---

仕込んだボトルネックの説明（発表者向け）

app/controllers/api/v1/posts_controller.rb の index アクションに2つのボトルネックを仕込んでいます。

囮ボトルネック: N+1クエリ

posts = Post.all

result = posts.map do |post|
  author = post.user          # N+1: Postごとにユーザーをクエリ
  # ...
  comment_count: post.comments.count  # N+1: Postごとにコメント数をクエリ
end

• 問題: Post.all で500件取得後、各Postに対して post.user と post.comments.count がそれぞれクエリを発行する
• 発行クエリ数: 1 + 500 + 500 = 1001クエリ
• 解決策: Post.includes(:user, :comments) に変更するか、counter_cache を使用する
• 特徴: SQL発行ログを見れば一目瞭然で気づきやすい「囮」のボトルネック

本命ボトルネック: ループ内でのテキスト処理（extract_keywords）

posts.map do |post|
  keywords = extract_keywords(post.body)  # 500回呼ばれる
end

def extract_keywords(text)
  text.downcase
      .scan(/\b[a-z]{3,}\b/)     # 本文全体をスキャン
      .reject { |w| STOPWORDS.include?(w) }
      .tally
      .max_by(5) { |_, count| count }
      &.map(&:first) || []
end

• 問題: 500件のPost本文に対して毎回 scan → reject → tally → max_by という重いテキスト処理が走る
• 解決策: 本文からのキーワード抽出結果をDBに保存してキャッシュするか、バックグラウンドジョブで事前計算する
• 特徴: コードを一見すると普通のメソッド呼び出しに見える。N+1と違ってクエリログには現れないため、stackprofなどのプロファイラを使わないと発見しにくい点がポイント

---

stackprofを使った計測方法

1. スクリプトから直接計測する

script/profile.rb を作成して実行します:

# script/profile.rb
require_relative '../config/environment'

StackProf.run(mode: :cpu, out: 'tmp/stackprof.dump', interval: 100) do
  # プロファイルしたい処理
  posts = Post.all
  posts.map do |post|
    post.user
    post.slug.match(/\A[a-z0-9]+(?:-[a-z0-9]+)*\z/) ? true : false
    post.comments.count
  end
end

bin/rails runner script/profile.rb

2. ミドルウェアとして組み込む（リクエスト単位で計測）

config/initializers/stackprof.rb を作成:

# config/initializers/stackprof.rb
if Rails.env.development?
  require 'stackprof'
  Rails.application.middleware.use StackProf::Middleware,
    enabled: true,
    mode: :cpu,
    interval: 1000,
    save_every: 5
end

サーバー起動後にリクエストを送ると tmp/stackprof-*.dump が生成されます。

3. 結果の確認

# テキスト形式でフレームグラフを表示
stackprof tmp/stackprof.dump --text

# 上位メソッドを表示
stackprof tmp/stackprof.dump --text --limit 20

# 特定メソッドの詳細（ソースアノテーション付き）
stackprof tmp/stackprof.dump --method 'Api::V1::PostsController#index'

# フレームグラフをHTMLで出力
stackprof tmp/stackprof.dump --flamegraph > tmp/flamegraph.html
open tmp/flamegraph.html

4. rails runnerで直接計測する（推奨）

HTTPリクエスト経由ではなく、問題のある処理を抽出して直接実行することで、Puma・ミドルウェア・ネットワークI/Oを除外した正確な計測ができます。

# tmp/profile_run.rb
require 'stackprof'

profile = StackProf.run(mode: :wall, interval: 1000, raw: true) do
  100.times do
    posts = Post.all
    posts.map do |post|
      post.user
      post.slug.match(/\A[a-z0-9]+(?:-[a-z0-9]+)*\z/) ? true : false
      post.comments.count
    end
  end
end

StackProf::Report.new(profile).print_text(false, 30)

FileUtils.mkdir_p('tmp')
File.open('tmp/stackprof.dump', 'wb') { |f| Marshal.dump(profile, f) }

# サーバー起動不要・rails runner で直接実行
bin/rails runner tmp/profile_run.rb

---

データ構成

モデル	件数	備考
User	50件	name, email
Post	500件	slug は post-{hex8} 形式
Comment	2500件	各Postに5件、belongs_to :post/:user