#Fluentd トラブル相談 2 - Fluentdの再起動時にEADDRINUSEが発生する - 2021-10-07

第2回目のFluentdトラブル相談で取り上げるのは、Fluentdでサービスのログを転送する際に発生したトラブルです。

ご相談内容

Fluentdを使って、自社サービスのログを中央のサーバーに収集しています。

困っていることとして、ログ収集サーバーのFluentdを再起動すると、EADDRINUSEというエラーが発生することがあります。発生頻度は時々で、必ず発生するわけでもありません。また、Fluentdを一旦すべて終了してから再起動すると復旧します。

毎日の運用上、非常に煩わしいので、このエラーがどうして起きているのか調査いただけないでしょうか。

解説 - ネットワーク設計は慎重に！

Fluentdに関するトラブル相談でとても多いのが、転送にまつわる不具合です。転送処理が突然止まってしまった、データを確認すると欠損が見つかった、 Fluentdのノードが動いているはずなのに落ちていると判定される...などなどです。

トラブルの原因がFluentdの実装の不具合であることももちろんありますが、現実の多くのトラブルはサーバーやFluentdの設定ミスに起因しており、設計時にネットワーク設計の考慮点を詰めきれてないことが原因であることが少なくありません。

どのように調査したのか

今回のご相談について詳細をヒアリングすると、実際に発生していた例外は次のようなものでした。

<Errno::EADDRINUSE: Address already in use - bind(2) for "0.0.0.0" port 24224>

この例外は、Fluentdが24224番ポートを開こうとしたところ既に別の誰かが使っていたことを表します。 24224番はForwardプラグインがデフォルトで受信用に使うポート番号なので、例外が起きたのはin_forwardの初期化の段階であることことまでは容易に推測できます。問題は「誰がこのポートを使っていたのか？」です。この点は残されたメッセージからは分からないので、実際のサーバーで調査する必要があります。

この調査のときに便利なのがlsofコマンドです。これはLinuxサーバーに標準搭載されている診断ツールで、誰がどのファイルディスクリプタを開いているかを確認することができます。

例えば、ネットワークポートを開いているプログラムの一覧は、次のように打てば確認できます。

$ sudo lsof -i

Fluentd自身がポートをブロックするケース

もし、24224番ポートを使っているのが他のデーモンプログラムであれば解決は単純で、ポートがかぶらないように調整すれば済みます。

今回の相談ケースが興味深いのは、実は24224番ポートを使っているのがFluentd自身だったという点でした。実際に、次に障害が発生した時にlsofでサーバーの状況を確認いただくと、おおむね次のような結果が得られました。

$ sudo lsof -i
COMMAND     PID     USER   FD   TYPE  DEVICE SIZE/OFF NODE NAME
...
ruby      49680   fluentd   4u  IPv4 1314461      0t0  UDP *:24224
...

一見すると「どうしたらこうなるんだろう？」と不思議に思われるかもしれませんが、この手の「Fluentd自身がFluentdが使うポートを占有してしまう」という事例は、トラブルシューティングの現場では割とよく見かけます。

この場合、原因としては大きく２つのパターンに分かれます：

Fluentdが多重起動しているケース。 Fluentdの前のプロセスが何らかの理由で残ってしまっていて、再起動時に後続するプロセスをブロックしてしまうというパターンです。この場合は、起動スクリプトを調整するなりして、多重起動を防止すれば解決できます。
サーバーのエフェメラルポートの設定がおかしいケース。 Linuxは接続ポートを指定しない場合、所定のポートから空いているものをとって使います。この自由に使えるポートの範囲は多くの環境では32768-60999ですが、環境によってはこの値を変更している場合があります。エフェメラルポートの範囲にFluentdがlistenするポートが含まれていると、受信用のポートが別の用途に先取りされてEADDRINUSEが発生する可能性があります。

この場合の切り分けは単純で、問題が発生している環境で、次のコマンドを打てばどちらが原因かが分かります¹。

$ cat /proc/sys/net/ipv4/ip_local_port_range
1024 60999

どのように解決したのか

今回の相談は「Fluentdが利用する24224番が誤ってエフェメラルポートに含まれてしまっている」という(2)のパターンでした。ここまで分かれば解決策は単純で、対象サーバーの/etc/sysctl.confを編集して次の内容に変更いただくことで、無事にトラブルを解決することができました。

net.ipv4.ip_local_port_range = 32768 60999

このように、Fluentdをデプロイする際には、サーバーのネットワーク設定もあわせて確認しておく必要があります。

サポートのご依頼を受け付けてます！

クリアコードではFluentdのサポートサービスを提供しています。 Fluentdに関するトラブルを抱えて困っている等ありましたら、ぜひこちらのお問い合わせフォームからご連絡ください。

出力される最初の数字がエフェメラルポートの開始を表し、次の数字が終了を表します。 ↩

ククログ