【Rails 高速化】ペパボのフリマアプリ「kiteco（キテコ）」の API を高速化したときのことを詳しく書いてみた

最近、仕事でずっと iPhone アプリの API を Rails でつくっていて、ようやく 2014年2月6日（木）にやっとリリースできました。いろんなメディアに取り上げていただいて、ユーザー数も伸びてきて、嬉しい限りです。

• 古着フリマアプリ kiteco（キテコ）- 手数料無料キャンペーン中！

開発の過程のなかで、Ruby コミッターの @hsbt さんと、WEB+DB PRESS で連載記事持ってる @udzura さんにだいぶ「かわいがって」いただいたので、得られた知見をここに書くことで、少し還元したいと考えています。

で、手始めに Rails の高速化のハナシから。

セキュリティに配慮してコードやログは加工しておりますが、できるだけプロセスを再現するかたちで書いてみます。

もくじ

1. はじめに
2. 高速化に着手する前に
3. 現状分析
- ログから読み取れること
4. テーブルのインデックス
- 参考書籍
5. includes メソッド
- 結果
6. クエリ結果のキャッシュ
7. ビューのキャッシュを入れる前に
8. JSON のレンダリングの高速化
- 結果
9. キャッシュストアを何にするか
10. キャッシュストアとして Memcached を使う設定
11. Cache Digests（Russian Doll Caching）
- モデルのインスタンスをキャッシュのキーに指定すると捗る
- 子モデルが更新されたら、親モデルの updated_at も更新する
- キャッシュのネスト
- 結果
-（参考）ファイルキャッシュの結果
12. 使用しない middleware は削除する
- 結果
13. まとめ

1. はじめに

• API は Rails4 でつくっていて、JSON のレスポンスを Jbuilder で生成して返しています。
• JSON の生成を高速化する箇所以外は（API ではなく）ウェブページの高速化にも当てはまると思います。

2. 高速化に着手する前に

僕は基本的に機能の実装と高速化を分けて行うようにしています。そもそも高速化しなくても問題ない箇所もあるし、それ以上に僕自身が頭を切り換えないとすごく手が遅くなってしまうためです。

さらに、高速化をするときも、今回はここを速くしようという具合にターゲットを絞ってやっています。

3. 現状分析

そして、いつも最初の一歩は現状分析から。ターゲットに指定した箇所について

• いま現状どのくらいのレスポンス速度なのか？
• どのような SQL が投げられているか？そこでどのくらい時間がかかっているか？
• ビューのレンダリングに時間がどれくらいかかっているか？

等を見ています。プロファイリングツール使ってもいいし、New Relic もいいし、アプリケーションのログ見てもよいと思います。アプリケーションログの場合は

config.log_level = :debug

となっているか確認しておきます。

ログから読み取れること

今回はアプリケーションのログを見ながらチューニングしました。適当に加工したものを載せておきます（伝わりやすいように、例として商品一覧 API っぽいものを書きましたが、このとき実際にチューニングを行ったのは、べつの重い処理です）

Started GET "/api/products.json" for xxx.xxx.xxx.xxx at 2014-01-07 21:32:06 +0900
Processing by Api::ProductsController#index as JSON
  Parameters: ...
  ...
  Product Load (76.7ms)  SELECT `products`.* FROM `products` WHERE `products`.`user_id` = 9 ORDER BY created_at DESC
  ...
  Rendered api/users/_user.json.jbuilder (12.5ms)
  ...
  Rendered api/products/_product.json.jbuilder (1052.1ms)
  ProductImage Load (43.6ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 58
  ProductImage Load (77.1ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 108
  ProductImage Load (72.3ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 77
  Rendered api/products/index.json.jbuilder (2620.9ms)
Completed 200 OK in 2844ms (Views: 1034.1ms | ActiveRecord: 1606.6ms)

まず最初に見るべきは、トータルのレスポンス速度。2844ms かかっています。だいぶ遅いです。これを速くするのが目的です。

次に遅い原因をログから探ります。だいたい典型的なパターンは限られているので。順に書いていきます。

4. テーブルのインデックス

ログ中に SELECT 文を投げている箇所があって、そこに時間がかかっていたら、テーブルにインデックスが適切に張られていないことを疑ってください。

Product Load (76.7ms)  SELECT `products`.* FROM `products` WHERE `products`.`user_id` = 9 ORDER BY created_at DESC

微妙な速度ですけど、今回はきちんとインデックス張っていました。

なおインデックスが適切に使われているかどうかは、僕は Pry でデバッグして、explain メソッドで見るようにしています。MySQL にコンソール接続して、EXPLAIN を使っても良いと思います。

• Active Record Query Interface — Ruby on Rails Guides

User.where(id: 1).joins(:posts).explain

余談ですが、インデックスが使われていないときに MySQL のスローログに書き込むようにしておくと、高速化のターゲットを決めるときに役立ちますね。

参考書籍

EXPLAIN の結果を見ても、どこがどう悪いのか分からないという方は、鍵本（下記）の該当箇所を読むと良いと思います。

エキスパートのためのMySQL[運用+管理]トラブルシューティングガイド

インデックスについてよく分からないのであれば、オライリーの下記の本が詳しいです。

実践ハイパフォーマンスMySQL 第3版

5. includes メソッド

下記のように、同じリソースに対して SELECT 文が繰り返し実行されていたら includes メソッドを使うべきか検討してください。

ProductImage Load (43.6ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 58
ProductImage Load (77.1ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 108
ProductImage Load (72.3ms)  SELECT `product_images`.* FROM `product_images` WHERE `product_images`.`product_id` = 77
...

• Active Record Query Interface — Ruby on Rails Guides

clients = Client.includes(:address).limit(10)
 
clients.each do |client|
  puts client.address.postcode
end

下記のような SQL が実行されて、関連リソースを一括で取得できます。

SELECT * FROM clients LIMIT 10
SELECT addresses.* FROM addresses
  WHERE (addresses.client_id IN (1,2,3,4,5,6,7,8,9,10))

結果

今回、適切に includes で取得していない箇所があって、そこを変更したらかなり変化が見られました。

# Before
Completed 200 OK in 2844ms (Views: 1034.1ms | ActiveRecord: 1606.6ms)

# After
Completed 200 OK in 1072ms (Views: 851.2ms | ActiveRecord: 215.1ms)

6. クエリ結果のキャッシュ

クエリの結果をキャッシュして、次回の問合せは、そこから返すようにすることができます。しかし、kiteco では DB の問合せよりもむしろビューの生成（= JSON の生成）に多くの時間を要していたので、クエリ結果のキャッシュよりもビューのキャッシュが有効だと考え、そちらを行うことにしました。

択一的なことではなく、両者を組み合わせることもできますが、複雑になるので、それはさらなる高速化が必要になったときに限定して使おうと考えました。

7. ビューのキャッシュを入れる前に

ログ中のビューのレンダリング時間には、DB の問合せ時間も含まれていますが、インデックスや includes メソッドを使って DB の問合せを改善したにも関わらず、まだ時間がかかっていたら、ビューのレンダリング自体を速くする必要があります。

また、ビューのレンダリング結果をキャッシュするのも、とても効果が期待できます。

ただし、キャッシュを入れると、キャッシュが効いていない状態のパフォーマンスのチューニングがやりにくくなるので、先にキャッシュ以外の対策をしておいて、キャッシュは最後に入れたほうが良いです。

8. JSON のレンダリングの高速化

前述のとおり、JSON のレンダリングは Rails4 標準の Jbuilder を使っています。

• rails/jbuilder

公式ドキュメントに書いているとおり、バックエンドに JSON gem ではなく Yajl JSON を使うようにすると高速化が期待できます。

# Gemfile
gem 'yajl-ruby'

# config/initializers/multi_json.rb
require 'multi_json'
MultiJson.use :yajl 

結果

Before と After それぞれ 5回ずつくらい計測しましたが、結果はだいたい同じでした。15% くらい速くなりました。

# Before
Completed 200 OK in 1072ms (Views: 851.2ms | ActiveRecord: 215.1ms)

# After
Completed 200 OK in 851ms (Views: 666.8ms | ActiveRecord: 180.9ms)

9. キャッシュストアを何にするか

そして、ビューのキャッシュ。大抵の場合、大きな効果が期待できます。

まずキャッシュストアとして、Memcached を使うかファイルキャッシュを使うかを検討しました。

アプリケーションサーバがひとつであれば、ファイルキャッシュの方が Memcached よりも速度が出るかもしれません。Memcached を入れているサーバがアプリケーションサーバと別であれば尚更です（Memcached の場合、Memcached のネットワークの通信コストがかかるため）

一方で、アプリケーションサーバが複数の場合、Memcached だと複数のサーバから共通のキャッシュを使うことができるので、ファイルキャッシュの場合に較べてキャッシュヒット率が高くなります。このあたり、下記が詳しいです。

WEB+DB PRESS Vol.70

今回は、アプリケーションサーバを複数にする予定だったので、基本的に Memcached を選ぶようにして、ファイルキャッシュの方が断然速いのであれば（キャッシュヒット率は下がるけれども）ファイルキャッシュにしようかなと考えていました。

なお、Memcached を置くサーバは、アプリケーションサーバとは別にしています。Memcached のネットワークの通信コストは計測してみないと読めないところがあります。

10. キャッシュストアとして Memcached を使う設定

キャッシュストアとして Memcached を使う場合、Memcached クライアントには Dalli を使うのが定番だと思います。設定の仕方は公式ドキュメントに載っています。

• mperham/dalli

# Gemfile
gem 'dalli'

# config/environments/production.rb
config.cache_store = :dalli_store, 'memcached001.example.com',
  { namespace: 'my-app', compress: true } 

大事なことは compress: true で圧縮すること。大抵の場合、圧縮した方がレスポンス速いと思います。

11. Cache Digests（Russian Doll Caching）

Cache Digests（Russian Doll Caching）の使い方は、下記の RailsCasts の記事が詳しいです。また、Jbuilder での使い方も、Jbuilder の公式ドキュメントに載っています。

• #387 Cache Digests - RailsCasts
• ActionView::Helpers::CacheHelper
• rails/cache_digests
• rails/jbuilder

なので重要な点を補足するに留めます。

モデルのインスタンスをキャッシュのキーに指定すると捗る

json.cache! product, expires_in: 1.hour do
  json.extract!(product,
    :id,
    :name,
    :description,
    :created_at,
    :updated_at,
  )
end

次のようなキャッシュキーが自動生成されます。

# model_name/model_id-model_updated_at/hash_digest
product/74-20131207100840000000000/ed31faf7b577886dc62312707a604216

キーの中にモデルの updated_at を含むので、モデルが更新されたら、キャッシュも新しくつくり直されて便利です。

子モデルが更新されたら、親モデルの updated_at も更新する

下記のようにすると、子モデルが更新されたときに親モデルの updated_at も更新されるので「子モデルを更新したのにレスポンスに反映されない」ということを防止できます。

# app/models/product_image.rb
class ProductImage < ActiveRecord::Base
  belongs_to :product, touch: true
  #...

キャッシュのネスト

パーシャルにしたビューもキャッシュできます。また、キャッシュのネストも可能です。ただし、キャッシュをつくることもコストがかかるので、無駄なキャッシュができないようにする必要があります。

例えば商品一覧を返す API があって、商品ひとつをパーシャルのビューにしているとします。

この場合、商品一覧のビュー全体をキャッシュして、さらに個々の商品ビューをキャッシュすることも可能ですが、商品が登録されたときにすぐにそれを反映させたいと思ったら、商品一覧のビューキャッシュは頻繁に破棄しなければならなくなり、キャッシュ生成が無駄になります。

そこで、そのような場合は、商品個別のパーシャルビューのみをキャッシュにするのが良いと思います。

結果

ビューをキャッシュした結果。やっとマトモな数値が出るようになりました。

# Before
Completed 200 OK in 851ms (Views: 666.8ms | ActiveRecord: 180.9ms)

# After: 少しバラつきがあった
Completed 200 OK in 81ms (Views: 70.7ms | ActiveRecord: 7.1ms)
Completed 200 OK in 547ms (Views: 367.1ms | ActiveRecord: 19.0ms)
Completed 200 OK in 431ms (Views: 381.2ms | ActiveRecord: 46.6ms)
Completed 200 OK in 125ms (Views: 114.3ms | ActiveRecord: 7.1ms)

（参考）ファイルキャッシュの結果

ファイルキャッシュにすると通信が生じない分、速かったです。

が、前述のとおり、複数のアプリケーションサーバを使うので、キャッシュヒット率を考慮して Memcached を使うことにしました。

Completed 200 OK in 58ms (Views: 49.6ms | ActiveRecord: 4.9ms)
Completed 200 OK in 423ms (Views: 359.8ms | ActiveRecord: 57.7ms)
Completed 200 OK in 124ms (Views: 114.8ms | ActiveRecord: 5.7ms)
Completed 200 OK in 58ms (Views: 49.7ms | ActiveRecord: 4.9ms)

12. 使用しない middleware は削除する

下記を参考にしながら、使用していない middleware を削除しました。

• Rails on Rack — Ruby on Rails Guides
• http://blog.mirakui.com/entry/2012/04/03/slow-middleware
• rails-api/rails-api
• #348 The Rails API Gem - RailsCasts

# config/application.rb
config.middleware.delete "Rack::Sendfile"
# ...

結果

あまりがっつり消していないので、有意な差は見られませんでした。

13. まとめ

以上のようなパフォーマンスのチューニングを各所に施して、現在、本番環境で 200ms 〜 300ms で返しています。

今回、実際に行ったパフォーマンスのチューニングの流れをざっと書きましたが、個々のことについて、もう少し掘り下げたい点や、今回取り上げたこと以外でまだまだ書きたいことがあるので、それらについては追々書いていこうと思います。

長文にお付き合いいただきありがとうございました。今後ともこのブログと kiteco（キテコ）を何卒よろしくお願いします。

ペパボのフリマアプリ「kiteco」（キテコ）

まだまだ荒削りなところもありますが、なかなか良いアプリだと思うので、ぜひ触ってみてください。

• 古着フリマアプリ kiteco（キテコ）- 手数料無料キャンペーン中！

そして感想を App Store のレビューに書いていただけたら、泣いて喜びます！

招待キャンペーン中！！

大事なことを書き忘れてました！！

いま招待キャンペーン中なのでユーザー登録時に招待コード「VF69ztrc」を入れると、あなたも私も 300 ポイントもらえます！

キャンペーンもうすぐ終わるかもしれないのでお早めに！！

2014年3月4日 追記 - 一緒に働いてくれる仲間を募集中！！

一緒に働いてくれる仲間を募集しています！！

• 古着フリマアプリ「Kiteco」メール返信スタッフ（アルバイト） | カスタマーサービス | 職種詳細 | 株式会社paperboy&co.
• EC新規サービスRuby on Railsエンジニア　（正社員） | エンジニア | 職種詳細 | 株式会社paperboy&co.
• 職種一覧 | 株式会社paperboy&co.

関連エントリー

• Rails でつくる API のテストの書き方（RSpec + FactoryGirl）