OSS の APM！Elastic APM を試してみた

藤本真司

2018.03.08

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

Elastic Stack でアプリケーションのパフォーマンス監視ができるプロダクトがリリースされました。システムのモニタリング UI を Kibana に統一してみませんか？

概要

Elastic Stack 6.2.0 で Elastic APM の GA がリリースされました。

Elastic APM GA released

APM（Application Performance Monitoring/Management）は名前の通り、アプリケーションのパフォーマンス監視ができるソフトウェアの総称です。AWS のサービスでは AWS X-Ray、有名ドコロのサービスですと、New Relic、Datadog が SaaS として提供しています。

昨今のシステムは導入されるソフトウェアが多く、かつマイクロサービスなどで一つのWebリクエストでも複数のサブシステムに跨って処理が発生する構成も珍しくありません。このように複数のコンポーネント、サブシステムにおいて、パフォーマンスが悪い、レスポンスが遅いという事象が発覚した際に調査が難しいです。どのサービスのどのコンポーネントが遅いのか、遅いのは特定の処理なのかログだけの調査では非常に難しいですし、時間がかかります。

APM はこのような複雑化してきているシステムをリクエスト単位、処理単位などでサービスを横断してパフォーマンスを可視化できます。

Elastic APM

Elastic APM ならではの特徴は以下のように考えます。

無償で利用できる
- 既に Kibana を利用されている方は同居できるのでインフラコストも無料
モニタリング用 UI を Kibanaに統一できる
- 既にログデータ、Beats で取得したメトリクスを Kibana で可視化している場合はアプリケーションのパフォーマンスも一緒に可視化できる
- 既に Kibana を利用されている方は学習コストが低い
Kibana でプリセットされた可視化が利用できる
- 通常の Kibana ダッシュボードのように自由にカスタマイズも可能
ソースコードに少しの設定を加えるだけでパフォーマンス情報を抽出できる（これは大体の APM がそうですね
エラー情報も抽出できる

対応言語・フレームワーク

Node.js
- Express
- hapi
- Koa
Python
- Django
- Flask
Ruby（Beta版）
- Rails
- Rack
JavaScript（Alpha版）

構成

Elastic APM は以下のような構成となります。公式ドキュメントから引用します。

引用：Getting Started with APM >> Overview

APM Agent

APM Agent はアプリケーションの処理とトラッキングして、APM Server へ情報を送信します。特にプロセスを常駐させる必要はなく、各アプリケーションでライブラリとして動作します。

APM Server

APM Agent から情報を受信し、Elasticsearch へデータをインデキシングします。

Elasticsearch

パフォーマンスデータをストアします。

Kibana

Elasticsearch にストアされたデータを可視化します。Elastic APM はグラフ、ダッシュボードを用意していて、コマンド一つでよく使われるダッシュボードを生成します。もちろんストアしたパフォーマンスデータを通常通り任意のグラフで可視化して、任意のダッシュボードを作成することもできます。

試してみた

今回は Django アプリケーションに Elastic APM エージェントを導入し、Kibana で可視化するまでをやってみます。

APM Server のインストール
APM Server の起動
APM Python Agent のインストール
APM Agent を Django にセットアップ
Kibana の APM UI セットアップ
動作確認

前提

Elasticsearch、Kibana は最新版がインストールされていることとします。

環境

Elastic APM、Elasticsearch、Kibana は一つの OS上に起動します
- OS : CentOS 7.4
- Elasticsearch : 6.2.2
- Kibana : 6.2.2
アプリケーション（エージェント）
- OS : MacOS
- 言語 : Python 3.6.1
- フレームワーク : Django 2.0.2

APM Server のインストール

まずは APM Server を導入します。RedHat系 OS では Elastic が提供する YUM Repository からインストールできます。非常に簡単ですね。

$ echo '[elasticsearch-6.x]
name=Elasticsearch repository for 6.x packages
baseurl=https://artifacts.elastic.co/packages/6.x/yum
gpgcheck=1
gpgkey=https://artifacts.elastic.co/GPG-KEY-elasticsearch
enabled=1
autorefresh=1
type=rpm-md' |sudo tee /etc/yum.repos.d/elastic.repo
$ sudo yum install -y apm-server
<skip>
Installed:
  apm-server.x86_64 0:6.2.2-1

Complete!

APM Server の起動

デフォルト設定では APM Server は localhost の tcp/8200 で APM Agent からのデータを LISTEN します。APM Agent は外部からのアクセスになると思うのでアクセスを開放するように設定ファイルを編集します。
（RPM にてインストールした場合、設定ファイルのパスは /etc/apm-server/apm-server.yml となります）

$ sudo sed -ie 's/localhost:8200/0.0.0.0:8200/g' /etc/apm-server/apm-server.yml

アクセス開放以外にも APM Server と Elasticsearch が異なるホストの場合、APM Server と Kibana が異なるホストの場合、通信するホストのホスト名:ポート番号を指定します。

設定が完了したら、Kibana にインデックステンプレートと、ダッシュボードをインポートします。

$ sudo apm-server setup
Loaded index template
Loaded dashboards

APM Server を起動します。

$ sudo systemctl start apm-server

8200 番ポートで接続できればOKです。

$ curl -v telnet://localhost:8200
* About to connect() to localhost port 8200 (#0)
*   Trying ::1...
* Connected to localhost (::1) port 8200 (#0)

APM Python Agent のインストール

ここからは Agent 側の操作なのでアプリケーション側にて修正します。今回は Django の処理をモニタリングするため、Python 向けの APM Agent をインストールします。インストールは pip コマンドでインストールできます。

$ pip install elastic-apm

APM Agent を Django にセットアップ

Django アプリケーションは /app/health リクエスト送ったら JSON 返すだけの適当な Web API を作りました。

Django アプリケーションの場合、settings.py に下記の 3つを追記してください。

settings.py

ELASTIC_APM = {
  'SERVICE_NAME': 'app',
  'SERVER_URL': 'APM_SERVER_URL(ex. http://10.0.0.100:8200)'
}

INSTALLED_APPS = [
  ### add in INSTALLED_APPS
  'elasticapm.contrib.django',
]

MIDDLEWARE = [
  ### add in MIDDLEWARE
  'elasticapm.contrib.django.middleware.TracingMiddleware',
]

これだけです。簡単ですね。

動作確認

アプリケーションを起動して、curl コマンドでリクエストを送ってみます。

$ curl localhost:8000/app/health
{"status": "ok"}

Elasticsearch にどんなデータが入っているか確認してみましょう。

Kibana Console

インデックスを確認します。

GET _cat/indices
yellow open apm-6.2.2-2018.03.08       OByL2JaQQ5eVM8MkaAEnPA 1 1   1 0  16.7kb  16.7kb

apm-VERSION-YYYY.MM.DD という命名規則でインデックスが作成されるみたいです。中のデータも確認してみます。

POST apm-6.2.2-2018.03.08/_search
{
  "took": 0,
  "timed_out": false,
  "_shards": {
    "total": 1,
    "successful": 1,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": 1,
    "max_score": 1,
    "hits": [
      {
        "_index": "apm-6.2.2-2018.03.08",
        "_type": "doc",
        "_id": "IU0JAmIBMr3dFxv_qyvT",
        "_score": 1,
        "_source": {
          "@timestamp": "2018-03-08T01:52:03.388Z",
          "processor": {
            "name": "transaction",
            "event": "transaction"
          },
          "transaction": {
            "id": "4b280b5a-7d54-4b2c-990d-1f26159d9e30",
            "name": "GET app.views.health",
            "duration": {
              "us": 8213
            },
            "type": "request",
            "result": "HTTP 2xx",
            "sampled": true
          },
          "context": {
            "process": {
              "pid": 92709,
              "argv": [
                "./project/manage.py",
                "runserver"
              ]
            },
            "response": {
              "status_code": 200,
              "headers": {
                "content-type": "application/json",
                "x-frame-options": "SAMEORIGIN",
                "content-length": "16"
              }
            },
            "user": {
              "username": "",
              "is_authenticated": false
            },
            "tags": {},
            "request": {
              "headers": {
                "host": "localhost:8000",
                "user-agent": "curl/7.54.0",
                "accept": "*/*",
                "content-length": "",
                "content-type": "text/plain"
              },
              "method": "GET",
              "socket": {
                "remote_address": "127.0.0.1",
                "encrypted": false
              },
              "cookies": {},
              "url": {
                "pathname": "/app/health",
                "port": "8000",
                "full": "http://localhost:8000/app/health",
                "protocol": "http:",
                "hostname": "localhost"
              },
              "env": {
                "SERVER_PORT": "8000",
                "REMOTE_ADDR": "127.0.0.1",
                "SERVER_NAME": "1.0.0.127.in-addr.arpa"
              }
            },
            "service": {
              "agent": {
                "name": "python",
                "version": "2.0.1"
              },
              "language": {
                "name": "python",
                "version": "3.6.1"
              },
              "runtime": {
                "version": "3.6.1",
                "name": "CPython"
              },
              "framework": {
                "version": "2.0.2",
                "name": "django"
              },
              "name": "app"
            },
            "system": {
              "architecture": "x86_64",
              "platform": "darwin",
              "hostname": "HL00120.local"
            }
          },
          "beat": {
            "name": "localhost.localdomain",
            "hostname": "localhost.localdomain",
            "version": "6.2.2"
          }
        }
      }
    ]
  }
}

結構多くのデータを取ってくれるみたいです。大事なデータはリクエスト受付日時（@timestamp）、処理時間(transaction.duration.us)、URL パス(context.request.url.pathname)でしょうか。Django ならではで言うと、transaction.name で view の関数名まで取得できています。

可視化

リクエストに関するパフォーマンスデータが入っていることを確認できました。それでは Kibana からデータを確認してみましょう。ダッシュボードを確認すると既に 5つのダッシュボードが存在します。

[APM] Transcations を開きます。パフォーマンスのダッシュボードが表示されます。

適当に立てた Django アプリケーションで面白いデータが取れませんでしたが、一つづつ説明します。

Response Times（左上）
全てのリクエストに対する平均、95%タイル、99%タイルのレスポンスタイムが表示されます。全体的に高くなっているとアプリケーションレベルでの異常を疑えます。95%タイル、99%タイルのみ高くなっている場合は特定のリクエスト、処理の異常を疑えます。
Request Per Minute（右上）
HTTP レスポンスステータスコード単位での 1分毎のリクエスト数が表示されます。リクエスト数が急増したことが原因でレスポンスタイムが悪くなっていればここを見れば判断できます。
Top Transactions for time Period（下）
URL パス単位での平均、95%タイルのレスポンスタイムが表示されます。特定のパスの処理が遅い時はここを見ればすぐに分かります。

この Transactions ダッシュボードではこのようなことを推察できます。もちろん、あくまでデフォルトのダッシュボードですので他にも原因特定するためのグラフをこのダッシュボード上に並べることも可能です。例えば、RDBMS のスロークエリログのグラフを並べて、リクエストのレスポンス性能低下と、SQL のレスポンスタイムを照らし合わせるようなことも可能です。