Fluentdのロギング #Fluentd

Fluentdの公式ドキュメントにloggingのページがあるんですが，まだ英語しかなく，運用の話を聞いてるとここに書いてあることで解決出来るケースがいくつかあったので，とりあえず日本語で記事にしておきます．

プラグイン毎のログレベル

昔のFluentdはグローバルに一つしかログレベルを設定出来なかったんですが，今ならプラグイン毎に設定出来ます．プラグインが対応している必要がありますが，まぁ今時のプラグインや広くつかわれているやつはほとんど対応していると思います．

<source>
  type tail
  # ... その他の設定
  log_level error
</source>

in_tailプラグインはログにマッチしない行があったらwarnでメッセージを出しますが，そういうbrokenな行があることが分かっていてログを出さずに無視して欲しい，というような場合に有効です．
その他にも，あるプラグインだけデバッグモードで走らせたい，みたいなことが出来るようになります．

ログのスタックトレースの抑制

Fluentdはデフォルトでログにスタックトレースを含みます．

2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:154:rescue in emit_stream: emit transaction failed  error_class = RuntimeError error = #<RuntimeError: syslog>
  2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/out_stdout.rb:43:in `emit'
  [snip]
  2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/in_object_space.rb:63:in `run'
2013-12-04 15:05:53 +0900 [error]: plugin/in_object_space.rb:113:rescue in on_timer: object space failed to emit error = "foo.bar" error_class = "RuntimeError" tag = "foo" record = "{ ...}"
2013-12-04 15:05:55 +0900 [warn]: fluent/engine.rb:154:rescue in emit_stream: emit transaction failed  error_class = RuntimeError error = #<RuntimeError: syslog>
  2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/o/2.0.0/gems/cool.io-1.1.1/lib/cool.io/loop.rb:96:in `run'
  [snip]
2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/in_object_space.rb:63:in `run'

これは運用・開発両面から，問題が起きた時にどこが原因かすぐ突き止めるためなんですが，プラグインがバグっていたり，ネットワークが不安定な環境だと，エラーが連続で起きてログが膨れる可能性があります．
このような場合に備えて，syslogのように同じメッセージを抑制する--suppress-repeated-stacktraceというオプションがあります．これを渡すと，最初エラーが起きた時のスタックトレースは表示されますが，それ以降は同じスタックトレースは表示されなくなります．

2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:154:rescue in emit_stream: emit transaction failed  error_class = RuntimeError error = #<RuntimeError: syslog>
  2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/o/2.0.0/gems/cool.io-1.1.1/lib/cool.io/loop.rb:96:in `run'
  [snip]
  2013-12-04 15:05:53 +0900 [warn]: fluent/engine.rb:140:emit_stream: /Users/repeatedly/devel/fluent/fluentd/lib/fluent/plugin/in_object_space.rb:63:in `run'
2013-12-04 15:05:53 +0900 [error]: plugin/in_object_space.rb:113:rescue in on_timer: object space failed to emit error = "foo.bar" error_class = "RuntimeError" tag = "foo" record = "{ ...}"
2013-12-04 15:05:55 +0900 [warn]: fluent/engine.rb:154:rescue in emit_stream: emit transaction failed  error_class = RuntimeError error = #<RuntimeError: syslog>
  2013-12-04 15:05:55 +0900 [warn]: plugin/in_object_space.rb:111:on_timer: suppressed same stacktrace

repeatedとオプションについてる通り，これは同じエラーが続く限り抑制されます．別のエラーが起きたら，また再度スタックトレースを表示します．実装として，各スレッド毎に以前起きたエラーを保存しているので，かなりのログを抑制出来るんじゃないかと思います．

v0.12からデフォルトでtrue

v0.10ではデフォルトでは抑制しないんですが，Fluentdも広まってきましたし，有名なプラグインもこなれてきました．なので，v0.12からはデフォルトで抑制されるようになります．

Pull Request #446 · fluent/fluentd

逆に開発時とかで冗長にログが欲しい場合には

fluentd --suppress-repeated-stacktrace false

のようにfalseをオプションに渡してあげれば，抑制が解除されます．

Fluentd自身のログをプラグインで扱う

Fluentdのコアやプラグインが吐くログはイベントになっているので，Outputプラグインで処理することが出来ます．タグはfluentと，infoやerrorなどのログレベルが連結されたものです．errorやwarnのログを監視することで，プラグインや環境の異常に早く気づくことが出来ます．
以下は，アプリケーションサーバのFluentdでログにホスト情報を付加し，モニタリング用の集計サーバで警告以上のログを抽出してIRCに投げる例です．

アプリケーションサーバ側

<match fluent.**>
  type record_modifier
  tag internal.message
  host ${hostname}  # どこで発生したかを特定するためにホストネームを追加
  include_tag_key   # 後々grepで判別するためタグを付加
  tag_key original_tag
</match>

<match internal.message>
  type forward
  <server>
    # 集約サーバの設定
  </server>
</match>

集計サーバ側

<source>
  type forward
</source>

# warn以上のログだけ抽出する
<match internal.message>
  type grep
  regexp1 original_tag fluent.(warn|error|fatal)
  add_tag_prefix filtered
</match>

# 今回の例ではIRC. もちろん他のプラグインでもOK
<match filtered.internal.message>
  type irc
  host irc.domain
  channel notify
  message notice: %s [%s] @%s %s
  out_keys original_tag,time,host,message
</match>

最後に…

いくつかプロダクションで使えるFluentd本体のログの扱いについて書きました．公式ドキュメント，日本語はコミュニティベースで翻訳しているため，常に最新とは限りません．この辺今どうなのかな？と思ったら英語版を確認してもらえると助かりますし，「俺も翻訳に参加してやるぜ！」って人はfluentd-docsのリポジトリにPull Reuestしてもらえると助かります！