キアラの備忘録

雑多なメモを書いていきます

トップ > fluentd > 【トラブル対応】td-agent(fluentd) 再起動時の "Address already in use" エラー

【トラブル対応】td-agent(fluentd) 再起動時の "Address already in use" エラー

fluentd

■背景

  • 複数台のWebサーバーのログを、td-agent によって、1台のログ集約サーバーに送っている
  • Webサーバー の td-agentをstepし、ログ集約サーバーの td-agent をrestart した
  • Webサーバーのtd-agentをstart すると ログ集約サーバーのポートにアクセスできないエラー出て、ログが送れなくなった
  • ログ集約サーバーのtd-agent のログには "Address already in use" のエラーが出た

■環境

  • td-agent v1.1.12
  • fluentd v0.10.33

■原因

  • ログ集約サーバーの td-agent を restart した際に、プロセスが残っていて、ポートが占有されたままになっていた

■対応

  • Webサーバーの td-agent を stop
  • ログ集約サーバーの td-agent を stop した上で、同サーバーの td-agent のプロセスを殺した
  • ログ集約サーバーのtd-agent を start
  • Webサーバーのtd-agent を start

■今回学んだこと

  • td-agent restart では、プロセスが残ってしまう場合がある

■トラブル発覚までの操作

1. webサーバーの td-agent を停止

[chiara@web01 ~]$ sudo /etc/init.d/td-agent stop

2. ログ集約サーバーの td-agent を再起動

[chiara@log ~]$ sudo /etc/init.d/td-agent stop

3. webサーバーの td-agent を開始

[chiara@web01 ~]$ sudo /etc/init.d/td-agent stop

4. Webサーバーのtd-agentのログを確認

ログ集約サーバーに接続できないエラーが発生した

[chiara@web01 ~]$ sudo cat /var/log/td-agent/td-agent.log
2018-11-01 10:55:00 +0900 [info]: detached forwarding server 'log' host="log" port=24224 hard_timeout=true

5. ログ集約サーバーのtd-agent のログを確認

ポート: 24224 が既に使われているエラーが発生していた

[chiara@log ~]$ sudo cat /var/log/td-agent/td-agent.log
  2018-11-01 11:00:00 +0900 [info]: listening fluent socket on 0.0.0.0:24224
  2018-11-01 11:00:00 +0900 [error]: unexpected error error="Address already in use - bind(2)"
  2018-11-01 11:00:00 +0900 [error]: /usr/lib64/fluent/ruby/lib/ruby/gems/1.9.1/gems/cool.io-1.1.1/lib/cool.io/server.rb:57:in `initialize'
  2018-11-01 11:00:00 +0900 [error]: /usr/lib64/fluent/ruby/lib/ruby/gems/1.9.1/gems/cool.io-1.1.1/lib/cool.io/server.rb:57:in `new'
  2018-11-01 11:00:00 +0900 [error]: /usr/lib64/fluent/ruby/lib/ruby/gems/1.9.1/gems/cool.io-1.1.1/lib/cool.io/server.rb:57:in `initialize'

■調査内容

ログ集約サーバーのtd-agentのプロセスを確認

確認すると、4つのプロセスが確認できた td-agent は、データ通信(TCP), UDP(死活監視) で2プロセス使うので、それ以外の2プロセスが余計に見える。

[chiara@log ~]$ ps aux | grep td-agent | grep -v grep
root      3580 0.0  0.5 841112 89744 ?        Sl   Oct29   0:37 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root     14311 78.0  0.1 723748 31088 ?        Rl   11:15   0:00 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root     24111 0.0  0.5 841112 87232 ?        S    Oct29   0:00 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root     29982  0.0  0.0 168292 14516 ?        Sl   11:15   0:00 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

td-agent を停止後に再度プロセスを確認

stop しても消えないプロセスが残っていた

[chiara@log ~]$ sudo /etc/init.d/td-agent stop                                           
Shutting down td-agent:                                    [  OK  ]
[chiara@log ~]$ ps aux | grep td-agent | grep -v grep
root      3580 0.0  0.5 841112 89744 ?        Sl   Oct29   0:37 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

root     24111 0.0  0.5 841112 87232 ?        S    Oct29   0:00 /usr/lib64/fluent/ruby/bin/ruby /usr/sbin/td-agent --group root --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

■対応内容

不要なプロセスをkillコマンドで殺した

[chiara@log ~]$ sudo kill -9 24111 3580