Fluentdのin_tailプラグインで複数行のログをよむ方法

Fluentd v0.10.45からin_tailプラグインで複数行のログを読み込めるようになりました。これは今まで外部プラグイン(fluent-plugin-tail-multiline)として提供されていた機能をマージしたものになります。v0.10.50で複数行ログの読み込みに関するバグ修正が入っているので、この機能を使う場合はv0.10.50以上を使いましょう。

基本的な使い方

基本的にはドキュメントに書かれている通りですが、in_tailのformatオプションにmultilineを指定することで複数行モードになります。実際のパースのためのルールはformatN(Nは1から20)という名前のオプションで記述します。

以下は公式ドキュメントから引用したサンプルでRailsのログのパースする設定となります。

format multiline
format_firstline /^Started/
format1 /Started (?<method>[^ ]+) "(?<path>[^"]+)" for (?<host>[^ ]+) at (?<time>[^ ]+ [^ ]+ [^ ]+)\n/
format2 /Processing by (?<controller>[^\u0023]+)\u0023(?<controller_method>[^ ]+) as (?<format>[^ ]+?)\n/
format3 /(  Parameters: (?<parameters>[^ ]+)\n)?/
format4 /  Rendered (?<template>[^ ]+) within (?<layout>.+) \([\d\.]+ms\)\n/
format5 /Completed (?<code>[^ ]+) [^ ]+ in (?<runtime>[\d\.]+)ms \(Views: (?<view_runtime>[\d\.]+)ms \| ActiveRecord: (?<ar_runtime>[\d\.]+)ms\)/

複数行モードの設定にはいくつか注意しないといけないことがあります。

formatNは必ず1から初めて連続していなければいけません。
各formatには必ず1つは名前付きキャプチャが含まれてなければいけません。
同じ数値で複数回書いた場合は後に書かれたルールが有効になり、前のものは単純に無視されます(はまりポイントその1)。
正規表現のマッチにはRegexpのRegexp::MULTILINEが使われるため、.(ドット)は改行にもマッチするようになります(はまりポイントその2)。
正規表現に渡される文字列(ログ)は最後の改行が削除されているので完全にマッチさせる場合には最後に改行を含んではいけません(はまりポイントその3)。

サンプルの2行目にあるformat_firstlineオプションは正規表現のマッチを始める行を指定するもので、指定しないこともできます。このオプションについてはもう少し詳しく説明します。

format_firstlineの使い分け

format_firstlineを指定した場合、この正規表現にマッチした行からログをバッファに貯めはじめ、次にformat_firstlineにマッチしたときにそれまでのバッファをformatNでパースしてメッセージを生成します。逆に指定しなかった場合は、常に各行をバッファに貯めはじめ、formatNに完全にマッチした段階でメッセージを生成します。どちらもメッセージを生成した段階でバッファをクリアします。

自分はこの仕様を見た時にformat_firstlineは必要ないんじゃないかと思っていたのですが、よく考えると必要な場合もありました。典型的にはパースしたいログの終端が予測できない場合にformat_firstlineが必要です。

例えば、メッセージの先頭にタイムプスタンプをつけてログに残すけどメッセージに改行が含まれることを許す場合です。

Jun 28 19:45:00 message1 foo!
Jun 28 19:45:05 message2 foo!
bar!
baz!
Jun 28 19:45:10 message3 foo!

上記のようなログの場合は各メッセージの終端が予測できないため、 先頭にタイムスタンプが来るまで というルールになります。この場合にはformat_firstlineに^[A-Z][a-z]{2} \d{2} \d{2}:\d{2}:\d{2}とでもいれておけば良いでしょう。

逆にこうなるとformat_firstlineオプションは必須でこれだけで良いでは？という気持ちになりますが、実はそうではなくメリット・デメリットがあります。

format_firstlineのメリット・デメリット

format_firstlineオプションを使った場合は、その仕様上 次のメッセージが来るまで今のメッセージの終端がわからない ということになります。つまり、メッセージがログに出力されてもすぐにそのログがFluentdのメッセージとして送信されるわけではなく、次のログが出てくるまで遅延することになります。ちなみに、次のログが来る前にFluentdを落としたら「今バッファに溜まっているメッセージはロストしないのか」というのが気になりますが、終了前にformatNの判定が行われるためロストすることはありません。

一方でformat_firstlineを使わない場合はログの終端が予測できるため、formatNにマッチした段階でメッセージを送信が可能になり、遅延することはありません。逆にこちらのデメリットとしては、 間違った正規表現(formatN)を書いても気づけない という問題があります。formatNにマッチするまで「まだログが不完全」と判断されるため、永遠にバッファにたまり続けます。

また、どちらの場合も(複数行として出されるものの)各行が一度にログに出力されない場合は、途中までしかFluentdのin_tailが読み込んでいない可能性があり、終了時のパースで失敗していまうのでそのログはロストします。これは結構注意しなければいけないことで、複数行ログの場合は一度にログを出力できなければロストする可能性があることを念頭に置きましょう。

まとめ

Fluentdのin_tailプラグインで複数行ログの読む場合にはformat_firstlineを使う方法と使わない方法があり、それぞれにメリット・デメリットがあります。どちらのケースが適しているかはよく考えて選びましょう。ちなみに個人的にはformat_firstlineを使わない方法をよく使っています。

記事に間違いなどがあれば随時修正します。