New Relicを使って、アプリAPIの応答速度を10倍早くしました

New Relic Rails

こんにちは。
中古マンション購入アプリRENOSYの、iOSアプリ兼APIサーバー開発を担当している植村です。2018年4月に新卒で入社し、はや1年半経ちました。iOSアプリ開発は1年半ずっと、サーバー開発は半年ほどの経験値です。
最近のマイブームは、週に1回スーパーで300gくらいの安いオージービーフを買って食らうことです。焼き加減は適当で、味付けは適当に塩コショウです。

www.renosy.com

この記事の概要

弊社では、New Relicというソフトウェアのパフォーマンス分析サービスを導入しています。このNew Relicを使って、RENOSYアプリ用のAPIのレスポンス速度を90%削減することに成功したので、どのような経緯でどのように解決したかを紹介したいと思います。

newrelic.nissho-ele.co.jp

背景知識

New Relic

上述したように、New Relicはソフトウェアのパフォーマンスを分析するサービス群です。サービス群と言ってるように、New Relicは以下の7つのサービスを提供しています。

  • New Relic APM (エーピーエム)
    • アプリケーションのパフォーマンス監視サービス
  • New Relic Browser
    • ブラウザのパフォーマンス監視サービス
  • New Relic Servers
    • サーバーのパフォーマンス監視サービス
  • New Relic Mobile
    • モバイルアプリ(iOS, Android)のパフォーマンス監視サービス
  • New Relic Synthetics (シンセティクス）
    • Webアプリ、サイトの疎通、障害監視サービス
  • New Relic Plugins
    • サードパーティによる各種プラグイン
  • New Relic Insights (インサイト）
    • リアルタイム分析ツール(ダッシュボード）

引用：New Relic の各製品紹介: New Relic ってアプリケーションパフォーマンス監視ツールじゃないの？ - Qiita


上記の中で、弊社は主にAPMの機能を利用しており、今回はこのAPMを使って速度改善を図りました。

やったこと

きっかけ

ある日、RENOSYチームのリーダーのSさんがこんな気づきを。

「アプリの起動時間なんか長くない？」

そこで自分でも試してみると、なんとおおよそ8秒間もスプラッシュ画面が表示（裏側でいくつかのAPIが走っています）されているではありませんか！
これはいけない。直さねば！

まずはアプリで

もともとずっとアプリエンジニアとして業務をしてきたので、まずはアプリの中のコードに、時間を計測するためのprint文を追加しました。
さてどんなもんだい！と確認してみると

START POST device:  2019/09/05 12:09:16.363
FINISH POST device: 2019/09/05 12:09:23.505

なんとデバイス登録APIに約7秒もかかっていることが判明😨。ちなみに他のAPIのレスポンスは0.2秒以下です😅

よしよし。どのAPIが原因かが分かったぞ！順調順調！

APIサーバーの中身を見てみる

次にデバイス登録APIのコードを読んでみる。user_agentやOSなどを保存してるんだな、ふむふむ。
しかし、意気揚々と望んだものの、処理全体のコード量が膨大で、どの部分の処理が重くなっているのかを特定するのがなかなかムツカシイ😫

そんなとき、RENOSYチームのTech LeadのAさんからメッセージが。

f:id:uemura1shi:20190912125755p:plain

にゅ、、にゅーれりっく・・？　ナニソレオイシイノ？

というわけで、ここで僕とNew Relicのお付き合いが始まりました。

New Relicをつかってみる

デバイス登録APIのパフォーマンスをNew Relicで眺めてみる。

f:id:uemura1shi:20190911195810p:plain

グラフィカルで、ビジュアライズが良いではないか！もっと使いこなせればいろんな事ができそうだな〜〜

と思っているとおかしなところが

f:id:uemura1shi:20190911200238p:plain

これは・・・

f:id:uemura1shi:20190911200201p:plain

OwnArticleをfindするDBの処理が890回／1トランザクションも呼ばれているではないか！！！！
さらに、デバイス登録処理の16.4%も処理時間を割いてしまっているだと・・・
まずはここからやっつけましょう。

APIサーバーの中身にもどる

再度、APIサーバーの中身にもどり、今度はデバイス登録処理の中のOwnArticleをfindしている部分の処理を探しました。（←ココ重要。New Relic無ければできなかったこと。）
アプリのユーザーであるOwnerをDBに保存後に、OwnArticleを呼び出す処理がされていました。該当コードはowner.rb内のafter_createコールバックの中でした。

class Owner < ApplicationRecord
  after_create do
    create_own_articles if customer_id
    create_default_own_articles if own_articles.blank?
  end
end


ふう・・無事発見。お前が原因か！！
って、これRENOSYアプリで必要ない処理っぽいぞ・・・。

この部分は、弊社が提供するもう一つのアプリ、OWNRで用いられているコードでした！びっくり！

www.renosy.com

修正・検証

上記の該当コードを、RENOSYでは処理を回避するように修正を加えました。

class Owner < ApplicationRecord
  after_create do
    create_own_articles if customer_id
    create_default_own_articles if own_articles.blank? && !is_renosy
  end
end



そしてドキドキの計測。。。果たして結果は！！！！ 

START POST device:  2019/09/05 16:26:44.577
FINISH POST device: 2019/09/05 16:26:45.122



約0.6秒に短縮🎉🎉🎉🎉🎉🎉🎉
たった一つの修正で 7秒→0.6秒 と 約10倍 、応答速度を早めることに成功しました。
New Relic上では、全体の中で占める処理の長さの割合は、16.4%と表示されていましたが、該当コードを回避することで、他のDB処理も芋づる式に削減することができたため、10倍の速度改善成功という、大きな成果に繋がりました。

感想

当てずっぽうや感覚だけで当たりをつけず、きちんとパフォーマンス分析ツールを使って、該当する部分を絞り込んでから、コードに手を付けたため、全く手戻り無く、かなりの少ない工数でパフォーマンス改善を行うことができました。New Relicを導入してもらった、弊社SREチームのみなさま、本当にありがとうございました。
普段からこういう機会が訪れることを想定して、パフォーマンスを監視しておくことの重要性に気づきました。 また、New Relic Mobileというモバイルアプリ向けのパフォーマンス監視サービスも提供されているとのことで、そちらもぜひ試してみたいなと感じました。

uemura1shi 読者になる

関連記事

エンジニア積極採用中

不動産業界のITイノベーション
最前線に立ちませんか?

ITANDI