Unboundを動かしているRHEL(CentOS)6系でrsyslogdがログを吐かなくなった
割と限定的な話ではあるんだけど、備忘録な意味も含めて残しときます。
RHEL(Red Hat Enterprise Linux)やCentOSの6系で何故かログが全然出力されなくなる現象に遭遇した。rsyslogdを再起動するものの現象は変わらず。rsyslogdの再起動自体は特にエラーが画面に出ることなく終わるんだけど、 /var/log/messages を見るとこんなログが表示されてる。
rsyslogdが /dev/log の作成に失敗している。実際に /dev/log を見るとデバイスが存在するので rm で削除しようとしても「Device or resource busy(…だったかな…確かこんな感じ)」というエラーが発生して削除できない。mvで名前の変更もできない。ちなみにOSを再起動すると /dev/log が作り直され、ちゃんとrsyslogdがログを出力するようになる。
OS再起動すれば元に戻るからいいじゃないと最初は思っていたものの、再起動しないと元に戻らないのは某OSのお家芸っぽくて嫌なので、その後の追加調査で原因が分かった。以下の条件が揃えばrsyslogdがログを吐かなくなる。
最後の条件は普段はあまりやらない操作だと思う。ただOSの再起動を滅多にやらない環境の場合は長期スパンで考えると条件を満たす可能性はあるのかもしれない。
そして何故、この操作でログを吐かなくなるのかというと、unboudの起動スクリプトに原因があります。unboundは起動時に /dev/log を別の場所(デフォルトだと /var/unbound/dev/log)にマウント(mount)します。そして停止時にunmountしてマウントを解除するという動作があるのですが、RHEL/CentOS6系は /proc/mounts の出力内容が若干変わっており、このunmountに失敗します(起動時のマウント状態のチェックも同じように失敗してる)。この状態でunboundを再起動するとどうなるか、こうなります。
/dev/logが2重にマウントされている(余談だが/dev/randomも2重にマウントされている)。2重にマウントできる仕様ってどうよとは思うものの、まぁできているので仕方ない。
この2重にマウントが発生している状態でrsyslogdを再起動すると /dev/log の削除に失敗してログが吐かれなくなります。解決方法はunboundの起動スクリプトを修正して停止の際にちゃんとunmountするように修正します。修正は次の通り。
適当修正で正規表現をちょっといじってるだけですが、これでunbound停止時にunmountが発生して2重マウントと言う事態はなくなります。
これでめでたし、めでたし…と言いたいところですが、もう一つ問題が残ってます。一度でもrsyslogdを再起動するとunboundのログが出力されなくなります。これはunboundが /dev/log を別の場所にマウントして利用していたところに、rsyslogdの再起動が発生すると元の/dev/logが再作成されるため、unboundが利用していた/dev/logはOS上では「削除」された事になるためです。
この解決方法は単純でrsyslogdを再起動したら、続けてunboundも再起動するだけ。すると古いマウントは削除され、新しい/dev/logをマウントするのでunboundのログが吐かれるようになります。
…単純だけど面倒だし、こんなノウハウ忘れそうですね、はい。
更に一歩進んだ解決方法もあって、unboundでマウントやめればいいです。例えばbindでchrootを有効にして実行するときはrsyslogd(syslogd)の設定を変えて、/var/chroot/named/dev/logとかでもログを受け付けるようにします。同じようにunboundでもrsyslogdの設定を変えてrsyslogdが/var/unbound/dev/logを受け付けるようにしてあげればマウントする必要はなくなります。
あとunboundの起動スクリプトをいじって/dev/logをマウントさせないようにすればOKです。これでunboundとrsyslogdそれぞれの動作に邪魔される事なく、自由に再起動できるようになります。
[おまけ]
unboundとunmountが似ていて、自分で書いてて途中でよくわからなくなった。