rack-mini-profiler gemの使い方・指標の見方・問題箇所の絞り込み方法

Railsアプリケーション開発でパフォーマンスモニタリング、パフォーマンスチューニングやってますか??

New relicを始め、DatadogやSkylightなど便利なモニタリングサービスがたくさんあるので使ってはいるけれど、イマイチ使いこなせていない状況ではないでしょうか。

また、こういったサービスを利用はしているものの、機能を実装してリリースした後に表示画面が遅いとユーザから報告をもらって、やっとパフォーマンス問題に気がついて、New relicを開いて遅い箇所を確認するという対応が後手に回ってしまう状態が発生していないでしょうか。

日頃から rack-mini-profiler というGemを使って開発時にActiveRecordの発行されるSQLクエリやJSの初期表示の時間を確認する習慣をつけておくと、後からパフォーマンス問題が発生するケースを少なくすることができます。

しかし、rack-mini-profiler の画面は見づらくて、うまく問題箇所を特定できなかったり、使いこなすための工夫が足りなかったりするので、より活用できるようにするためにまずは今回画面の見方、問題箇所の絞り込み方法をまとめてみようと思います。

rack-mini-profilerの使用をおすすめするのはこんな人

  • Rails開発し始めたけどパフォーマンスチューニングを行っていない方
    • => 導入簡単なのでおすすめ!
  • プロジェクト開始時で、あまりモニタリングサービスに費用をかけられないプロジェクト
    • => rack-mini-profilerはプロダクションでも使えるように設計されているのでおすすめです!
  • リリースした後にSQLのチューニングが必要になるケースが多い方
    • => SQLが見れるのでおすすめ!
  • これからリリースする機能でパフォーマンス面で問題ないのか事前に確認したい方
    • => 動作確認しながら計測時間を表示できるのでおすすめ!

インストール方法

①Gemfileに以下のコードを追加して、bundle update を実行

gem 'rack-mini-profiler', require: false

②コマンドを実行して、initializersディレクトリに設定用ファイルを作る

bundle exec rails g rack_profiler:install

使い方

indexやshowの画面を開くと、画面左上に1リクエストで要したサーバ側処理合計時間(リクエストを受け付けてから返すまで)が表示されます。

f:id:moritamorie:20190608110632p:plain

登録ボタン(create)を押した場合などは、登録(POST)とリダイレクト後の詳細画面の表示(GET)の2リクエストになるので、これらの合計時間が表示され、クリックするとPOST、GETそれぞれのリクエスト毎の時間が表示されます。(直近のリクエストの方が上)

f:id:moritamorie:20190608110705p:plain

指標詳細の画面の見方・問題箇所の絞り込み方法

リクエスト毎の時間をクリックすると詳細が表示され、さらにshow time with childrenをクリックすると以下のような詳細が表示されます。 f:id:moritamorie:20190608110730p:plain

サーバサイド

まず、上部に表示されるのがサーバサイド側(Rails)のリクエスト全体の時間です。サーバサイド側の全体(この例だと38.4ms)の内どこが遅いのかを見極めます。

①アプリケーションの主な処理(コントローラ+ビュー)以外のパフォーマンス

with children(ms)カラムを見て、もし赤枠(リクエスト全体)と緑枠(コントローラ+ビュー)の箇所に大きな乖離があれば、実装したアプリケーションの箇所以外(Rack midlwareのどこか)にパフォーマンスに問題があるのだろうと考えます。

具体的には、puma等のアプリケーションサーバの設定に問題があるケースなどが該当します。 この場合、rack-mini-profilerだけでは詳細を追えないので、framegraph等ほかのを導入すると追えるようになります。

②アプリケーションの主な処理(コントローラ+ビュー)のパフォーマンス

duration(ms)カラムを見て、もし緑枠(コントローラ+ビュー)の内、layouts/application以外で時間がかかっていれば、実装したアプリケーションのどこかに問題があるのだろうと考えます。

ループの書き方や外部サービスへの接続等要因は様々ですが、アプリケーションの実装で改善できるケースで多いのはActiveRecordで実装したモデルの処理のSQLクエリが遅い問題が経験的に多いと感じています。 詳細の~~~% in sqlの箇所を見て、サーバサイド全体の内、何%がSQLクエリの実行時間に要しているのかを確認します。 f:id:moritamorie:20190608110755p:plain

もし、~~~% in sqlが高ければ、その上の各query timeの時間、遅いSQLクエリを確認し、SQLクエリの変更やキャッシングなどの対応を検討します。

③Assets precompileやWebpackerのbundleの設定等のパフォーマンス

duration(ms)カラムを見て、もし緑枠(コントローラ+ビュー)の内、layouts/applicationで時間がかかっていれば、実装したAssets pipelineの設定やWebpackerのbundle等views/layouts/application.rbで行っている処理のどこかに問題があるのだろうと考えます。(stylesheet_link_tagやjavascript_include_tag等があるため)

クライアントサイド

次に下部に表示されるのがクライアントサイド側のリクエスト全体の時間です。

④ネットワーク

黄枠の内、RequestとResponseの差分を見て、上部のサーバサイドの時間と比較して、大きな乖離があればネットワークの問題だろうと考えます。

この場合はあまりできることはないけど、もしResponseのデータサイズ大きすぎるみたいなときには、減らすような対応考えるくらいかなと思います。

⑤JSやCSS等のパフォーマンス

①〜④までのパフォーマンスに問題がなくそれでもパフォーマンスが悪い場合は、JSやCSS等のコンテンツデータサイズの問題、JSの実装などフロントエンドのどこかにが問題あるのだろうと考えます。

クライアントサイドの問題の場合、rack-mini-profilerよりchrome developer toolsのような他のツールを使った方が多くのことが分かるので、使うツールを切り替えて分析を進めていくことになります。

また、ツールを切り替える際は、rack-mini-profilerの値と chrome developer toolsは近い指標を参考に、頭の中で対応付けをするとすっと切り替えられます。 f:id:moritamorie:20190608110808p:plain

共有

問題箇所を特定できたら、詳細画面でshareを押すと綺麗なレポートが表示されるので、問題の共有に役に立つかもしれません。(使ったことないけど) f:id:moritamorie:20190608110828p:plain rack-mini-profilerの見方が分からないと辛いのですが、慣れると便利なので是非使ってみてください!