Railsのパフォーマンス・チューニング

Tech

パフォーマンス改善

Rails アプリケーションのパフォーマンス改善というものに初めて取り組んだので、その記録を残します。
ほとんどがはじめて行ったものなので、かつ他の方がすでにまとめられているものではありますが何らかの参考になれば幸いです。

手順

基本的な手順は

  1. アプリケーションの速度を計測する
  2. 課題点を洗い出す
  3. 課題点を改善する

の繰り返しで少しずつ時間を削っていきました。

計測

今回ここが一番勉強になりましたが、アプリケーションの速度計測は様々な方法で図ることが可能です。

  • Chromeの開発者ツール
  • WEBサービス
  • データベースのログ
  • gem

今回は上記について記録を残していきます。

Chromeの開発者ツール

一番最初に行ったのはChromeの開発者ツールで「ページ全体の読み込み」について調べました。
主に参考にしたのは http://qiita.com/y_fujieda/items/a0a69151cf7307039f74 こちらのnetworkを参考にしました。


(※今回の改善点と画像の数値は関係ありません)

開発者ツールのnetworkタブを表示した状態で、読み込むとこのような形で表示がされます。
特に今回見ていたのは以下の部分です

■全体の読み込み


ページ下部に表示されています。全体の読み込み時間は一つの指標としました。

■TTFB(Time To First Byte)


networkタブで読み込んだときの一番最初にでてくるDocumentのTTFBをよく見ていました。
TTFBは「最初の1バイト」でリクエストを投げてから応答が返ってくる一番最初の部分です。
ここがほかのと比べて時間がかかっていたので、今回注視して見ていました。
Googleはこの部分が200ms程度までで返ってくることを推奨しているようです。

その他にも色々見ることができるので、活用されると良いと思います。

WEBサービス

■Google Page Speed Insights

URL: https://developers.google.com/speed/pagespeed/insights/


モバイルとPCでWEBサイトの課題を表示してくれます。
レンダリングブロックなどアプリケーションの部分から、サーバ設定の部分までアドバイスがあります。

■GTmetrix

URL: https://gtmetrix.com/


これもWEBページの評価をしてくれます。
開発者ツールの項目に近い感じです。

ログ

アプリケーションのログから主にデータベースのログを確認していました。

_id" = $1 AND ("records"."date" BETWEEN $2 AND $3) AND "records"."category_id" = $4  [["user_id", 1], ["date", Wed, 01 Feb 2017], ["date", Tue, 28 Feb 2017], ["category_id", 15]]
2017-02-22T10:23:45.892753+00:00 app[web.1]: D, [2017-02-22T19:23:45.892254 #4] DEBUG -- : [c1917d0b-0d2b-4005-86de-5a54690e8d92]    (1.3ms)  SELECT SUM("records"."amount") FROM "records" WHERE "records"."user_id" = $1 AND ("records"."date" BETWEEN $2 AND $3) AND "records"."category_id" = $4  [["user_id", 1], ["date", Wed, 01 Feb 2017], ["date", Tue, 28 Feb 2017], ["category_id", 16]]
2017-02-22T10:23:45.894353+00:00 app[web.1]: D, [2017-02-22T19:23:45.894036 #4] DEBUG -- : [c1917d0b-0d2b-4005-86de-5a54690e8d92]    (0.9ms)  SELECT SUM("records"."amount") FROM "records" WHERE "records"."user_id" = $1 AND ("records"."date" BETWEEN $2 AND $3) AND "records"."credit" = $4  [["user_id", 1], ["date", Wed, 01 Feb 2017], ["date", Tue, 28 Feb 2017], ["credit", true]]
2017-02-22T10:23:45.894666+00:00 app[web.1]: I, [2017-02-22T19:23:45.894607 #4]  INFO -- : [c1917d0b-0d2b-4005-86de-5a54690e8d92]   Rendered welcome/index.html.haml within layouts/application (38.3ms)
2017-02-22T10:23:45.896675+00:00 app[web.1]: I, [2017-02-22T19:23:45.896615 #4]  INFO -- : [c1917d0b-0d2b-4005-86de-5a54690e8d92] Completed 200 OK in 44ms (Views: 18.0ms | ActiveRecord: 23.4ms)

例えばこんなようなログから 「3桁msのもの」や「同じようなクエリ」を探してリストアップして言いました。

計測で使用したgem

今回新鮮だったのが、この計測系gemでした。
わたしは以下の2つを使いました。

■rack-mini-profiler

URL: https://github.com/MiniProfiler/rack-mini-profiler

発行されたSQLとその内容に加え、それぞれにかかっている時間が表示されます。


左上にこのような数値が表示されて、クリックすると


みたいな感じでログが表示されます。
すごくボトルネックが探しやすい。すごくたくさんのSQLが発行されていたり、著しく遅いところをさがしていきます。

■rack-lineprof

URL: https://github.com/kainosnoema/rack-lineprof

このgemは行単位で時間の計測が可能です。
画像を見てもらうのがはやいかとおもいますが、


※ ↑ https://github.com/kainosnoema/rack-lineprof の画像を転記

このような形で表示されます。一連の処理に対してどれくらいかかったかというのがログでも見れるのですが、
どの部分にどれくらいというところが、画像のような感じでわかりやすく見ることができるので、これを土台に話たりして、とてもはかどりました。

課題

上記のツールで計測をしていくといくつか課題が見えてきます。
私の場合見えてきた課題は以下のとおりでした。

  • イテレータの中でクエリが走っていて、無駄なやり取りが発生していた。
  • キャッシュして良さそうな部分にキャッシュがなかった
  • 画像の圧縮ができそう
  • ブラウザキャッシュの設定ができそう
  • データベースの取得に時間がかかっていた

あとは細かいコードの書き換えを少し行ったりしました。

改善

課題にあげたところを参考までにどんな感じの修正をしたか記録していきます。

データベースの取得に時間がかかっていた

時間がかかっているクエリを調べて、ひたすらINDEXを作成していく。

無駄クエリ

イテレータの中で取得していたクエリを、外で一括で取得してそれに対してイテレータをかけるようにした。
※record_ids は複数のrecord idの配列
※mongoidです

before.rb

record_ids.each do |record_id|
 record = Record.where(id: record_id, status: 'open').first
# recordに関する処理
end

after.rb

open_records = Record.in(id: record_ids).where(status: 'open')
open_records.each do |record|
# recordに関する処理
end

キャッシュして良さそうな部分にキャッシュがなかった

railsが持っているキャッシュの機能を使用してみました。
下記、が参考になるかと思います。

WEBサーバ

■画像の圧縮ができそう

nginxを使用しているので ngx_http_gzip_module を使用して、
まだ圧縮設定が入っていないものを追加しました。

■ブラウザキャッシュの設定ができそう

これもGoogle Page Speed Insight で指摘された事項で
特定のファイルに関してキャッシュさせても問題なさそうだったので
nginxに設定を追加しました。

最後に

今回走り書きですが、主に計測のところを重点的に記載しました。
一つの作業でXXmsが減っていく感覚は結構面白く、貴重な体験でした。