Posted at

詳解 NewRelic で性能改善〜その3

More than 3 years have passed since last update.

詳解 NewRelic で性能改善〜その2の続きです。

今回はKey TransactionsのX-Ray Sessionsという機能でみれるThread Profilerの紹介です。

x_ray_0.png


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

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

しかし、もっと細かくソースコード単位でどこの処理で時間がかかっているのか見たい場合もあると思います。

その時に活躍するのが、Key TransactionsX-Ray Sessionsです。

Key Transactionsは、特定のAPIごとに、リクエストを別ページで追跡して詳細なログを見ることができます。

その特定のリクエストのプロファイラを表示してくれるのが、 X-Ray Sessionsです。


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

今回は、/api/homeのAPIのパスをKey Transactionsとして追加してみようと思います。

以下のように①=>②=>③の順番でクリックします。②で気になるAPIをクリックして追跡します。今回の場合だとhomeのAPIです。

transactions.png

/api/homeのKey Transactionが出来るので、ウィザードに従いKey transactionsのページへ移動して見てみます。

このように特定のAPIのリクエストのみの情報が見れます。

key_transactions_1.png

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

x_ray_1.png

x_ray_2.png

これでX-Rayが設定できました。sampling_homeという名前で、最大1時間にわたって、50リクエスト追跡します。

アクセスがあるサーバならしばらくまつか、APIテストなどを該当のAPIにリクエストして50リクエストたまるのを待ちます。

たまったらsampling_homeを開いて、X-Rayをクリックし、Thread Profileを開いてみます。

実行された順番ごとにかかった時間のパーセンテージがのっているので詳しく、ボトルネックを見ることができます。(結構モザイクばっかりで見難くてすいません)

ただし注意しなければいけないのは、IO待ちやコンテキストスィッチなどでCPUが切り替わったときに待っている待ち時間もここに反映されているので参考程度にという形ではあります。

x_ray_3.png


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

Key Transactionsにはもう1つ便利な機能があって、トラックしたリクエストの1つ1つの詳細を応答時間に応じて見ることができます。

これを使えば、多くのリクエストは早いけれども、時々遅いものがあるなどの場合を発見しやすく、その特定のリクエストだけをフォーカスして、どこの処理が遅くなっているか見ることができます。

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

x_ray_4.png


結び

これにて、その1〜3まで続いた詳解 NewRelic で性能改善は終わります。

New Relicは簡単に様々なメトリックスが見れ、空いた時間を本当に必要なサービス開発にさけるすばらしいツールだと思っております。