読者です 読者をやめる 読者になる 読者になる

開発環境のパフォーマンスチューニング

こんにちは。技術部の吉川です。

クックパッドでは、ユーザーが快適にサービスを利用できるように本番環境でのパフォーマンスを向上させるための様々な工夫がなされています。

ところでパフォーマンスを気にするのは本番環境だけで良いのでしょうか? 開発環境に目を向けると、そこにもユーザーがいます。開発者です。開発環境のパフォーマンスが向上することで、開発者が快適にサービスを開発できるようになります。 今回はそういった開発環境でのパフォーマンス向上のための取り組みについてご紹介します。

※ なお先日 Ruby2.2化されました が、今回紹介するものはそれ以前に実施されたため、Ruby2.2で同じ結果になるとは限りません。

状況

今回対象とするのはcookpad.comのアプリケーションです。 近年はMicroservices化を進めていますが、それでも本体のレシピサービスのアプリケーションは依然として非常に巨大なRailsアプリケーション です。

まずは施策無しの状態でのパフォーマンスがどの程度なのかを調べてみました。

rails consoleやrspecを手元で実行する際に、起動・初期化にかかる時間が20秒程度。 rails server(実際にはforemanを使って関連するミドルウェアも同時起動したりしています)で起動する時間が30秒程度でした。

ページ表示時間は、当然箇所によって異なりますが、トップページやレシピ詳細ページを起動後初回表示すると、JSなど含めて全てのロードが終わるまで30秒程度かかっていました。 なおこの数値は初回表示の場合で、二回目以降の表示ではキャッシュが効いて30秒だったものが12秒程度になります。

起動処理

まずは起動時間の20秒に着目しました。何に時間がかかっているのか? おおよそ8秒程度が Bundler.requireしている時間でした。また、Railsの初期化処理にも8秒程度かかっていました。 Railsの初期化処理をもっと細かく見ていくと、ほとんど(7秒程度)はbundleしているGemがhookしている初期化処理に費やされていました。 つまり75%程度がGemのロードに使われていました。

何かロードに時間がかかるGemでもあるのかというとそうではなく、単純に量が多かったのです。 約300ものGemがロードされていました。まさに塵が積もった状態です。

ただ起動についてはRailsが提供しているSpringを使えば、一度起動してしまえば次回以降は時間がかからなくなります。 Springを使うことで、ほとんど手をかけずに20秒かかっていた起動が3秒程度になりました。

とはいえクックパッドのように古くからあるアプリケーションの場合、そもそもRailsのアップデートをしていなければ導入できません。 こまめにアップデートに追随しておくことでこういった恩恵を得ることもできます。

クエリ発行数の削減

さて次はページ表示です。初回表示と二回目以降で大きく違うのはDBとSolrへのクエリがmemcachedなどにキャッシュされるためです。つまりIOが大きく寄与していることになります。 実際に調べてみると、キャッシュが全く無い場合、あるページではDBとSolrへのクエリがあわせて190本程度発行されていました。

N+1クエリが発生していたというわけではありません。純粋に量が多いのです。 レシピを表示するのにも、例えば関連キーワードでのレシピ検索結果など、様々な関連情報をロードするためです。

こういった情報は本番環境ではキャッシュを活用しています。誰かのアクセスでロードされればキャッシュされるため、ほぼ常にキャッシュされているような情報です。 しかし開発環境だとそもそもキャッシュにのる機会が少ないためヒット率が悪い。

これは性質上避けられないので初回時のキャッシュヒット率は諦め、開発環境であることを逆手にとって、もっと幅広くキャッシュすることにしました。 開発時に発行するクエリを全てキャッシュするのです。

開発時の動作確認、例えばviewの調整などのために何度も表示するような場合、期待するクエリ結果が変わることはほとんどありません。 更新系のクエリが発行された場合にだけキャッシュを破棄し、それ以外は、一度発行されたクエリは結果を常にキャッシュすることで大幅にIOを軽減させることができます。

DBへのクエリをキャッシュするために、クックパッドの開発環境では弊社森田が開発したreuse_query_resultsというGemが使われています。

またGemにはなっていませんが、Solr(Sunspot)クエリも同様にキャッシュされるようになっています。

もちろんデメリットもあります。手元のアプリケーションからの更新系クエリしか検知しないので、例えばDBスキーマを頻繁に変更しながら開発する場合はむしろ邪魔になります。 そこで起動時に環境変数でオンオフできるようになっています。

これらにより主なIOをほぼ無くすことができました。12秒だった表示時間は10秒を切るようになります。 それでも10秒・・・道は長そうです。

例えばGCを止める

IOが無いのにどこに時間がかかっているんだ?ということで細かく見ていきます。

表示にかかる時間のうち、60〜70%程度がコントローラーの処理が終わった後のテンプレートエンジンがviewを構築する時間に費やされていました。

テンプレートエンジンが遅いのか?と思いきや、簡単なペライチのviewだと300ms程度で終わるので、もう少し細かく見ていくことにしました。 するとどうやらpartial viewが多いほど遅くなっていることがわかりました。10秒かかるページでは、ループによって複数回renderされる数も含めると70以上ものpartial viewのrender処理が走っていたのです。

さらにその内訳を見ていくと、ほとんどは1ms以内からちょっと大きめでも10ms程度で終わっているものの、しかし一部のviewが300〜400msと非常に時間がかかっていることがわかりました。 これはただ重い処理をしている箇所があるだけか?と思いきや・・・計測する度に時間がかかる箇所が変動します。 さらに計測範囲を細かくして見ていくと、あるviewのrender処理が終わったあと次のviewのrender処理が始まるまでの間に時間がかかっていることがわかりました。 コードの実行の合間に実行されるものといえば・・・GCですね。そこでためしにGCを止めてみることにしました。

クックパッドの本番環境ではかなり前からGCを止めて運用しています。 止めるといっても完全に止めるのではなく、リクエスト処理開始時にGCを止め、レスポンス後にGCを再度有効にすることで、リクエスト処理中にGCが発生しないようにするOut-of-Band GCの手法です。 OoBGCにすることで、renderに300〜400msかかるようなviewがなくなりました。 これによって表示時間は10秒から7秒程度になりました。

棚卸しする

ここまで高速化するための施策について書いてきましたが、視点を変えて現状を維持するための施策もご紹介します。

機能はどんどん増えていくものですが、一方で既に必要ないものも存在するはずです。 必要ない処理やコードはどんどん整理していくことで、オーバーヘッドの増加を食い止めることもできるはずです。 その機能でしか使っていないGemがあってそれも消せるのであれば、その分Gemのロード時間にも寄与します。

しかし必要ないもの、というのは裏を返せば開発が終わっているということでもあり、開発者が既に別プロジェクトに移っていたり、 既にチームが無かったりして、どれが必要ないのかといったコンテキストが既にわからなくなっているケースもあります。 掃除と同じでこまめにやる工夫が必要です。

その工夫の1つとして、プロトタイピング開発に使われているChankoのunitの棚卸しを行っています。 unitとは、Chankoにおける機能をひとかたまりにした単位で、assetやテストも含み、unit単位で公開範囲の切り替えを行うものです。 全体公開せずにベータ版のまま開発終了してしまったが、コードがそのままになっているものや、期間限定公開で公開終了したのに残っているというものを棚卸しするのが目的です。

unitごとにコミットしたauthorを抽出し、1ヶ月に一度 GitHub上でissueが作られmentionするようにしています。 その際アプリケーション内でinvokeされているかどうかも合わせて出力しています。既に機能を落としたが残りっぱなしになっているものなどがわかりやすくなります。 また一時的に下げているだけだったり、期間限定機能だったりする場合は、設定でこのアラートを抑制することもできます。 例えば3ヶ月限定公開なら、3ヶ月後からアラートが飛ぶようにできます。

まとめ

開発環境高速化のための取り組みについてご紹介しました。いかがでしたでしょうか。

本番環境と比較すると、開発環境のパフォーマンスは実ユーザーが使うものではないため軽視されがちです。 しかし開発者の生産性が向上することで、結果的によりユーザーに価値が届けられるようになると考えています。

例えば起動に20秒かかっていれば、たとえテストが1秒で終わったとしても1分間に3回程度しか実行できませんが、3秒で済むなら20回テストが実行できます。 12秒が7秒になれば、1時間かかっていた動作確認は35分で済むようになります。これがエンジニアの人数分だけ効果が広がるのです。

ただ現状ではキャッシュに頼った高速化なので、初回アクセスが重い問題は解決していません。表示速度もまだ快適というレベルには至っていません。 今後も開発環境の高速化の取り組みは継続していこうと思っています。

/* */ @import "/css/theme/report/report.css"; /* */ /* */ body{ background-image: url('http://cdn-ak.f.st-hatena.com/images/fotolife/c/cookpadtech/20140527/20140527163350.png'); background-repeat: repeat-x; background-color:transparent; background-attachment: scroll; background-position: left top;} /* */ body{ border-top: 3px solid orange; color: #3c3c3c; font-family: 'Helvetica Neue', Helvetica, 'ヒラギノ角ゴ Pro W3', 'Hiragino Kaku Gothic Pro', Meiryo, Osaka, 'MS Pゴシック', sans-serif; line-height: 1.8; font-size: 16px; } a { text-decoration: underline; color: #693e1c; } a:hover { color: #80400e; text-decoration: underline; } .entry-title a{ color: rgb(176, 108, 28); cursor: auto; display: inline; font-family: 'Helvetica Neue', Helvetica, 'ヒラギノ角ゴ Pro W3', 'Hiragino Kaku Gothic Pro', Meiryo, Osaka, 'MS Pゴシック', sans-serif; font-size: 30px; font-weight: bold; height: auto; line-height: 40.5px; text-decoration: underline solid rgb(176, 108, 28); width: auto; line-height: 1.35; } .date a { color: #9b8b6c; font-size: 14px; text-decoration: none; font-weight: normal; } .urllist-title-link { font-size: 14px; } /* Recent Entries */ .recent-entries a{ color: #693e1c; } .recent-entries a:visited { color: #4d2200; text-decoration: none; } .hatena-module-recent-entries li { padding-bottom: 8px; border-bottom-width: 0px; } /*Widget*/ .hatena-module-body li { list-style-type: circle; } .hatena-module-body a{ text-decoration: none; } .hatena-module-body a:hover{ text-decoration: underline; } /* Widget name */ .hatena-module-title, .hatena-module-title a{ color: #b06c1c; margin-top: 20px; margin-bottom: 7px; } /* work frame*/ #container { width: 970px; text-align: center; margin: 0 auto; background: transparent; padding: 0 30px; } #wrapper { float: left; overflow: hidden; width: 660px; } #box2 { width: 240px; float: right; font-size: 14px; word-wrap: break-word; } /*#blog-title-inner{*/ /*margin-top: 3px;*/ /*height: 125px;*/ /*background-position: left 0px;*/ /*}*/ /*.header-image-only #blog-title-inner {*/ /*background-repeat: no-repeat;*/ /*position: relative;*/ /*height: 200px;*/ /*display: none;*/ /*}*/ /*#blog-title {*/ /*margin-top: 3px;*/ /*height: 125px;*/ /*background-image: url('http://cdn-ak.f.st-hatena.com/images/fotolife/c/cookpadtech/20140527/20140527172848.png');*/ /*background-repeat: no-repeat;*/ /*background-position: left 0px;*/ /*}*/