【備忘録】rsyslogのwarningでハマった話

rsyslogの「warning: ~ action is deprecated, consider using the 'stop' statement instead」でハマった話

sftpの構築をしていた際、SFTPの操作をログに残すための設定を一通り施し、よし、再起動しようってなり、rsyslogのrestartをかけ、/var/log/sftpのログ出力のテストを実施。
よし、/var/log/sftpログは問題なく出ていると、ご機嫌になる。

ログ出力時のプロセスログを確認したいとふと思い、rsyslogのstatusをみると、次のような出力が出た。（結論としては本事象はsftpの構築とは全くの無関係だったのだが、rsyslogの再起動するときって基本ログ関係の設定するときくらい。）

①rsyslogのstatus確認

[root@Server01:~]# systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 金 2024-07-05 18:02:48 JST; 2min 23s ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 120829 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─120829 /usr/sbin/rsyslogd -n

 7月 05 18:02:48 Server01 systemd[1]: Starting System Logging Service...
 7月 05 18:02:48 Server01 rsyslogd[120829]:  [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="120829" x-info="http://www.rsyslog.com"] start
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 systemd[1]: Started System Logging Service.
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]

ん？プロセスはちゃんとactiveで起動しているけど、なんかWarningでている。

これはなんか/etc/rsyslog.confやlogrouteに不備あるかと段階的にSFTP系の設定を戻す→再起動を繰り返し、ついにsftp構築前の状態に戻すも

②rsyslogの再度status確認

[root@Server01:~]# systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 金 2024-07-05 18:02:48 JST; 2min 23s ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 120829 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─120829 /usr/sbin/rsyslogd -n

 7月 05 18:02:48 Server01 systemd[1]: Starting System Logging Service...
 7月 05 18:02:48 Server01 rsyslogd[120829]:  [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="120829" x-info="http://www.rsyslog.com"] start
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 systemd[1]: Started System Logging Service.
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]

直んないんだけどｗｗｗ

warningの出力で示しているリンクhttp://www.rsyslog.com/e/2307を読んでみる。

どうもdiscard やomrulesetといったステートメントが別のに置き換えることを推奨しますよ、さもないとWarningだしますよ書かれていたので、「/etc/rsyslog.conf」内でgrep するもヒットしない。

※ちなみにこのサイト(http://www.rsyslog.com/e/2307)のコメント欄をみると、推奨設定ごときでWarning出力いらないんだけど的な避難轟轟のコメントで溢れ返っているのには笑ったｗ

え、てことは、そもそも元から（デフォルト）でWarning出力されていること？？？と思い、ひとまず何もsftpの構築をしていないサーバはどうなんだと、他のサーバでもrsyslogのrestartをかけ、statusをみる。（なにも異常がないように見えてここにも落とし穴があるのだが後述）

rsyslogのstatus確認

2024/07/08 21:00:23 [ansible@Server02:~]$ systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 月 2024-07-08 14:39:20 JST; 6h ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 124041 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─124041 /usr/sbin/rsyslogd -n

warningがないやんか...やはりsftp構築が関係してそう (´；ω；｀)ﾌﾞﾜｯ

いやー、なんか戻してない設定あったけかー。。。？と、半分泣きそうになり、historyで実行コマンド振り返るもここで終業時間がきてしまう。
とりあえず、プロセス自体は生きているし、
推奨設定の類なら急いで対応する必要はなさそうだったので、翌日再度調査する。

翌日

同じServer01で確認。すると

rsyslogのstatus確認

[ansible@Server01:~]$ systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 月 2024-07-08 14:39:20 JST; 6h ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 124041 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─124041 /usr/sbin/rsyslogd -n

あれ？warningなくね？

su - でrootに昇格してからプロセスリスタート
そしてステータス確認

rsyslogのstatus確認

[root@Server01:~]# systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 金 2024-07-05 18:02:48 JST; 2min 23s ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 120829 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─120829 /usr/sbin/rsyslogd -n

 7月 05 18:02:48 Server01 systemd[1]: Starting System Logging Service...
 7月 05 18:02:48 Server01 rsyslogd[120829]:  [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="120829" x-info="http://www.rsyslog.com"] start
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server01 systemd[1]: Started System Logging Service.
 7月 05 18:02:48 Server01 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]

warning復活...゜゜(´□｀。)°゜

しかしここでようやく、からくりに気づく。
ステータス確認の際、一般ユーザ(ansible)で確認してたが為にWarningが出力されなかったようだ。
ためしにSFTP構築無関係のserver2でもroot権限でstatus確認すると

rsyslogのstatus確認

[root@Server02:~]# systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 金 2024-07-05 18:02:48 JST; 2min 23s ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 120829 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─120829 /usr/sbin/rsyslogd -n

 7月 05 18:02:48 Server02 systemd[1]: Starting System Logging Service...
 7月 05 18:02:48 Server02 rsyslogd[120829]:  [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="120829" x-info="http://www.rsyslog.com"] start
 7月 05 18:02:48 Server02 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server02 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]
 7月 05 18:02:48 Server02 systemd[1]: Started System Logging Service.
 7月 05 18:02:48 Server02 rsyslogd[120829]: warning: ~ action is deprecated, consider using the 'stop' statement instead [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/2307 ]

Warningが出ていた・・・

デフォルトででていたのね。

対処法はすぐに見つかった。

rsyslogの出力が止まった時の対応
~(チルダ)をstopに変えると直るらしい。

/etc/rsyslog.dのディレクトリ配下にもrsyslog系のcongfigがあるのでそこで非推奨設定を確認するとよい。
以下出力のコメントアウト部分が設定前
その下が設定後となる。

rsyslogの設定内容

[ansible@dev-tom1-batp-t01:~]$ grep -ie "~" -ie stop /etc/rsyslog.conf 
#:msg, contains, "Dropped by INPUT"    ~
#:msg, contains, "Dropped by OUTPUT"    ~
:msg, contains, "Dropped by INPUT"    stop
:msg, contains, "Dropped by OUTPUT"    stop
 [root@dev-tom1-batp-t01:~]# grep -ie "~" -ie stop /etc/rsyslog.d/21-cloudinit.conf
# & ~
& stop

直し完了！

プロセスリスタート＆確認！(どきどき)

rsyslogのrestart&status確認（直った！）

[root@Server01:~]# systemctl restart rsyslog.service
[root@Server01:~]# systemctl status rsyslog.service
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since 月 2024-07-08 21:22:10 JST; 11s ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 83395 (rsyslogd)
    Tasks: 4
   CGroup: /system.slice/rsyslog.service
           └─83395 /usr/sbin/rsyslogd -n

 7月 08 21:22:10 Server01 systemd[1]: Starting System Logging Service...
 7月 08 21:22:10 Server01 rsyslogd[83395]:  [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="83395" x-info="http://www.rsyslog.com"] start
 7月 08 21:22:10 Server01 systemd[1]: Started System Logging Service.

わーい、直ったど～！(,,>᎑<,,)

warningがなくなりきれいさっぱり
事象判明～対処まで合計一日弱、使いました。
sftp構築ではなく、単純にrsyslogの不具合だったという事実に気づけていれば、すぐに対処できる事象だったと思います。

エンジニアとして、ひとつ反省と成長を得た事件でした。

SFTPの構築もうまいこといったし、
めでたしめでたし。（完）