ENECHANGE Developer Blog

ENECHANGE開発者ブログ

Scout APM を導入して、高速化したときの話

自己紹介

cuzic こと、 ENECHANGE チーフエンジニアの川西です。

今回は enechange.jp で Scout APM を使って高速化した話を書きます。

はじめに

enechange.jp で、サイトが遅いので高速化したい、という声が開発者から多くありました。

特に、開発環境ではマシンが低速だったりキャッシュクリアして動作確認が必要なケースも多く、耐えがたく遅い場合がありました。

それで、性能監視ツール Scout APM を導入しました。 Scout APM を選定したのは単純に RubyKaigi で名刺交換し、2週間無料のアカウントを設定してもらったから。そのときは、たまたま忙しいタイミングであったということもあり、一切検証せずに2週間が過ぎてしまっていた。 今回、お願いしでみたら、あっさり再度 2週間の検証用アカウントを利用させてもらえた。神。

とはいえ、検証期間が2週間しかない。短い。締め切りまでにやらなきゃ。というわけでバタバタと 8件の PR を作成。

f:id:cuzic:20200117163828p:plain
Scout APM を参考にして作成した高速化 Pull Request

N+1 問題を解消する PR がほとんど。

N+1 問題があると、下記のようにタグがつくので、根本原因がすぐに分かります。

f:id:cuzic:20200117171830p:plain
N+1 問題の表示の例

N+1 問題以外にも高速化の役に立ちます。 この記事では、ずっと放置されていたレスポンスが遅い事象を発見・解決した件について特に紹介します。

低確率で発生する時間のかかる処理を高速化

今回の検証期間では Scout APM を本番環境にも導入し、性能監視を行いました。

すると、下記のような事象を発見しました。

f:id:cuzic:20200117163912p:plain
非常に遅い HTTP リクエストにより表示に 11秒かかっていた例

非常に遅い xml_tag_from_wp という同じメソッドを 5回呼んでいます。結果、表示に11秒もかかっています。遅すぎです。 これは Wordpress の API に対してリクエストするメソッドです。 このメソッドは非常に応答が遅くなるときはあるのですが、本来 Redis を使って結果をキャッシュするはずです。 5回も行われるような処理ではありません。

原因となった元のコードは下記のとおりでした。(実際のコードを説明用に簡素化しています)

return Rails.cache.read(cache_key) if Rails.cache.read(cache_key)

xml_tag_from_wp メソッドは HTTP リクエストが失敗するとき結果が nil になる場合があります。この場合、 Rails.cache.read(cache_key) の結果も nil になり、キャッシュが使われません。その結果、非常に低速な HTTP リクエストの処理を、リトライも含めて 5回行う処理となっていました。

このコードを下記のように修正しました。

return Rails.cache.read(cache_key) if Rails.cache.exist?(cache_key)

exist? を使うことで、2回目以降はキャッシュを使って nil を返すことができるようになり、非常に高速化することができました。

このように、低確率で発生する事象は、通常はなかなか発見することはできませんが、今回、本番環境に Scout APM を導入し、気づくことができました。

おわりに

2週間の検証期間でさまざまな高速化に取り組み、結果として Scout APM を enechange.jp の本番環境に本格導入しました。

さらに、今はキャンペーンで特別に、 Scout APM に関する技術ブログを執筆すると、特別なディスカウントがありました。 お得。