ククログ

株式会社クリアコード > ククログ > #Fluentd トラブル相談 1 - Fluentdが数時間後にENOENTを出力する

#Fluentd トラブル相談 1 - Fluentdが数時間後にENOENTを出力する

クリアコードではFluentdのサポートを受け付けています。 サポートの内容としては、Fluentdのバージョンアップのアドバイスから、 トラブル発生時の原因調査まで様々です。 この新しい連載「Fluentdトラブル相談」では、日々のサポート業務の中から いくつか事例を取り上げて紹介していきます。

今回の記事で取り上げるのは、障害対応からの一事例です。

ご相談内容

サーバーからログを転送するのにFluentdを利用しています。 最近、Fluentdを起動してから数時間すると、突然ENOENTエラーが発生するようになりました。 必ず起きるわけではなく、再現条件もよくわからないので困っています。

この原因と解決方法を調査いただけないでしょうか。

解説 - なぜFluentdの障害調査は難しいのか

開発者の観点からすると、Fluentdの特性の一つは、長時間連続して稼働しつづける点にあります。 この類のプログラム(いわゆるデーモン)では状態の管理が常に問題になります。 ロジックの少しの不備が、長い時間をかけると膨大なズレを引き起こす事が少なくないためです。 サーバーのメモリを食い尽くすバグの原因が、 ほんの一箇所のオブジェクトの解放のし忘れであるといったことは実にありがちです。

一般論として、Unixコマンドのように実行してすぐに終了するプログラムであれば、 問題を再現させることも容易で、トラブルシューティングも早期に片付く傾向にあります。 一方、Fluentdの場合は、長い時間をかけた後で何かがおかしくなるケースがままあり、 障害調査も紆余曲折をたどる事が少なくありません。

どのように調査したのか

今回のケースでは、例外に伴うエラーメッセージがログに出力されていたので、 それをほとんど唯一のヒントとして調査を進めました。

ただ「調査」と一口に言っても、この類のケースでは「これをやればわかる」ということは少なく、 問題箇所の実装と関数の呼び出し関係から、考えられる仮説を洗い出していく地道な作業になります。 例えば、今回のエラー文言は次のようなものでした。

[warn] emit transaction failed: error_class=Errno::ENOENT error="No such file or directory"

サポートエンジニアにとっては、この無味乾燥な情報から、その背後にある 事情を"読む"のが重要であり、エラー発生時のプログラムの実行状態の推定から始まり、 そこから原因と対応策の大体の目星をつけていく事になります。 製品に対する理解の深さと根気強さが重要になる部分です。

今回の事例では、幸いエラー文言から原因のコード行をすぐに特定することが できました。 buf_file.rbの67行目のFileBufferChunk.mv()関数です。

67 def mv(path)
68   File.rename(@path, path)
69   @path = path
70 end

Fluentdは転送時にファイルをリネームします(Fluentdはファイル名でデータの 転送ステータスを管理するためです)。 今回のエラーがENOENT (No such file or directory) であることを踏まえると、 「Fluentdがあると思っていたバッファファイルが、いつのまにか消えてしまっていた」 というのが発生していた状況のようです。

問題は、どうやったらこんな状態が起こりうるのかです。 この部分は実装コードからパターンを考えるしかなく、様々な仮説を立てては、 その仮説を一つ一つ再現環境で試しては棄却していくという調査過程になりました。

  • 別のプログラムがバッファファイルを削除している。
  • Fluentdのバッファパスの生成ロジックに、流量が多い場合のみ顕現する不具合がある。
  • Fluentdが多重起動した結果、不整合が起きている。
  • ...

どのように解決したのか

今回は、発生したエラーをヒント起こりうるパターンを考えるうちに、 2つのFluentdのインスタンスが同じバッファパスを共有している場合に、 上記のエラーが発生することに思い至りました。例えばこんな状態です:

# fluentd1.conf
<match **>
 @type forward
 ...
 buffer_path /var/data/org.example.test/abc/
 ...
</match>

# fluentd2.conf
<match **>
 @type forward
 ...
 # fluentd1.confと同じパスを指定してしまっている!
 buffer_path /var/data/org.example.test/abc/
 ...
</match>

お客様に確認すると、1台の端末あたり十数台のFluentdを稼働されている状況で、 その中にたまたま設定のミスでかぶってしまっていたインスタンスがあることが 判明しました。

Fluentdには転送待ちデータをファイルシステム上に保持する機能があるのですが、 インスタンスが再起動するタイミングで、データを管理する"帳簿"がリフレッシュされます。 この時に、バッファ先のパスにあるファイルはすべて自分の担当分として読み直すため、 2つのインスタンスがパスを共有していると、複数のFluentdが同じファイルを転送しはじめてしまいます。

そこで、今回のケースでは、設定を変更してインスタンスごとにバッファパスが ユニークになるように調整いただくことで、無事にエラーが発生しなくなりました。

このように、障害が発生する正確なプロセスさえ突き止められれば、 大抵のケースではすんなりと解決までたどり着くことができます。

さいごに

クリアコードではこれまで5年以上にわたって、様々なお客様のFluentdの課題解決を行ってきました。

Fluentdに関するトラブルを抱えて困っている、運用の効率化に関するアドバイスが欲しいという方は、 ぜひこちらのお問い合わせフォームからご連絡ください。