概要

１年半ほどNewRelicを本番環境+開発環境で使ってきて知見が溜まってきたので共有したいと思います。ここで説明している機能は有料版のものも含みます。

NewRelicとは

NewRelicとはサーバ、またはアプリケーションの状態をモニターし、その性能を改善するために使われるツールです。既存のモニタリングツールとしては、zabbix, ganglia, nagios, munin など各種ありますが、NewRelicが優れているのはその手軽さかと思います。インストールしたらアプリケーションをサーバ運営する上で必要なメトリックスが一通り揃っています。既存のモニタリングツールだとインストールするユーザが必要なメトリックスを定義して設定、場合によってはスクリプトを書かなければいけません。その点、NewRelicはデフォルトのメトリックスが非常に充実しており見やすく配置されており追加設定なしで十分という場合も多いでしょう。既存のメトリックスにない場合でも手軽にインストールできるプラグインが充実しております。

この記事ではNewRelicの誰でもしっている機能から、有料版の細かい機能までをケーススタディ別で紹介したいと思います。

前提環境

スマートフォンゲームのアプリケーションサーバを開発してます。 NewRelicでメトリックスを取っているアプリケーショの環境図は以下です。

AWS環境
アプリサーバは複数台でEC2に乗っているDjango (python)のアプリケーション
MySQLとRedisにアプリサーバが繋がっている

と、ごくごく一般的な構成です

それではサーバエンジニアのケーススタディを始めます

ケース1: アプリケーションの応答が遅いけどもっと早くならないか

いろいろな人から言われると思います。ざっくりすぎてよくわからないので、まず問題を定義するところから始めます。遅いところはどのAPIなのか。いつから遅くなったのか。特定の場合のみ遅いのか。他のユーザはどうなのか。たくさんありますが、何が問題なのかを具体的にします。その結果以下のような問題がわかりました。

ガチャのAPIが１日まえくらいから遅くなった。他のプレイヤー全員が遅いわけではなく、早い人もいる。

だいぶ具体的になったので、NewRelicを見てみます。 APPSで該当のアプリケーションを選んでから、Transactionsという項目を押してください。「Slowest average response time」というものを選ぶと応答時間の順に遅いAPIがわかります。（注意: 全体的に遅いですが、まだ性能改善前で、サーバのチューニングもしていないのです。。。）

そこのgachaのクリックすると右側に以下のようなページが見えます。

このページを見ることによって以下の事がわかります。

pythonコードのFunctionで多くの時間を取っている
unit_player_xxのselectが多い
unit_player_xxのinsert, updateも多い

問題定義の内容とソースコードの両者を合わせてボトルネックを探ると以下の点が問題でした。

大量にユニットを所持しているユーザのレスポンスが遅かった => ユーザの取得済みユニットの全リストをAPIで返しているが必要ないので削除
ガチャで取得したユニットごとに複数のinsert/udpateが走っている => 更新系はbulkで行う

上記の対応をすることによりAPIが早くなり問題ない応答時間になりました。このようにNewRelicではAPIごとのSQL発行数, Redisへのクエリ発行数, pythonコードの実行時間が取得で性能改善に役立ちます。

ただ、ここで注意しなければならないのは、Avg timeはあくまでかかった時間なので、サーバのCPUがいっぱいいっぱいだと、pythonコードが処理できずコードの時間が長くなったりします。

ケース2: MySQLがなんか遅そうなのだけれどもどこが原因？

NewRelicのMySQL項目を説明するためのケースのようですが、実際に起こり得ます。ユーザが増えてきた際にAppサーバのCPUは50%くらいで問題なさそうなのになんかおそくなったという際はMySQLかRedisが原因かもしれません。

よくわからないときは基本のOverviewを見ています

なんだかMySQLが遅そうですね。そのようなときは、左ペインDatabasesを選択し、ひとまず以下の項目を見てみます。（注意: 別の時間のものです。単に紹介なので）

クエリごとの応答時間がわかるので、遅くなったクエリなど一目瞭然です。このケースでありがちなのは、データの履歴が少なかったときは早かったのですが、多くなってくると遅くなるパターンなどです。インデックスの貼り忘れだったり、そもそも履歴が必要なかったりするケースがあったりするのでそこを直します。それぞれのクエリをクリックするとそのクエリを発行しているAPIもわかるので改善により役立ちます。

この項目ではクエリ単位でしか見れませんが、MySQLのサーバ自体のメトリックスをみたい場合は、MySQL pluginがおすすめです。（注意: 別の時間のものです。単に紹介なので）

http://newrelic.com/plugins/new-relic-platform-team/52

インストールすると以下のような項目が見れます。

ケース3: CPUがいっぱいいっぱいになっているがなにがおこっているのか

どのプロセスがCPUをくっているのか知りたいときもありますがAWSコンソールの標準のメトリックスでは全然わかりません。そんなときもNewRelicならdefaultでインストールしたエージェントでとれます。

トップペインからSERVERSを選びます。Processesを左ペインから選ぶとどのプロセスがCPUを多く使っているかわかります。

ケース4: いつデプロイしたのか知りたい

NewRelicのWeb APIにイベントを投げる事によってデプロイした時間にマークをつけることができます。

ケース5: リリースしてからてんやわんや

なんだかよくわからないケースですが、本番サーバにしかNewRelicをいれていなかったというお話です。 NewRelicは開発期間中に開発サーバにいれてこそ効果が発揮されます。よくあるのは開発で早く動いていても本番になると性能が劣化するパターンです。開発環境では十分な負荷がかかっていないので、SQLのクエリが遅かったりすることろがわかりません。そのような際は開発環境にもNewRelicを入れておき、APIごとのSQL発行数などを監視しておきます。もちろん負荷試験をリリース毎にやればいいのですが、コスト・時間的に現実的ではない場合も多いです。月々多少の費用はかかりますが十分ペイできると思います。

ケース6: アプリケーションが正しく動いているのか知りたい

ようするに生存確認です。正しくやろうとすると、一通りのAPIにリクエストを投げてレスポンスを確かめます。ただ、実際にはそこまでする必要はなくアプリケーションが動いているかどうかを１つの生存確認用のAPIに投げてレスポンスがただしいかどうか確かめればいいと思います。その際に、どのようなAPIを作るかが大事です。echoサーバのようにただechoを返すのではなくMySQL, Redisなど繋がっているサービスにも軽いクエリをなげるといいです。その様にすることによりMySQL, Redisの生存確認も同時にすることができます。

NewRelicでは以下で設定できます。

設定したあとはAvailabilityでその結果を見ることができます。

Alertメールなども設定できるので、設定しておくとシステムダウンの際に素早く気づくことができます。自分の所属しているチームでは、開発環境が接続できなくなったときなどチャットに通知がとどくので素早く気付き修正することができます。

ケース7: 世界各国からの応答時間を知りたい

世界展開しているアプリは、各国からの応答時間がきになるものです。 NewRelicではSYNTHETICSを設定することによって以下の地域からの応答時間を調べることができます。一定時間ごとに送ってくれるます。

ケース8: 例外が発生したときにそのプレイヤーIDが知りたい

NewRelicでは発生した例外はErrorsで表示されるのですが、自分で設定しない限りはアプリケーション特有の情報は含んでくれません。例えば、player_idなどユーザを特定できるものが例外とともに記録されていればアプリケーションの管理画面などからそのユーザを検索し、例外のより詳しい状況がわかることができます。

NewRelicで正しく設定すると以下のように見れます。

ソースコード上では以下のように設定しています。共通処理なので、decoratorとかviewの前処理などに仕込めばいい感じにしてくれそうです。(Djangoでのお話)

# newrelicにplayer_idを追加する
newrelic.agent.add_custom_parameter('player_id', player.id)

ケース9: あるAPIを改善したので実際に早くなっているのか確認したい

改善したならば計測して実際に早くなっているか確認しないと意味がないですね。 NewRelicでその辺も確認できます。

ケース10: ある特定のAPIが遅いがソース上でどこが遅いのか確認したい

その1のケース1で遅いAPIのざっくりどこで時間をとっているかわかりました。

しかし、もっと細かくソースコード単位でどこの処理で時間がかかっているのか見たい場合もあると思います。その時に活躍するのが、Key TransactionsとX-Ray Sessionsです。

Key Transactionsは、特定のAPIごとに、リクエストを別ページで追跡して詳細なログを見ることができます。その特定のリクエストのプロファイラを表示してくれるのが、 X-Ray Sessionsです。

それでは設定していきましょう。

今回は、/api/homeのAPIのパスをKey Transactionsとして追加してみようと思います。以下のように①=>②=>③の順番でクリックします。②で気になるAPIをクリックして追跡します。今回の場合だとhomeのAPIです。

/api/homeのKey Transactionが出来るので、ウィザードに従いKey transactionsのページへ移動して見てみます。このように特定のAPIのリクエストのみの情報が見れます。

Key transactionによってAlertなども設定できますが、今回は、X-Rayで処理のボトルネックを調べてみます。

これでX-Rayが設定できました。sampling_homeという名前で、最大1時間にわたって、50リクエスト追跡します。アクセスがあるサーバならしばらくまつか、APIテストなどを該当のAPIにリクエストして50リクエストたまるのを待ちます。

たまったらsampling_homeを開いて、X-Rayをクリックし、Thread Profileを開いてみます。実行された順番ごとにかかった時間のパーセンテージがのっているので詳しく、ボトルネックを見ることができます。（結構モザイクばっかりで見難くてすいません）ただし注意しなければいけないのは、IO待ちやコンテキストスィッチなどでCPUが切り替わったときに待っている待ち時間もここに反映されているので参考程度にという形ではあります。

おまけ: たまたま遅いリクエストの原因を追求する

Key Transactionsにはもう１つ便利な機能があって、トラックしたリクエストの１つ１つの詳細を応答時間に応じて見ることができます。これを使えば、多くのリクエストは早いけれども、時々遅いものがあるなどの場合を発見しやすく、その特定のリクエストだけをフォーカスして、どこの処理が遅くなっているか見ることができます。

さらに実行された SQL も細かく見れるので障害対応や遅いクエリの対応にかなり役立ちます。