logrotateでrsyslogへのSIGHUP送信をたくさん書いてはいけない話

systemd

前提

logrotateの設定で、rsyslogを再起動させたいときにSIGHUPを送る。以下はRHEL 9の例。

/var/log/cron
/var/log/maillog
/var/log/messages
/var/log/secure
/var/log/spooler
{
    missingok
    sharedscripts
    postrotate
        /usr/bin/systemctl -s HUP kill rsyslog.service >/dev/null 2>&1 || true
    endscript
}

複数SIGHUPの問題

上記の設定はごく普通で、これだけだと何の害もないが、ローテート間隔が違うファイルを扱うなどで複数のSIGHUP送信を書くと問題がある。

  • rsyslogはSIGHUPのハンドラを実行している最中にSIGHUPを受信すると異常終了する。

多少緩和されていて、rsyslog.serviceに Restart=on-failure が設定されているので、SIGHUP連打が発生してもsystemdが自動再起動を行う。

もちろんソケットは一旦切れるのでtcp/udpでsyslogを受信している場合はログ欠損が起きる。

さらに、自動再起動が5回以上になるとレート制限(start-limit-hit)によりsystemdの自動再起動も失敗する。 つまりlogrotateの設定でSIGHUP送信をたくさん行うとrsyslogが意図せずlogrotateのタイミングや(しばらく停止したあとの)起動直後のタイミングで失敗するケースが発生しうる。タイミングにより必ず発生するわけではないあたりがいやらしい。

対策

RHEL 10やFedora では既に対策されている。rsyslog.serviceではExecReload でSIGHUPを送信するように設定して、 logrotateからは systemctl reload rsyslog でSIGHUPを送信する。

# /usr/lib/systemd/system/rsyslog.service
[Unit]
Description=System Logging Service
;Requires=syslog.socket
Documentation=man:rsyslogd(8)
Documentation=https://www.rsyslog.com/doc/
Wants=network.target network-online.target
After=network.target network-online.target

[Service]
Type=notify
EnvironmentFile=-/etc/sysconfig/rsyslog
ExecStart=/usr/sbin/rsyslogd -n $SYSLOGD_OPTIONS
ExecReload=/usr/bin/kill -HUP $MAINPID     <<====
UMask=0066
StandardOutput=null
Restart=on-failure
(以下略)
# /etc/logrotate.d/rsyslog
/var/log/cron
/var/log/maillog
/var/log/messages
/var/log/secure
/var/log/spooler
{
    missingok
    sharedscripts
    postrotate
        /usr/bin/systemctl reload rsyslog.service >/dev/null 2>&1 || true    <<===
    endscript
}

対策のしくみ

どのバージョンからか確認していないがrsyslogはsystemd notify(オペレーションできる状態になったとsystemdに通知する仕組み)に対応していて、rsyslog.service は Type=notifyになっている。 この場合reloadは、ExecReloadのコマンドを実行したあとsystemd notifyを受信するまで完了しない。 rsyslogはSIGHUPの処理が終わるまで systemd notifyを送信しないので、systemctl restart なら連打されても割り込み処理中に再度割り込みが入ることがない。