console.blog(self);

技術、読んだ本、いろいろ。

1年間で取り組んだProttのパフォーマンスチューニング

f:id:sadah:20151225074123p:plain

Goodpatch CTOの id:sadah です。

これはGoodpatch Advent Calendar 2015の25日目のエントリです。

Prottというサービスではパフォーマンスチューニングのために、Railsアプリケーション/フロントエンドの改善、ミドルウェアのバージョンアップ、SPDYやHTTP/2の導入、オンプレミス環境からAWSへの移行などを行ってきました。 今回はその取り組みの一部をご紹介します。

Slides

10月にGoodpatch Engineer Meetupというイベントをやって、Prottのパフォーマンスチューニングについて話した。

イベントの内容はこちらにまとまっている。

僕のスライドはこんな感じ。

"Make the Prott Faster"ってタイトルにしたけど、theはいらないよってあとから教えてもらった。cute misstakeって言われた。感覚がわからない。

パフォーマンスチューニングで取り組んだこと

Goodpatchには2015年1月に入社して、そこからいろいろなことに取り組んできた。10月の時点で2倍くらいは速くなった。いまはさらに速くなっている。でもまだまだ改善できるので、来年もパフォーマンスチューニングに取り組んでいく。 2015年10月に計測したときはこんな感じだった。

f:id:sadah:20151225074418j:plain

f:id:sadah:20151225074437j:plain

イベントのあった10月までに、こんなことをやってきた。

  • Infrastructure
    • RubyRailsのバージョンアップ
    • Nginxのチューニング
    • SPDYの導入(HAProxyからNginxへの移行)
  • Rails Application
    • N+1問題の解消(道半ば)
    • Slow Queryの解消
    • メモ化
    • Cache(Russian Doll Caching)
  • Frontend
    • AngularJSバージョンアップ
    • $watchの削減

11月から12月にかけて大きな変更をした。

  • Infrastructure
    • オンプレミス環境からAWSへの移行(計画停止しての移行)
    • MongoDB / Nginx など各種ミドルウェアのバージョンアップ
    • HTTP/2の導入

僕は主にRails側の対応を行い、フロントエンドやインフラの対応はチームメンバーがやってくれた。SPDY導入や、$watchの削減についてはこちらの資料にまとまっている。

Prottの抱えていた課題

プロジェクト一覧の画面が遅い。

f:id:sadah:20151225074858j:plain

スクリーン一覧の画面が遅い。

f:id:sadah:20151225074920j:plain

このよく使うページを中心に改善していった。

パフォーマンスチューニングの指針

よく言われていることを、ちゃんと実践するようにする。

f:id:sadah:20151225074958j:plain

  • 推測するな、計測せよ。
  • 時期尚早な最適化は諸悪の根源だ。
  • 1度に修正するのは1箇所のみ。

このあたりに詳しく書いてある。

ただこのときは、時期尚早どころか
もっと早く対応するべきだった…。

SPDY

f:id:sadah:20151225075102j:plain

SPDYの導入にあたってはこんなことをした(いまはHTTP/2を使っているけど)。

  • spdycatで接続確認する
  • h2loadで計測する

このあたりを参考にさせていただいた。

spdycatを使うと、こんなふうに接続確認ができる。

% spdycat https://prottapp.com/ -v -n
[  0.379] NPN select next protocol: the remote server offers:
          * spdy/3.1
          * http/1.1
          NPN selected the protocol: spdy/3.1
[  0.386] Handshake complete
[  0.387] recv SETTINGS frame <version=3, flags=1, length=20>
          (niv=2)
          [4(0):100]
          [7(0):2147483647]
[  0.387] recv WINDOW_UPDATE frame <version=3, flags=0, length=8>
          (stream_id=0, delta_window_size=2147418111)
[  0.387] send SYN_STREAM frame <version=3, flags=1, length=215>
          (stream_id=1, assoc_stream_id=0, pri=3)
          :host: prottapp.com
          :method: GET
          :path: /
          :scheme: https
          :version: HTTP/1.1
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: spdylay/1.3.2

h2loadで負荷を掛けられる。cでクライアント数、nで回数を指定できる。出力はこんな感じ。

% h2load -c 1 -n 1 https://prottapp.com
starting benchmark...
spawning thread #0: 1 concurrent clients, 1 total requests
Protocol: TLSv1.2
Cipher: ECDHE-RSA-AES256-GCM-SHA384
Server Temp Key: ECDH P-256 256 bits
progress: 100% done

finished in 117.42ms, 8.51665 req/s, 1.29MB/s
requests: 1 total, 1 started, 1 done, 1 succeeded, 0 failed, 0 errored, 0 timeout
status codes: 1 2xx, 0 3xx, 0 4xx, 0 5xx
traffic: 158829 bytes total, 375 bytes headers, 158106 bytes data
                     min         max         mean         sd        +/- sd
time for request:    78.29ms     78.29ms     78.29ms         0us   100.00%
time for connect:    38.74ms     38.74ms     38.74ms         0us   100.00%
time to 1st byte:    90.82ms     90.82ms     90.82ms         0us   100.00%

開発環境でApache Benchとh2loadで測定したら、レスポンスタイムが10%程度改善した。あんまり厳密は計測していなくて、遅くなったりしないことだけ確認した。

MongoDBのSlowQuery

mongoidのexplainメソッドだとほしい情報が取れなかった(executionStatsを渡した結果がほしかった)ので、monogo shellでexplainした。

> db.xxxx.find({ deleted_at: null, screen_id: ObjectId('XXXXXXXXXXXX')}).sort({_id:1}).explain('executionStats')

{ "queryPlanner" : { ...
  "winningPlan" : {
          "stage" : "FETCH", ...
  },},
"executionStats" : { ...
  "executionTimeMillis" : 111,
  "totalKeysExamined" : 55555,
  "totalDocsExamined" : 55555,
} }

winningPlanの内容を確認すると、stageがFETCHになってはいるけど、sortが効いてるだけっぽい。 検索したindexの数と検索したdocumentの数が同一になってしまっているので、indexは効いていなかった。

indexを追加することで改善した。

> db.xxxx.find({ deleted_at: null, screen_id: ObjectId('XXXXXXXXXXXX')}).sort({_id:1}).explain('executionStats')

{ "queryPlanner" : { ...
  "winningPlan" : {
          "stage" : "FETCH", ...
  },},
"executionStats" : { ...
  "executionTimeMillis" : 2,
  "totalKeysExamined" : 1,
  "totalDocsExamined" : 1,
} }

Rails Application

計測するためにつかったツールとか。

使わなかったツールとか。

stackprofとstackprof-webnav

stackprof

stackprofはRubyのプロファイラ。作者はGitHubのAman Gupta(@tmm1)さん。RubyKaigi2014 3日目の基調講演のスピーカーでセッション終了後の拍手がものすごかった。

RubyKaigi2014でのスライドはこちら。

config.ruをこんな感じにするとRAILS_ROOT/tmpにダンプができる。

require ::File.expand_path('../config/environment',  __FILE__)

use StackProf::Middleware, enabled:    true,
                           mode:       :cpu,
                           raw:        true,
                           interval:   1000,
                           save_every: 5
run Rails.application

stackprofで解析するとこんな感じ。

$ stackprof tmp/stackprof-cpu-*.dump --text --limit 1
==================================
  Mode: cpu(1000)
  Samples: 780 (5.45% miss rate)
  GC: 88 (11.28%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
        33   (4.2%)          27   (3.5%)     Psych::ScalarScanner#tokenize

stackprof-webnav

stackprofの出力をWebで確認できる。ドリルダウンとかできて便利。

$ gem install stackprof-webnav
$ stackprof-webnav -f tmp/stackprof-cpu-53222-1444801808.dump

こんな感じで表示される。

f:id:sadah:20151225075311j:plain

こんな感じでドリルダウンできる。

f:id:sadah:20151225075355j:plain

Frontend

画像の Layout / Paint が重かった。Chrome DevTools の timeline を使って計測。画像を縮小して表示している部分が重かった。

f:id:sadah:20151225075536j:plain

DevToolsのUI、カオス。そしてまたいろいろ変わっているんだろうな。Renderingタブにいろいろ設定がある。

f:id:sadah:20151225075606j:plain

いろいろ有効にすると、LayerやFPSを確認できる。

f:id:sadah:20151225075634j:plain

改善するために、試しにtransform使ってGPU使ってみた(ちょっと試してみたかった)。速くなったけど根本的な解決じゃないではないので、Nginx(ngx_small_light)で縮小したサイズの画像を生成することにした。

画像への初回リクエスト時に指定されたサイズの画像を生成しキャッシュするようにした。適切なサイズの画像を使うことで、ブラウザがかなりスムーズに動くようになった。

あとはこんなツールを使ったり、細かいJSの改善をやり続けていった。

AWS

これらの取り組みのあと、インフラをオンプレミス環境からAWSに移行した。地理的には東京からオレゴンに移行した。Prottをグローバルに使われるサービスにしていくために必要なことだった。とても難しい決断だった。

ヨーロッパでProttが遅いという報告を以前から受けていて、10月から11月にかけてベルリンに行って調査した。アメリカにサーバを置くと、かなり改善することがわかった。もちろん日本からのアクセスのレイテンシーは大きくなる。

そのため、AWS化にともないNginx / MongoDBなど主要なミドルウェアのバージョンアップを行い、さらに使うインスタンスのスペックを上げた。

その結果、日本からのアクセスのレイテンシーは増えたけどパフォーマンスは上がり、これまでよりも速くなった。ヨーロッパやアメリカでは格段に速くなった。

事前にしっかり準備することで、大きな問題も起こさずに移行を完了できた。海外のメンバーから、Prottが速くなった!というメッセージをたくさんもらえて、とてもうれしかった。

まとめ

フロントエンドの改善は id:yoshiko_pg が、がつがつ進めてくれた。インフラ周りのほとんどの作業を id:urapico が担当してくれた。他のメンバーもいろいろな改善をやってくれた。

経営的判断として、パフォーマンスチューニングを最優先課題として取り組んだ。チーム全体でパフォーマンスチューニングに
取り組む期間を作れたことはとてもよかった。

ただ、まだまだボトルネックになっているところは多いし、もっと速くしていかなくてはならない。例えばキャッシュで速くなっても初回アクセスの重さが解消できていないし、当たり前の設定を入れた感じなので
もっと攻めたい。

Goodpatchは「ハートを揺さぶるデザインで世界を前進させる」というビジョンを掲げている。サービスが遅いと
ハートを揺さぶれない。パフォーマンスは
UXに直結する。

Prottをもっとよいサービスにするために、来年もいろいろなことに取り組んでいく。

We are hiring!!

Prottを改善していくエンジニアを募集しています!興味があれば気軽に連絡ください。