2018.01.12

Prometheus でアプリのログを監視してアラートを発火する

レガシー環境のクラウド化およびセキュア化担当の D.M. です。

最近流行しはじめた監視ツール Prometheus は非常にシンプルで利用しやすいツールです。主に Docker やサービスディスカバリが利くクラウドとの相性がウリで Web にはいろいろな記事があがっています。特に AbemaTV、 freee が大々的に利用しているようです。

AbemaTV の事例
「Monitoring at AbemaTV」
http://sssslide.com/speakerdeck.com/nghialv/monitoring-at-abematv

freee の事例
「Prometheus 監視で変わるもの」
https://speakerdeck.com/sugitak/prometheus-jian-shi-debian-warumofalse

基本的な事柄の詳細は他の記事に譲りますが、その代わりに Prometheus の基本的なデータの流れを示す図を描きました。（このぐらいが理解できていればこの記事を読むぐらいのことはだいたい大丈夫です）

今回はやや発展的に、「Prometheus でアプリのログを監視し、ある条件でアラートを発火する」ことをやってみたいと思います。

Prometheus の好きなところ

個人的に推しのポイントを書きます。

・golang なのでだいたいどこでもすぐ動く。

インストールはほぼダウンロード＋解凍だけというのは最高のメリットでしょう。 yum や rpm や依存関係などでハマることが全くないため初めての人でも簡単にはじめることができます。もちろん Docker Image もあるので、導入のコストは誰にとっても小さいものと言えると思います。

・エージェントの Exporter の監視データはテキストのキーバリューが HTTP で送信されるですぐ見られる。

Prometheus は PULL 型の監視ツールです。すなわち各 VM で Exporter というエージェントが動いていて、そこに HTTP でアクセスしてメトリクスデータを取得するスタイル。 Nagios 、 Zabbix と同じタイプです。取得できるデータは CPU や DISK などの状態でいわゆる普通に監視したいものが Exporter として多数提供されています。

以前は PULL 型の Nagios は数百台の大規模サーバ群に弱いという記事を読んだことがありましたが、Prometheus はある説によると 1 万台でも動くらしい。

PULL 型 PUSH 型の比較はこちらが詳しいです。
http://yasuharu519.hatenablog.com/entry/2017/12/16/215855

・独自言語 PromQL で多彩な条件が書ける。

Prometheus は取得したメトリクスデータを SQL ではなく独自言語 PromQL で操作できます。なんだよまた独自言語かよと思う人が大半かと思いますが、これは一長一短で SQL よりシンプルです。生データ自体がほぼキーバリュー形式なので少し凝っても秘伝のたれ的な記述にはならないと思ってます。

文法については以下の記事がよくまとまっているので細かいことを実現したい場合は参考になると思います。

「サンプルで学ぶ！PromQLで自在にグラフを描こう (Prometheus + Grafana)」
https://qiita.com/nekonok/items/4390a2db8be34da9d238

Grafuna と簡単に連携できるので最近のツールでは当たり前となった綺麗なグラフでの可視化も普通にできます。また Alertmanager でアラート条件を決めたりと器用にカスタマイズ可能です。

Prometheus の弱いところ

・完璧な冗長性を担保する仕組みではない。

2 台立てると同じデータを同期するようなことは設計的に意図されていません。別個に 2 台立てて、それぞれが別々にデータを収集するという雑な方法で冗長性を担保するという思想です。まあ内部のサーバメトリクスなので 2 台で大差が出ることはあまりないかと思いますが、厳密さを求められるユースケースでは注意が必要です。

アプリのログを監視する

さあここからが本題です。

Prometheus のインストール

11月に Prometheus はヴァージョン 2 になりましたのでそれを前提で進めます。

公式はこちら。ダウンロードすればすぐに動作させることができます。
https://prometheus.io/

$ wget https://github.com/prometheus/prometheus/releases/download/v2.0.0/prometheus-2.0.0.linux-amd64.tar.gz
$ tar -xzvf prometheus-*.gz
$ cd prometheus-*
$ ./prometheus –config.file=prometheus.yml

これだけで動きます！
prometheus.yml は grok_exporter 、 AlertManager と連携する設定があるので後半で解説します。

アプリのログを監視できる grok_exporter

前述した既存で提供されている Exporter は OS や MySQL などの特定のミドルウェアのメトリクスに最適化されています。自分で作ったバッチや Web アプリのメトリクスを取ろうと思ったら、ログをパースして独自のメトリクスを定義しなければなりません。一般的にアプリのログというのは非構造化データ、つまりはそれぞれが異なる形式です。最近は解析しやすいように JSON 形式ログなどが増えたりしていますが、レガシーシステムなどを含めるとさまざまな形式が想定できるかと思います。

この非構造化ログのパースに対応できるのが grok_exporter です。ベースとなる Grok は、非構造化ログデータを構造化されクエリ可能なものに解析するツールで、 ElasticSearch の Logstash でアプリのログデータを取得するために使用されていているものです。その利便性を Prometheus のメトリクスとして抽出するためのツールが grok_exporter なのです。

公式はこちらです。細かい仕様の確認の際はこの README を読みましょう、
https://github.com/fstab/grok_exporter/blob/master/README.md

grok_exporter のインストール

ここから自分の環境に合わせたバイナリーをとってきて解凍すれば動きます。とっても簡単！
https://github.com/fstab/grok_exporter/releases

$ wget https://github.com/fstab/grok_exporter/releases/download/v0.2.3/grok_exporter-0.2.3.linux-amd64.zip
$ unzip grok_exporter-0.2.3.linux-amd64.zip
$ cd grok*
# 設定ファイルを定義（後述）
$ vi ./app_log_config.yml
# 起動。 systemctl などでデーモン化したほうがよいです
$ ./grok_exporter -config ./app_log_config.yml

設定ファイル app_log_config.yml は以下のようになりました。

global:
  config_version: 2
input:
  # ファイルから読む設定。 stdin も可能。
  type: file
  # 読み込むログのパス。1つしか定義できない。複数は別 exporter に分ける
  path: /var/log/gmo/app.log
  # 読み込みのタイミングで毎回全部読むか追加部分だけ読むかの設定。 
  # false で追加部分を tail してくれる。
  readall: false 
grok:
  # ログパース用の正規表現の塊があるところ。デフォルトで結構ある。
  patterns_dir: ./patterns
  # とくに今回だけ定義したい変数。
  # 共通変数は patterns dir のほうに入れる。
  additional_patterns:
  - 'DATETIME %{YEAR:php_year}-%{MONTHNUM:php_month}-%{MONTHDAY:php_day} %{TIME:php_time}'
  - 'ERROR_MESSAGE .*in'
  - 'ERROR_SRC_PATH Z.*'
metrics:
  # grok_exporter が行う加工処理。
  # 詳細は上述の README を参照。
  # counterは回数のカウント。
  - type: counter 
  name: error_message
  help: count error messages in app.log.
  # 正規表現の本丸です
  match: '%{DATETIME:datetime}\s+\[%{IP}\]\[.*\]\[%{NUMBER}\]\[.*\]\[.*\]\s+URL=%{URI:uri}\s+%{ERROR_MESSAGE:msg}.*%{ERROR_SRC_PATH:path}'
  labels: error
  # ここがメトリクスとして出力する値です。
  # 実際 prometheus が読み込みます。
  error_message: '{{.uri}} {{.msg}} {{.path}}' 
  # この時間でcounterがクリアされます。
  retention: 1m 
server:
  # grok_exporter を立ち上げるポート。
  # 複数のログを読むときはここを変更して別プロセスで立てる。
  port: 9144

この metrics の部分をここから詳細に解説していきます。

[grok_exporter利用例] Web アプリのログを Grok でパースしてみる

今回は grok_exporter で Web アプリが出しているログの API エラーの行をパースして、エラー回数をカウントするメトリクスを生成してみます。

以下は API への通信が失敗したときに出るエラーログの例です。以下のような構造をしています。

/var/log/gmo/app.log

2017-11-28 10:16:23 [192.168.2.20][5a1cb8bf29e69][123456][error][Exception] URL=http://www.example.com/top ‘Exception’ with message ‘fopen(http://api.example.com/api/get): failed to open stream: HTTP request failed! ‘ in /data/gmo/src/20171227222346Z/common/HttpClientUtil.php:123

このログを grok_exporter で認識させるには以下のような正規表現を設定ファイルに記述してパースします。今回ここだけはある種の魔術的な正規表現になります。一番独自の作りこみ箇所です。

上記の起動コマンドで読み込む ./app_log_config.yml 内の metrics の match パターン定義に以下を設定します。

%{DATETIME:datetime}\s+\[%{IP}\]\[.*\]\[%{NUMBER}\]\[.*\]\[.*\]\s+URL=%{URI:uri}\s+%{ERROR_MESSAGE:msg}.*%{ERROR_SRC_PATH:path}

IP など一般的に利用できる正規表現は patterns フォルダに含まれていますのでそのまま利用できます。ただ独自の正規表現を定義したい場合は additional_patterns の箇所で以下のカスタム変数を作成できます。

– ‘DATETIME %{YEAR:year}-%{MONTHNUM:month}-%{MONTHDAY:day} %{TIME:time}’
– ‘ERROR_MESSAGE .*in’
– ‘ERROR_SRC_PATH Z.*’

これでログをパースする正規表現が定義できました。

grok_exporter の良いところ

あらかじめ定義された正規表現の資産が使えます。デフォルトで使える正規表現は、変数として pettern フォルダの grok_pettern ファイルに入ってます。シンプルなところですと、 YEAR とか MONTHNUM とか MONTHDAY など、また syslog 、 apache などに向けた 100 個以上の変数が正規表現で備わっているので、カスタムパターンで拡張するのは簡単です。

Grok のデバッグ

ただ Grok のパターン定義は結構デバッグがやりづらいです。自分で定義したパターンでログがパースできない場合、どこが間違っているのかは grok_exporter のログでは正直さっぱりわかりません。

そこで役に立つのが以下のサイトです。

Grok Debugger
https://grokdebug.herokuapp.com/

これはもともと ElasticSearch の Grok 用のテストサイトで、自分の書いた正規表現のテストするためのものです。テキストを入力直後にコンパイルされるため結果は一瞬で表示されます。1単語ずつパースされるかテストすることができます。

また Discover の画面では、ログを与えるとパターンを推測して自動生成もしてくれます。ただ怪しい結果になるので自分でチューニングが必要です。

パターンのリストも画面で確認できます。

先ほどのログのパースの結果です。Prometheus 側にはこの値を元にした値を連携します。

{
  "datetime": [
    [
      "2017-11-28 10:16:23"
    ]
  ],
  "year": [
    [
      "2017"
    ]
  ],
  "month": [
    [
      "11"
    ]
  ],
  "day": [
    [
      "28"
    ]
  ],
  "time": [
    [
      "10:16:23"
    ]
  ],
  "HOUR": [
    [
      "10"
    ]
  ],
  "MINUTE": [
    [
      "16"
    ]
  ],
  "SECOND": [
    [
      "23"
    ]
  ],
  "IP": [
    [
      "192.168.2.20",
      null
    ]
  ],
  "IPV6": [
    [
      null,
      null
    ]
  ],
  "IPV4": [
    [
      "192.168.2.20",
      null
    ]
  ],
  "NUMBER": [
    [
      "123456"
    ]
  ],
  "BASE10NUM": [
    [
      "123456"
    ]
  ],
  "uri": [
    [
      "http://www.example.com/top"
    ]
  ],
  "URIPROTO": [
    [
      "http"
    ]
  ],
  "USER": [
    [
      null
    ]
  ],
  "USERNAME": [
    [
      null
    ]
  ],
  "URIHOST": [
    [
      "www.example.com"
    ]
  ],
  "IPORHOST": [
    [
      "www.example.com"
    ]
  ],
  "HOSTNAME": [
    [
      "www.example.com"
    ]
  ],
  "port": [
    [
      null
    ]
  ],
  "URIPATHPARAM": [
    [
      "/top"
    ]
  ],
  "URIPATH": [
    [
      "/top"
    ]
  ],
  "URIPARAM": [
    [
      null
    ]
  ],
  "msg": [
    [
      "'Exception' with message 'fopen(http://api.example.com/api/get): failed to open stream: HTTP request failed! ' in"
    ]
  ],
  "path": [
    [
      "Z/common/HttpClientUtil.php:123"
    ]
  ]
}

今回 grok_exporter のメトリクスで使う変数は url と msg と path にしました。これらを統合して1つのエラーとみなし、 counter 機能で個数をカウントして Prometheus に連携します。

上述の設定ファイルを再掲します。ログから match した値を error_message という項目でメトリクスとして出力します。 retension 1m としたので1分間でカウントをクリアして記録します。

metrics:
  - type: counter
  name: error_count
  help: error message.
  match: '%{DATETIME:datetime}\s+\[%{IP}\]\[.*\]\[%{NUMBER}\]\[.*\]\[.*\]\s+URL=%{URI:uri}\s+%{ERROR_MESSAGE:msg}.*%{ERROR_SRC_PATH:path}'
  labels:
  error_message: '{{.uri}} {{.msg}} {{.path}}'
  retention: 1m

例として、grok_exporter の出力するメトリクスのレスポンスデータは以下ようになります。 “error_message” の “failed to open stream” が 4 回発生しましたという結果です。

error_message{error_message=”http://www.example.com/top exception ‘Exception’ with message ‘fopen(http://api.example.com/api/get): failed to open stream: HTTP request failed! ‘ in Z/common/HttpClientUtil.php:123″} 4

grok_exporter の制約

イケテナイところも結構あります。

まず、1つの grok_exporter インスタンスは1つのログファイルだけしか監視できないという点。1つ以上のファイルを監視したい場合は、別の設定ファイルかつ別のポートで grok_exporter インスタンスを起動しなければいけないです。

そして Prometheus 側も複数の grok_exporter を別々に読み込むように設定する必要があります。

また、ログが１つの行内に同じ構造を持つ場合にのみ適しています。ログの1単位は改行ごとに区切られているようで、複数の行を１つの単位として扱うことはちょっと試した限りではできませんでした。

Prometheus が grok_exporter からメトリクスデータを受け取り、アラート条件にかける

ここからは grok_expoter ではなく Prometheus の設定です。（やっとはじめのインストールの箇所に戻ってきました）

Prometheus が grok_exporter へデータを取りにいく設定は prometheus.xml で以下のように定義します。以下の設定でログを出すサーバ ap01 の grok_exporter を 15s の間隔でスクレイピングします。
また AlertManager は同じ localhost の 9093 で起動させます。（これは後に補足解説します）

global:
  scrape_interval: 15s
  evaluation_interval: 15s

alerting:
  alertmanagers:
  - static_configs:
  - targets: ['localhost:9093']

# アラート発火のルールはver2ではYMLで書きます
rule_files:
  - "./alert_rules.yml"

scrape_configs:
  - job_name: 'ap01'
  static_configs:
  - targets: ['192.168.1.11:9144']

アラートの条件を決める alert_rules.yml は以下の内容です。今回のアラート発生条件は expr: error_message > 1 で、 for: 1s つまり、 error_message が1回以上 1s 以上発生した場合ということになります。

groups:
- name: ap_error
  rules:
  - alert: Error
    expr: error_message > 1
    for: 1s
    labels:
      severity: warn
    annotations:
      summary: an error happened.

Alertmanager からアラートを飛ばしてみる

Alertmanager は Golang で書かれた Prometheus のツールで、別のプロセスで動きます。
メールでアラートする例はよく記事にあるので、今回は Slack 通知をしてみます。

Alertmanager のインストールは例によってダウンロード＋解凍だけ。とても簡単です。

$ wget https://github.com/prometheus/alertmanager/releases/download/v0.12.0/alertmanager-0.12.0.linux-amd64.tar.gz
$ tar -xzvf alertmanager-0.12.0.linux-amd64.tar.gz
$ cd alertmanager-0.12.0.linux-amd64
$ alertmanager -config.file ./alert_config.yml

ポートは9093で立ち上がります。
設定には alert_config.yml を作成します。

Slack 通知で書くのは以下の内容だけです。発生したら30秒に1回通知します。
slack_api_url は Slack Webhook から発行したものを貼ります。
channel は通知したいチャンネルです。

global:
  slack_api_url: 'https://hooks.slack.com/services/XXXXXXX/YYYYYY/ZZZZZZZ'

route:
  group_wait: 30s
  group_interval: 30s
  repeat_interval: 30s
  receiver: default

receivers:
- name: 'default'
  slack_configs:
  - channel: '#api-test'

簡単に通知できました！

最後に

次世代システム研究室では、アプリケーション開発や設計を行うアーキテクトを募集しています。アプリケーション開発者の方、次世代システム研究室にご興味を持って頂ける方がいらっしゃいましたら、ぜひ募集職種一覧からご応募をお願いします。

グループ研究開発本部の最新情報をTwitterで配信中です。ぜひフォローください。

Follow @GMO_RD

Prometheus でアプリのログを監視してアラートを発火する

Prometheus の好きなところ

Prometheus の弱いところ

アプリのログを監視する

Prometheus のインストール

アプリのログを監視できる grok_exporter

grok_exporter のインストール

[grok_exporter利用例] Web アプリのログを Grok でパースしてみる

grok_exporter の良いところ

Grok のデバッグ

grok_exporter の制約

Prometheus が grok_exporter からメトリクスデータを受け取り、アラート条件にかける

Alertmanager からアラートを飛ばしてみる

最後に

最新の記事

採用情報

インターンシップ

インタビュー

Prometheus でアプリのログを監視してアラートを発火する

Prometheus の好きなところ

Prometheus の弱いところ

アプリのログを監視する

Prometheus のインストール

アプリのログを監視できる grok_exporter

grok_exporter のインストール

[grok_exporter利用例] Web アプリのログを Grok でパースしてみる

grok_exporter の良いところ

Grok のデバッグ

grok_exporter の制約

Prometheus が grok_exporter からメトリクスデータを受け取り、アラート条件にかける

Alertmanager からアラートを飛ばしてみる

最後に

タグ

最新の記事

採用情報

インターンシップ

インタビュー