Edited at

TCP 接続で syslog サーバにログを送ると、syslog サーバが停止している場合、rsyslogd 本体が停止してしまう

メールシステムなど複数サーバからなるシステムを運用している場合、トラブルシュートを行う時に複数サーバの /var/log/ を横断検索するのは大変なので、


  • 各サーバの /var/log/ にログは蓄積する

  • 同時に、syslog サーバにもログを転送しておく

と設定をするのは、ごく自然な話だと思います。が、今回、その設定で痛い思いをしました。

192.0.2.17 で動作しているメールサーバ(Postfix や Dovecot が稼働)には、以下のように設定が書いてあり、同一サブネット内の syslog サーバ(192.0.2.65)だけでなく、遠隔地の syslog サーバ(198.51.100.65)にもログを転送しています。


/etc/rsyslog.d/forward-syslog.conf

mail.* @@198.51.100.65

mail.* @@192.0.2.65

遠隔地の syslog サーバ(198.51.100.65)が停電により停止していると、192.0.2.17 で動作している rsyslogd は、遠隔地の syslog サーバとの通信を開始しようと SYN パケットを送ったまま、そこで処理が止まってしまいます。

root@mx1:/local/tutimcadmin# netstat -nap | grep syslog

tcp 0 1 192.0.2.17:46698 198.51.100.65:514 SYN_SENT 11353/rsyslogd
unix 5 [ ] DGRAM 1699971854 11353/rsyslogd /dev/log
unix 5 [ ] DGRAM 1699971856 11353/rsyslogd /var/spool/postfix/dev/log

すると、症状としては、/var/log/syslog に rsyslogd が再起動したよというログは残るのですが、Postfix や Dovecot などのログは一切 /var/log/mail.log に出てこないだけでなく、192.0.2.65 で動作している同一サブネット内の syslog サーバにも全くログが転送されないという状況になります。


/var/log/syslog

Aug 11 10:03:45 mx1 rsyslogd: [origin software="rsyslogd" swVersion="5.8.11" x-pid="11353" x-info="http://www.rsyslog.com"] start


Postfix は /dev/log に書き込みができない場合、SMTP セッションそのものは受け付けるのですが、その後、応答ができなくなってしまうらしく、/proc/net/nf_conntrack を調べてみると、ESTABLISH されているのに UNREPLIED なセッションが大量に存在しているという状態になります。

root@mx1:/local/tutimcadmin# cat /proc/net/nf_conntrack|grep ESTABLISHED|grep UNREPLIED|wc -l

1065
root@mx1:/local/tutimcadmin# cat /proc/net/nf_conntrack|grep ESTABLISHED|grep UNREPLIED|tail -1
ipv4 2 tcp 6 303348 ESTABLISHED src=192.0.2.17 dst=203.0.113.42 sport=25 dport=53413 [UNREPLIED] src=203.0.113.42 dst=192.0.2.17 sport=53413 dport=25 mark=0 zone=0 use=2

syslog に記録が出てこないため、トラブルシュート初期の段階で rsyslogd の動作は疑ったのですが、


  • rsyslogd のプロセスは存在している。


  • /var/log/syslog に rsyslogd が起動したというメッセージは出ている。


  • rsyslogd -N 1/etc/rsyslog.conf の文法チェックを行なってもエラーも警告も出ない。

という状況で、ネットワークやハードウェアなどより低レイヤーが原因となっている可能性を疑ったため、rsyslogd が原因であると辿り着くのに時間を要しました。

というわけで、 rsyslog-5.8.x を使って TCP 接続でログを送信する設定を行う場合は、十分な検証が必要です。

少なくとも rsyslog-8.4 ならば、TCP 接続および RELP 接続ともにタイムアウトして、rsyslogd 本体の機能は維持されるようなので、素直に rsyslog を更新したほうが良さそうです。

また、検証は相当に厄介そうです。まず、同一サブネット内の存在しないサーバを指定しても、上記の症状は再現できませんでした(停電中のサーバを指定すれば再現できる)。また、同僚の記憶によれば、2018年の停電時も同じ設定だったはずということなので、2018年には発生しなかったトラブルが何故2019年には発生したのか?の理由も不明のままです。