えいのうにっき

誤字脱字・記述の誤りなどはこちら https://github.com/a-know/blog.a-know.me へお願いします

Mackerelを用いた、メトリック化したログに対する監視のご提案

この記事は Mackerel アドベントカレンダー 2019 の25日目の記事です。僭越ながらトリを務めさせていただきます、株式会社はてな の Mackerelチーム・CRE(Customer Reliability Engineer)である a-know です。よろしくお願いします。メリークリスマス。

tl;dr

  • 特定条件に合致するログ出力がどれくらいあったか、という情報を行数としてメトリック化し Mackerel に投稿するメトリックプラグインを作りました
  • これと、以前書いた記事を組み合わせることで、従来までのログ監視 とは違ったログ監視手法を提案します
  • メリークリスマス!

ログの出力状況をメトリック化する

今回このアドベントカレンダー記事を執筆するにあたり、以下のプラグインを書きました。

github.com

これは、特定条件に合致するログ出力がどれくらいあったか、という情報を行数としてメトリック化し Mackerel に投稿するためのメトリックプラグインです。

これを利用するには、まずこの監視をおこないたいホスト内にプラグインをインストールをする必要があります。このプラグインサードパーティプラグインレジストリに対応していますので、ホスト内で以下のコマンドを実行してもらうことで簡単にインストール可能です。

mkr plugin install mackerel-plugin-log

(このコマンドでインストールをおこなうには、別途、公式CLIツールである mkrのインストールがおこなわれている必要はあります。)

続いて、このプラグインを mackerel-agent が利用するための設定として、mackerel-agent.conf に以下のように記述し、エージェントを再起動します。

[plugin.metrics.log-detect]
command = ["/path/to/mackerel-plugin-log", "--file", "/path/to/app.log", "--pattern", "ERROR", "--exclude", "retry"]

この設定内容だと、/path/to/app.log を毎分チェックし、 ERROR を含むが retry を含まないログ出力の行数をメトリックとして Mackerel に投稿する」という挙動になります。

プラグインに対して指定できるオプションは、以下のようなかんじです。

 $ /opt/mackerel-agent/plugins/bin/mackerel-plugin-log -h
 Usage:
   mackerel-plugin-log [OPTIONS]
 
 Application Options:
       --metric-key-prefix=PREFIX    Metric key prefix
   -f, --file=FILE                   Path to log file
   -p, --pattern=PAT                 Pattern to search for. If specified multiple, they will be treated together with the AND
                                     operator
   -E, --exclude=PAT                 Pattern to exclude from matching
   -i, --icase                       Run a case insensitive match
       --encoding=                   Encoding of log file
 
 Help Options:
   -h, --help                        Show this help message

mattnさんも大好きなプラグインでもある check-log で指定できるものからだいぶ差っ引いたかんじですね(雑)。

mackerel-plugin-log を仕込んでしばらく動かした様子をみてみましょう。

f:id:a-know:20191211111115p:plain
mackerel-plugin-log により描画された、ホスト毎の検出ログ件数のグラフ。

いいかんじですね。ここで、後述の作業のために、mackerel-plugin-log を仕込んだホストに対して専用のロールを付与しておきましょう。log-monitored とでもしておきます。

f:id:a-know:20191211111343p:plain
log-monitored ロールのグラフでログ検出行数のグラフを表示しているようす。

画像では2台のホストしかないですが、問題となるログが全体的にどれくらい出現しているかがパッと見で俯瞰できますね。

このメトリックに対して監視ルールを設定することも、当然ですが可能です。

f:id:a-know:20191211111611p:plain

一回のチェックでn行を超えるログの出力がm回連続で現れたらアラート、というかんじの挙動になります。

検出したログを log-monitored ロールグラフにアノテーションする

ここまでの内容だけだと、ログが出力されたことはわかるけど、具体的にどんな情報が出力されたのかがわかりませんね。これに対して、さきほど作成した log-monitored ロールのロールグラフに対してアノテーションすることで、できるだけ多くの情報をWebコンソール上で把握できるようにします。イメージ的には以下のようなもので、ここからは Mackerel のログ監視で検知された出力行をグラフにプロットする - えいのうにっき の再利用です。

f:id:a-know:20191211112054p:plain

さきほど mackerel-plugin-log の設定を仕込んだホストに対して、以下の設定も追加します。公式チェックプラグインの check-log を使いますので、未インストールの場合はまだインストールから実施してください( チェック監視に公式チェックプラグイン集を使う - Mackerel ヘルプ )。

 [plugin.checks.applog]
 command = '''
 output=$(check-log --file /path/to/app.log --pattern "ERROR" --exclude "retry" --return); if test $? -eq 0; then exit 0; else echo "$output"; exit 0; fi
 '''
 action = { command = "bash -c '[ \"$MACKEREL_CHECK_MESSAGE\" != \"\" ]' && mkr annotations create --service grass-graph --role log-monitored --from `date +%s` --to `date +%s` --title plugin.checks.applog --description \"${MACKEREL_CHECK_MESSAGE:0:1000}\"" }

ちょっとシェル芸ぽくなっちゃってますね。細かく説明します。

output=$(check-log --file /path/to/app.log --pattern "ERROR" --exclude "retry" --return) の部分は、mackerel-plugin-log でおこなっているログファイルへの監視と同内容のチェックをおこなうためのものです。 --return オプションを指定することで、検出されたログ情報を標準出力として得て、それを output 変数に代入しています。

if test $? -eq 0; then exit 0; else echo "$output"; exit 0; fi の部分は、さきほどの output を得るためのコマンドの終了ステータスをもとに条件分岐していて、 0 終了なら特になにもせずそのまま exit 00 以外での終了なら output 変数内の情報を echo して exit 0 しています。echo された output は、以降の action を実行する際に $MACKEREL_CHECK_MESSAGE に代入されます。 どちらにせよ exit 0 しているのは、check-log によるアラート発報は不要(させたくない)からです。mackerel-plugin-log により投稿されたメトリックに対するアラートだけで良しとします。

つづいて action のところ。この機能そのものについては以下の記事などを参照していただくとして、

mackerel.io

bash -c '[ \"$MACKEREL_CHECK_MESSAGE\" != \"\" ]' && とすることで、$MACKEREL_CHECK_MESSAGE に検出されたログ情報が代入されている場合にのみ、以降の処理をおこなうようにしています。その処理については以前の内容と重複するのでここでは割愛しますが、 log-monitored ロールに対するアノテーションにしていたり、${MACKEREL_CHECK_MESSAGE:0:1000} とすることでアノテーション可能な文字列長に収まるようにしています。

以上のような感じで、mackerel-plugin-log と check-log の両方を同時に運用することで、log-monitored ロールグラフに対して検出ログ行をアノテーションできるようになりました。

f:id:a-know:20191211112054p:plain

check-log の方の設定内容は、もう少しスッキリできるといいですね......。。

さらに応用として

出力行数の閾値は Mackerel のWebコンソールから可能ですが、検出条件を変更するには各ホスト内の設定ファイルを編集する必要があります。これについては、検出条件を、例えば Mackerel のホストやロール、サービスのメタデータとして持たせておき、毎回のチェックのタイミングではメタデータから検出条件を取ってくる、といった仕組みにしておくと、ある程度柔軟に対応することができそうです。

mackerel.io

また、ここでは検出したログ行をそのままアノテーションさせていますが、一旦どこかのログストレージに退避させておいて、Mackerel のグラフアノテーションにはその退避先のURLだけを投稿する。そのログがドンピシャで選択できるようなクエリをアノテーションするようにする。などとすると、実用面でもよろしいのではないかと思います。ぜひいろいろ工夫してみてもらえたらと思います。

先日開催された Mackerel 公式イベント、Mackerel DAY #2内で、@fujiwaraさんより、チェック監視の望ましくないところについてや、できればメトリック監視に代替するべきといったことについて言及がありました。

これについては僕も同感で、Mackerelのチェック監視は従来までの監視をおこなっていた方との架け橋的な存在だと思っています。「チェック監視結果をメトリックに変換するためのラッパー」みたいなのがあると面白いのかもしれないですね。

ということで、代替が難しいログ監視をメトリック化してみることに挑戦してみた、という内容でした。以上です、メリークリスマス!!