この記事は Mackerel アドベントカレンダー 2019 の25日目の記事です。僭越ながらトリを務めさせていただきます、株式会社はてな の Mackerelチーム・CRE（Customer Reliability Engineer）である a-know です。よろしくお願いします。メリークリスマス。
tl;dr
- 特定条件に合致するログ出力がどれくらいあったか、という情報を行数としてメトリック化し Mackerel に投稿するメトリックプラグインを作りました
- これと、以前書いた記事を組み合わせることで、従来までのログ監視 とは違ったログ監視手法を提案します
- メリークリスマス！
ログの出力状況をメトリック化する
今回このアドベントカレンダー記事を執筆するにあたり、以下のプラグインを書きました。
これは、特定条件に合致するログ出力がどれくらいあったか、という情報を行数としてメトリック化し 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 を仕込んでしばらく動かした様子をみてみましょう。
いいかんじですね。ここで、後述の作業のために、mackerel-plugin-log を仕込んだホストに対して専用のロールを付与しておきましょう。log-monitored とでもしておきます。
画像では2台のホストしかないですが、問題となるログが全体的にどれくらい出現しているかがパッと見で俯瞰できますね。
このメトリックに対して監視ルールを設定することも、当然ですが可能です。
一回のチェックでn行を超えるログの出力がm回連続で現れたらアラート、というかんじの挙動になります。
検出したログを log-monitored ロールグラフにアノテーションする
ここまでの内容だけだと、ログが出力されたことはわかるけど、具体的にどんな情報が出力されたのかがわかりませんね。これに対して、さきほど作成した log-monitored ロールのロールグラフに対してアノテーションすることで、できるだけ多くの情報をWebコンソール上で把握できるようにします。イメージ的には以下のようなもので、ここからは Mackerel のログ監視で検知された出力行をグラフにプロットする - えいのうにっき の再利用です。
さきほど 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 0 、0 以外での終了なら output 変数内の情報を echo して exit 0 しています。echo された output は、以降の action を実行する際に $MACKEREL_CHECK_MESSAGE に代入されます。
どちらにせよ exit 0 しているのは、check-log によるアラート発報は不要（させたくない）からです。mackerel-plugin-log により投稿されたメトリックに対するアラートだけで良しとします。
つづいて action のところ。この機能そのものについては以下の記事などを参照していただくとして、
bash -c '[ \"$MACKEREL_CHECK_MESSAGE\" != \"\" ]' && とすることで、$MACKEREL_CHECK_MESSAGE に検出されたログ情報が代入されている場合にのみ、以降の処理をおこなうようにしています。その処理については以前の内容と重複するのでここでは割愛しますが、 log-monitored ロールに対するアノテーションにしていたり、${MACKEREL_CHECK_MESSAGE:0:1000} とすることでアノテーション可能な文字列長に収まるようにしています。
以上のような感じで、mackerel-plugin-log と check-log の両方を同時に運用することで、log-monitored ロールグラフに対して検出ログ行をアノテーションできるようになりました。
check-log の方の設定内容は、もう少しスッキリできるといいですね......。。
さらに応用として
出力行数の閾値は Mackerel のWebコンソールから可能ですが、検出条件を変更するには各ホスト内の設定ファイルを編集する必要があります。これについては、検出条件を、例えば Mackerel のホストやロール、サービスのメタデータとして持たせておき、毎回のチェックのタイミングではメタデータから検出条件を取ってくる、といった仕組みにしておくと、ある程度柔軟に対応することができそうです。
また、ここでは検出したログ行をそのままアノテーションさせていますが、一旦どこかのログストレージに退避させておいて、Mackerel のグラフアノテーションにはその退避先のURLだけを投稿する。そのログがドンピシャで選択できるようなクエリをアノテーションするようにする。などとすると、実用面でもよろしいのではないかと思います。ぜひいろいろ工夫してみてもらえたらと思います。
先日開催された Mackerel 公式イベント、Mackerel DAY #2内で、@fujiwaraさんより、チェック監視の望ましくないところについてや、できればメトリック監視に代替するべきといったことについて言及がありました。
これについては僕も同感で、Mackerelのチェック監視は従来までの監視をおこなっていた方との架け橋的な存在だと思っています。「チェック監視結果をメトリックに変換するためのラッパー」みたいなのがあると面白いのかもしれないですね。
check-logはmetric監視で代替しづらいやつだなあ #mackerelio
— fujiwara (@fujiwara) 2019年12月23日
ということで、代替が難しいログ監視をメトリック化してみることに挑戦してみた、という内容でした。以上です、メリークリスマス！！
