11: 応用編 2: アプリ固有のパフォーマンス計測をしよう - New Relic を使ったアプリケーションのパフォーマンス監視入門

「[New Relic を使ったアプリケーションのパフォーマンス監視入門](https://qiita.com/kumatronik/items/f40c5a44156fa3716fb7)」第11回。応用編その２です。

今回で最後。これまでは、コード自体には何もしないで New Relic エージェントが収集したパフォーマンスデータで分析を行う方法を紹介していきました。

今回は、コードに計測ポイントなどを追加することで、より、サービス自体のパフォーマンス分析や調査が効率良く行える方法を紹介します。それが、**カスタム属性**と**カスタム計測**です。

似たような名前だが、機能は全く異なる機能です。

[**カスタム属性**](https://newrelic.degica.com/docs/insights/insights-data-sources/custom-attributes/requirements-custom-attributes)は、New Relic がデフォルトで収集データ(処理時間とか）に加え、任意のデータ(キー/値)を New Relic に送信できる機能。例えば、マルチテナントの EC ストアであれば、ストアIDをカスタム属性に追加することで、ストアごとのレスポンスの比較やスループットの比較なども行える。

[**カスタム計測**](https://newrelic.degica.com/docs/agents/manage-apm-agents/agent-metrics/custom-instrumentation)は、トレースディテールで表示される計測ポイントを追加できます。トレースディテールはメソッド単位までの粒度ではないので、そこにあるメソッドをカスタム計測として追加すると、そのメソッド単位で計測できるようになる。（これは文字で説明しづらいので、後でスクリーンショットを見てもらえればイメージがすぐにわかると思う）

## カスタム属性

上の説明で、既存のデータに加えて任意のデータを付加できると書きましたが、それをどのように使うかというと、APM  ではあまり、利用シーンはありません。(なぜなら、APM は決められた形式のデータしか表示できない UI のため）では、どうやってカスタム属性を活用するかというと、それが、**New Relic Insihts** です。

カスタム属性を追加することで、例えば、ストアごとのパフォーマンス比較や特定にユーザーのトランザクション一覧とそのパフォーマンス情報の取得。遅い検索条件の特定など、デフォルトで収集したデータだけではできない様々な角度からのパフォーマンス分析が行えるようになります。

### 追加方法

カスタム属性を追加するには、New Relic が用意している API を各アプリ内で呼出します。API は言語によって異なるので、ここでは Ruby の例を示します。

```ruby
::NewRelic::Agent.add_custom_attributes({ store_name: current_store.name })
```

Ruby 以外の言語の API は[この](https://newrelic.degica.com/docs/agents/manage-apm-agents/agent-metrics/collect-custom-attributes)ページをから確認してください。


### New Relic Insights を使ったパフォーマンス分析

６回目の「[基礎編 2: アプリ監視でやっておくべき３つの設定](https://qiita.com/kumatronik/items/b3bdbea4da4aa4b4761e)」にて、Apdex の閾値を求める際に、NRQL は多少説明していますので、それを前提に説明していきます。NRQL が分からない方は、先にそちらの記事をご覧ください。(または、SQL みたいなものだと思ってもらえればそれでも大丈夫です）

上記で `store_name` をカスタム属性として追加した場合は、以下のような NRQL が作れます。

**ストアごとの平均処理時間**

```sql
select average(duration) from Transaction facet store_name
```

![スクリーンショット 2017-12-25 22.49.54.png](https://qiita-image-store.s3.amazonaws.com/0/46003/ca8c1224-0bf8-17fc-75ea-b29b9774ae6a.png)


**ストアごとのトランザクション数の割合**

```sql
select count(*) from Transaction facet store_name
```

![スクリーンショット 2017-12-25 22.59.52.png](https://qiita-image-store.s3.amazonaws.com/0/46003/1fe6820e-8c50-db72-c956-aaf49efc2a3d.png)


**特定のストアごとのパフォーマンス情報**

```sql
select max(duration), max(databaseDuration), average(duration), average(databaseDuration) from Transaction where store_name = 'ストア名'
```

![スクリーンショット 2017-12-25 23.02.54.png](https://qiita-image-store.s3.amazonaws.com/0/46003/1ef6a61e-cbb0-ad32-493c-dcb9999985ea.png)

**ストアごとの平均処理時間の時系列チャート

```sql 
select average(duration) from Transaction TIMESERIES  facet store_name 
```

![スクリーンショット 2017-12-25 23.06.57.png](https://qiita-image-store.s3.amazonaws.com/0/46003/b0cc1241-c709-008f-236f-5d1551cfb190.png)

このように１つ属性を追加しただけでも、非常に様々な情報が取得でき、分析できることが分かってもらえたと思います。


#### NRQL アラートにも使える

今回の連載では紹介していませんが、アラートの一つの機能として、NRQL を使ってアラート条件を作成できる機能があります。それが「[NRQLアラート](https://newrelic.degica.com/docs/alerts/new-relic-alerts/configuring-alert-policies/create-alert-conditions-nrql-queries-cot)」です。

その名の通り、NRQL の結果を値として、他の静的な閾値のアラートと同じように指定した閾値を NRQL の結果が越えた場合にアラートを出すというものです。

この場合、NRQL を作成する注意点として、NRQL が単一の数値を返すものでなければならない。ということです。上記の例みたいに、複数の数値や時系列データを返す NRQL は使えません。

例えば以下のようなものとなります。

**ストアAの平均レスポンスタイムを返す NRQL**

```SQL
select average(duration) from Transaction where store_name = 'ストアA' 
```

NRQL アラートは、他のアラートと同じく、**New Relic Alerts** から設定します。詳しい設定手順や例は「[NRQL アラート: どんな項目もアラート条件として扱える最強のアラート設定](https://qiita.com/kumatronik/items/21397bce4f2a81486035)」をご覧ください。


### APM カスタム属性を確認できる場所

とはいっても、APM でもカスタム属性を確認できる場所が2つあります。

#### トレースディテールのトランザクション属性欄

１つ目は、トレースディテールのリクエスト情報欄です。トレースディテールは個々のリクエスト情報です。そのリクエスト内容(ユーザーエージェントなど）を見ることができます。カスタム属性として追加した情報はここに表示されます。

![スクリーンショット_2017-12-25_1_11_27.png](https://qiita-image-store.s3.amazonaws.com/0/46003/fbc54b6b-cac7-4293-2731-a59d65ef163a.png)

カスタム属性を追加しておくことで、トランザクションのボトルネックの調査に役立つかもしれません。

#### エラープロファイル

エラー分析機能の１つである[エラープロファイル](https://newrelic.degica.com/docs/apm/applications-menu/error-analytics/error-profiles-troubleshoot-trends)は、未キャッチ例外が発生したトランザクションと正常なトランザクションの差を利用して、エラーの根本原因を効率良く行えるようにサポートする機能です。

<img width="500" alt="スクリーンショット_2017-12-25_1_18_24.png" src="https://qiita-image-store.s3.amazonaws.com/0/46003/e56119ec-37f2-74c6-3729-ccacf509c93a.png">

カスタム属性を追加しておくと、その属性も差の比較対象になります。そのため、ストアIDをカスタム属性として追加していた場合に、特定のストアだけ例外が発生し易い傾向にあるといった情報が表示されるかもしれません。

エラー分析機能についてはここでは詳しく説明していないので、知りたい方は[ここ](https://qiita.com/kumatronik/items/72880fac183f432ab333)をご覧ください。また、エラープロファイルについては[ここ](https://qiita.com/kumatronik/items/fe8400c5286df095bb5b)をご覧ください。




## カスタム計測(Custom instrumentation)

トレースディテールを見ていて、このDB処理は具体的にどのメソッドで呼ばれているのかわかりづらいことがあります。特に処理が深い場合や何度も呼び出されるような処理になるとなおさらです。そのような場合に[カススタム計測](https://newrelic.degica.com/docs/agents/manage-apm-agents/agent-metrics/custom-instrumentation)を使うと、トレースディテールの計測ポイントを追加できます。これによって、そういったわかりづらさを解消できます。

見てもらった方が分かりやすいので、まずはカスタム計測を追加する前と追加した後のスクリーンショットをご覧ください。

カスタム計測を追加すると、トランザクションの処理の内訳に追加したカスタム計測が、カテゴリ **Custom** として追加されます。これによって、追加した箇所のパフォーマンスが一目で分かります。 
![custom1.png](https://qiita-image-store.s3.amazonaws.com/0/46003/1b50d12a-907b-7ef8-279e-840653d0aaa1.png)

次に、トレースディテールを見てみます。
![custom2.png](https://qiita-image-store.s3.amazonaws.com/0/46003/69f12440-e7af-89bf-0bd7-6d5003e00285.png)
追加前には、コントローラーが呼ばれた後にひたすらDB処理がフラットに大量に並んでいます。これだと、どの処理がどのメソッドで呼ばれたのか調べづらいですね。そこで、カスタム計測を３つメソッド定義に仕込みました。すると、そのメソッドごとにネスト構造になって表示されました。追加前と比べると、かなり分かり易くなっていることがわかると思います。

このように、フラットな呼出しを階層化することでデバッグしやすくするのがカスタム計測です。

### カスタム計測の追加方法

上記で実際に追加したカスタム計測は以下のようになります。上は Ruby アプリなので、Ruby の例となります。`Spree::Order` モデルの `next`、`update_totals`、`update!` メソッドに対してカスタム計測を追加しています。ただこれだけです。非常に簡単ですよね。

```ruby
Spree::Order.class_eval do 
  add_method_tracer :next
  add_method_tracer :update_totals
  add_method_tracer :update!
end
```

言語ごとにカスタム計測の追加方法は異なりますので、具体的な方法は「[カスタム計測の実装](https://newrelic.degica.com/docs/agents/manage-apm-agents/agent-metrics/custom-instrumentation#implementing)」に載っていますので、そちらをご覧ください。

注意点として、カスタム計測を追加すればするほど分かりやすくはなりますが、同時に負荷も上がりますので、そのバランスはとるようにしてください。


## トランザクション名の変更

APM の計測単位はトランザクションです。言い換えると、`Controller` 単位と言ってもいいでしょう。そのため、例えば、URL 単位では分かれていても、ルーティングの設定では１つのコントローラーで扱っていたり、入り口は１つのコントローラーだけど、実際は内部でパラメーターによって全く違う処理に分岐するみたいなこともあるでしょう。その場合は、同じ１つのコントローラーでも分岐によってパフォーマンスは全く異なるといったことがあります。そういう場合でも、１つのトランザクションタイプなので、平均すると実体がよくわからないパフォーマンスを表していることになります。

そういった場合に備えて、トランザクション名を変更する機能が New Relic にはあります。

これを使うことで、例えば、パラメーターの値でトランザクションを変更することで、別々のトランザクションとしてトランザクション一覧等で扱うことができるようになります。

### トランザクション名の変更方法

また Ruby の例ですが、Ruby で書くと以下のようになります。以下は、注文状態ごとにトランザクションを分けています。(この場合、`#{new_relic_name}` はオリジナルのトランザクション名を指します)

```ruby
NewRelic::Agent.set_transaction_name("#{new_relic_name} - #{order.state}")
```

こうすると、New Relic APM のトランザクション一覧では以下のように表示されます。
<img width="325" alt="スクリーンショット_2017-12-25_1_35_18.png" src="https://qiita-image-store.s3.amazonaws.com/0/46003/8bb0c19c-f1fd-f6b2-a916-c31da8eaec19.png">

`xxxController#update` だったものが、`xxxController#update - payment` と `xxxController#update - address` に分かれて表示されるようになりました。

こういう風に複数の責務を担うトランザクションのパフォーマンスを分離して把握したい場合に、この方法は役に立ちます。

####  言語別トランザクション名の変更方法

- [Ruby](https://newrelic.degica.com/docs/agents/ruby-agent/features/ruby-custom-instrumentation#naming-transactions)
- [.Net](https://newrelic.degica.com/docs/agents/net-agent/features/net-custom-instrumentation#transactions)
- [Java](https://docs.newrelic.com/docs/agents/java-agent/instrumentation/transaction-naming-protocol)
- [PHP](https://docs.newrelic.com/docs/agents/php-agent/php-agent-api/newrelic_name_transaction)
- [Python](https://docs.newrelic.com/docs/agents/python-agent/python-agent-api/set_transaction_name)


## まとめ

以上で、「New Relic を使ったアプリケーションのパフォーマンス監視入門」と題した一連の掲載は終わりとなります。全体は「[目次: New Relic を使ったアプリケーションのパフォーマンス監視入門」](https://qiita.com/kumatronik/items/f40c5a44156fa3716fb7)をご覧ください。