こんにちは！AWS事業本部のおつまみです。
みなさん、 Red Hat Enterprise Linux9 で logrotate を使って、ログファイルを1時間ごとにローテーションさせたいと思ったことはありますか？私はあります。
logrotate は、ログファイルをローテーションし、必要に応じて圧縮などを行うツールです。
これを使うことで、「週次や月次でローテーションする」、「ファイルサイズがある値を超えたらローテーションする」といったことができ、ログの肥大化を防ぐことができます。
Linuxに標準で備わっているツールのため、こちらを使用してログローテションしている方も多いと思います。
今回この機能を使って、ログファイルを1時間ごとにローテーションさせたいと思ったのですが、かなり苦戦しました。。
同じように悩んでいる方のために対処方法をシェアします。
いきなり結論
- Red Hat Enterprise Linux 9 の logrotate は
cronではなく、systemd-timerで起動している。 - デフォルトでは、 logrotate は日次で起動するようになっている。
- 1時間ごとにローテションさせるには、
logrotate.timer内のOnCalendarをdailyからhourlyに変更し、デーモンを再起動する必要がある。
検証環境
- Red Hat Enterprise Linux 9 (HVM), SSD Volume Type
背景
logrotate.d下にある設定ファイル/etc/logrotate.confと/etc/logrotate.d/tomcatを以下のように設定しました。
/etc/logrotate.conf
# see "man logrotate" for details
# global options do not affect preceding include directives
# rotate log files weekly
weekly
# keep 4 weeks worth of backlogs
rotate 4
# create new (empty) log files after rotating old ones
create
# use date as a suffix of the rotated file
dateext
# uncomment this if you want your log files compressed
#compress
# packages drop log rotation information into this directory
include /etc/logrotate.d
# system-specific logs may be also be configured here./etc/logrotate.d/tomcat
/var/log/tomcat/catalina.out
{
hourly
missingok
rotate 24
ifempty
dateext
compress
}※ 今回は検証のため、catalina.outのみローテーションさせるように設定しています。
各パラメータの詳細について知りたい方はこちらの記事がわかりやすいので、ご参考ください。
ログローテートソフトウエア logrotate についてまとめ - Qiita
/etc/logrotate.d/tomcat内でhourlyで設定したため、1時間ごとにローテーションされるかなと思いきや、いつまで経ってもローテーションされませんでした。
ちなみにlogrotateは設定ファイルを変更しても、再起動などは不要です。
なお以下は確認済でした。
- デバックモードでの起動
logrotate -dv /etc/logrotate.confでerrorが出ないこと。 - 手動での強制ローテーション
logrotate -f /etc/logrotate.confでは正常にローテーションされること。 - 自動ローテーションの場合、日次でのローテーションは実行されている。
原因
原因は Red Hat Enterprise Linux 9 の logrotate の起動方法のデフォルトがcronからsystemd-timerに変わっており、logrotateのデフォルトの動作間隔がdailyであるためでした。
1つずつ解説していきます。
logrotateの起動方法について
logrotate はcronもしくはanacronから実行されていることが多いです。
色々なサイトを調べたところ、「cronで起動しています」と書かれていることがほとんどです。
しかし、Red Hat Enterprise Linux 9 以降はsystemd-timer を使い、logrotate が実行されるようになっていました。
そのためcron内にlogrotateの設定ファイルは含まれておらず、代わりに/usr/lib/systemd/system/logrotate.timer,logrotate.serviceが含まれるようになっています。
この設定ファイルを参照してlogrotateが動いているということですね。
logrotateのデフォルトの動作間隔について
/usr/lib/systemd/system/logrotate.timerを見てみます。
[Unit]
Description=Daily rotation of log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
[Timer]
OnCalendar=daily
AccuracySec=1h
Persistent=true
[Install]
WantedBy=timers.targetOnCalendar=dailyとなっているため、日次で起動されることが初期設定となっていることがわかりました。
よって、logrotate の設定ファイル内でhourlyを指定したとしても、そもそも１時間毎にlogrotateが実行されないため、ログのローテーションは行われなかったというわけです。
ちなみに、systemd-timerで起動しているサービスはsystemctl list-timersコマンドで確認できます。
# sudo systemctl list-timers
NEXT LEFT LAST PASSED UNIT ACTIVATES
Thu 2023-09-07 12:53:34 JST 2min 32s left Thu 2023-09-07 12:48:34 JST 2min 27s ago nm-cloud-setup.timer nm-cloud-setup.service
Thu 2023-09-07 14:23:18 JST 1h 32min left Thu 2023-09-07 12:43:03 JST 7min ago dnf-makecache.timer dnf-makecache.service
Fri 2023-09-08 00:00:00 JST 11h left Thu 2023-09-07 00:00:00 JST 12h ago logrotate.timer logrotate.service
Fri 2023-09-08 08:14:51 JST 19h left Thu 2023-09-07 08:14:51 JST 4h 36min ago systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.servicelogrotate.timerの実行が翌日になっているため、日次でしか起動されないことが確認できました。
対処方法
logrotate.timer内のOnCalendarをdailyからhourlyに変更し、デーモンを再起動させます。
以下のコマンドをroot権限、もしくはsudoをつけて実行してください。
１. まず設定ファイルを/etc/systemd/system/下にコピーします。
cp /usr/lib/systemd/system/logrotate.timer /etc/systemd/system/
cp /usr/lib/systemd/system/logrotate.service /etc/systemd/system/２. /etc/systemd/system/logrotate.timerを編集します。
vi /etc/systemd/system/logrotate.timer修正前
[Unit]
Description=Daily rotation of log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
[Timer]
OnCalendar=daily
AccuracySec=1h
Persistent=true
[Install]
WantedBy=timers.target修正後
[Unit]
Description=Daily rotation of log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
[Timer]
OnCalendar=hourly
AccuracySec=1m
Persistent=true
[Install]
WantedBy=timers.targetOnCalendarに合わせてAccuracySecもローテーションの頻度に合わせて1時間から1分に変更しました。
この設定により指定した時間間隔から 1 分以内の適当なタイミングでローテーションが実行されるようになります。
３. デーモンの再起動とlogrotate.timerを有効にします。
systemctl daemon-reload
systemctl enable logrotate.timer動作確認
systemctl list-timersコマンドで実行頻度を確認します。
sudo systemctl list-timers
NEXT LEFT LAST PASSED UNIT ACTIVATES
Thu 2023-09-07 04:45:59 UTC 1min 17s left Thu 2023-09-07 04:40:59 UTC 3min 42s ago nm-cloud-setup.timer nm-cloud-setup.service
Thu 2023-09-07 05:00:00 UTC 15min left Thu 2023-09-07 04:00:12 UTC 44min ago logrotate.timer logrotate.service
Thu 2023-09-07 05:18:57 UTC 34min left Thu 2023-09-07 03:38:59 UTC 1h 5min ago dnf-makecache.timer dnf-makecache.service
Fri 2023-09-08 01:24:59 UTC 20h left Thu 2023-09-07 01:24:59 UTC 3h 19min ago systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.serviceNEXTが翌日ではなく、当日になっているので問題なく設定されているようです！
そのまま時間になるまで待ちます。
ll /var/log/tomcat/catalina.out*
-rw-r--r--. 1 root root 0 Sep 7 05:00 catalina.out
-rw-r--r--. 1 root root 20 Sep 7 04:00 catalina.out-2023090705.gz無事に自動でローテーションできていました！
おまけのQ&A
Q.systemd-timerの場合、時間を迎えたタイミングでOSが停止している時はOS起動のタイミングで再実行してくれる？
A.logrotate.timer内のパラメータPersistent=trueの場合は再実行してくれます。
こちら確認するためにEC2インスタンスを2時間ほど停止後、再実行させました。
systemctl list-timers
NEXT LEFT LAST PASSED UNIT ACTIVATES
Thu 2023-09-07 08:40:38 UTC 3min 42s left - - nm-cloud-setup.timer nm-cloud-setup.service
Thu 2023-09-07 08:50:38 UTC 13min left - - systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
Thu 2023-09-07 09:00:00 UTC 23min left Thu 2023-09-07 08:35:46 UTC 1min 9s ago logrotate.timer logrotate.service
Thu 2023-09-07 09:09:07 UTC 32min left - - dnf-makecache.timer dnf-makecache.service
4 timers listed.
Pass --all to see loaded but inactive timers, too.ちょうど1分前に再起動しているので、ローテーションが実行されているようでした。
念の為ファイルも確認します。
cd /var/log/tomcat/
ll
-rw-r--r--. 1 root root 0 Sep 7 08:35 catalina.out
-rw-r--r--. 1 root root 20 Sep 7 04:00 catalina.out-2023090705.gz
-rw-r--r--. 1 root root 20 Sep 7 05:00 catalina.out-2023090708.gz停止していた時間を除いて、再起動時にローションされていました。
これはlogrotate.timer内のパラメータPersistentがtrueの場合は再実行してくれます。デフォルトではtrueになっていました。
trueを指定するとサービスユニットが最後に実行された時刻が保存され、タイマーが非アクディブで実行されなかったイベントがアクティブになった瞬間に実行されます。
つまり、停止していて実行されなかったイベントが起動と同時に実行されるようになります。ちなみにこのオプションを有効にするにはOnCalendarの指定が必要になります。
anacronでも実行履歴を確認して、未実行であれば実行してくれるという機能があるので、 systemd-timerでも同様の機能があるようでよかったです。
Q.オリジナルの/usr/lib/systemd/system/logrotate.timer とコピーされた/etc/systemd/system/ はバッティングしないのか？
A.同名の設定ファイルが設置された場合は、/etc/systemd/system フォルダの設定ファイルが優先されます。
「2つ設定ファイルがあると、どっちも有効にならないのか？」
と心配になりました。
しかし、心配ご無用。/usr/lib/systemd/system と /etc/systemd/system に同名の設定ファイルが設置された場合は、/etc/systemd/systemフォルダの設定ファイルが優先されるようです。
つまり、/usr/lib/systemd/systemからファイルをコピーしてきて編集した場合は、編集後のファイルが優先されます。
下記の Red Hat Customer Potal に記載の通り、設定ファイルは/etc/systemd/system/下で作成、編集するのが通例なようです。
追記：SELinux有効な環境の場合、ローテートに失敗する
今回使用した環境の場合、デフォルトでSELinuxが有効になっていました。
SELinuxとはSecurity-Enhanced Linux の略で、Linux のセキュリティをより強固なものにするために使用される設定です。
下記コマンドgetenforceで有効化状態を確認できます。
getenforce
Enforcing- Enforcing：検知して拒絶する
- Permissive：検知してログに書き込むが、拒絶まではしない
- Disabled：無効。検知も拒絶もしない
SELinux有効の状態でlogrotate.serviceを確認したところエラーメッセージが出力されています。
systemctl status logrotate.service
× logrotate.service - Rotate log files
Loaded: loaded (/etc/systemd/system/logrotate.service; static)
Active: failed (Result: core-dump) since Fri 2023-09-08 13:00:02 JST; 38min ago
TriggeredBy: ● logrotate.timer
Docs: man:logrotate(8)
man:logrotate.conf(5)
Process: 9973 ExecStart=/usr/sbin/logrotate /etc/logrotate.conf (code=dumped, signal=ABRT)
Main PID: 9973 (code=dumped, signal=ABRT)
CPU: 19ms
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp systemd[1]: Starting Rotate log files...
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp logrotate[9973]: error: cannot allocate memory [readConfigFile():1806]
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp logrotate[9973]: free(): double free detected in tcache 2
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp systemd-coredump[9975]: [🡕] Process 9973 (logrotate) of user 0 dumped core.
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp systemd[1]: logrotate.service: Main process exited, code=dumped, status=6/ABRT
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp systemd[1]: logrotate.service: Failed with result 'core-dump'.
Sep 08 13:00:02 WSRTOMAPD01.awsweb.fancl.co.jp systemd[1]: Failed to start Rotate log files.エラーメッセージでぐぐったところ下記のサイトがヒットしました。
ログ出力しようとしているシンボリックリンクのセキュリティコンテキストのタイプがunlabeled_t:s0となっており、ラベル付けされていないことが原因でした。
ls -ldZ /var/log/tomcat/
drwxr-xr-x. 2 tomcat tomcat system_u:object_r:unlabeled_t:s0 4096 Sep 7 12:14 /var/log/tomcat/そのため、semanage fcontext コマンドで、ファイルの SELinux コンテキストを変更し、ディレクトリのコンテキストを一括再設定(リストア)します。
sudo semanage fcontext -a -t tomcat_log_t "/var/log/tomcat(/.*)?"
sudo restorecon -R /var/log/tomcat/これでローテーションが問題なく実行されるようになります。
さいごに
今回はRed Hat Enterprise Linux 9 で logrotateを使ってログファイルを1時間ごとにローテーションさせる方法をお伝えしました。
解決までに半日ほど時間がかかりましたが、無事解決できてよかったです！
同じように詰まっている方のお役に立てれば幸いです。
最後までお読みいただきありがとうございました！
以上、おつまみ（＠AWS11077）でした！
参考資料
ログローテートソフトウエア logrotate についてまとめ - Qiita
syslog に関する RHEL 9 cron.daily の質問 - Red Hat Customer Portal
systemd .timerについて調べた事を記事にしておく | そう備忘録
10.6. systemd のユニットファイルの作成および変更 Red Hat Enterprise Linux 7 | Red Hat Customer Portal
CentOS 7 における systemd のファイル・フォルダ構成 |
/usr/lib/systemd/system/と/etc/systemd/system/ - tsunokawaのはてなダイアリー
0
