hiro99ma blog: [linux]思ったより logrotate が難しい

現在進行形だ。

常時起動するアプリを作って、ログをファイルに保存するようにした。
アプリの起動時にログファイルを O_APPEND で開いて、あとはそこに書き込むだけである。

そうなると、起動している時間が長いとログファイルが肥大してしまって困ったことになるだろう。
直近の数日分だけあればよいのだが、アプリのログ出力をがんばる気力がない。

そういうときに使うのが logrotate コマンドだ。
そういうときじゃなくても、ログファイルを管理するのに便利だから覚えておきたいところだ。

logrotate 自体は単なるコマンドで、実行されたら設定ファイル置き場にある各アプリの設定ファイルに従ってログファイルを操作する。

誰かが実行しないと動かないので、そこは systemctl やら cron やらを使うようになっている。
Ubuntu 20.04 ではどちらにも仕掛けてあって、 systemctl のタイマーが動いているなら systemctl から、そうでなければ cron から実行するようになっている。

と、さも詳しげに書いているのだが、実はまだうまく動かせていない・・・。
直接 logrotate コマンドを動かすと自アプリのログファイルが整理されたのだが、自動に任せると何も行われていないのだ。

まず、 systemctl か cron かを見ていこう。

わかりやすいのは cron の方だと思う。
デフォルトのままなら /etc/cron.daily/logrotate にスクリプトがあるだろう。

$ cat /etc/cron.daily/logrotate 
#!/bin/sh

# skip in favour of systemd timer
if [ -d /run/systemd/system ]; then
    exit 0
fi

# this cronjob persists removals (but not purges)
if [ ! -x /usr/sbin/logrotate ]; then
    exit 0
fi

/usr/sbin/logrotate /etc/logrotate.conf
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
    /usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit $EXITVALUE

スクリプトの通り、cron で実行しない条件が2つある(青文字のところ)。

/run/systemd/system ディレクトリがある場合
/usr/sbin/logrotate という実行ファイルがない場合

手元の Lubuntu 20.04 はどちらも一致しないので、cron では動かないことになる。

では systemctl で動いてくれるのだろう。

$ systemctl list-timers logrotate
NEXT LEFT LAST PASSED UNIT ACTIVATES
Sun 2022-04-17 00:00:00 JST 2h 22min left Sat 2022-04-16 20:48:31 JST 48min ago logrotate.timer logrotate.service

1 timers listed.
Pass --all to see loaded but inactive timers, too.

改行されて見づらいが、これを書いているのが 2022-04-16 の 21時半くらいで、 list-timers の NEXT には 2022-04-17 となっているから、次回は明日の 0時に動いてくれるということなのだろう。
なので、タイマーとしては少なくとも動いていると考えて良かろう。

では、systemctl として logrotate が動いているのかどうか。

$ journalctl -u logrotate
...(略)...
Apr 10 00:00:14 あああ systemd[1]: Finished Rotate log files.
-- Reboot --
Apr 11 23:16:00 あああ systemd[1]: Starting Rotate log files...
Apr 11 23:16:01 あああ systemd[1]: logrotate.service: Succeeded.
Apr 11 23:16:01 あああ systemd[1]: Finished Rotate log files.
-- Reboot --
Apr 16 20:48:31 あああ systemd[1]: Starting Rotate log files...
Apr 16 20:48:32 あああ systemd[1]: logrotate.service: Succeeded.
Apr 16 20:48:32 あああ systemd[1]: Finished Rotate log files.

うーん、いま見ている Ubuntu は VirtualBox で動かしていて、あまり長い時間動作させないのだった。
よくわからんが、少なくともエラーにはなっていないので大丈夫じゃないかな。

ただ、起動時に動かしたことしかわからない。
そもそも動作する周期はどうなっているのか？

$ cat /etc/systemd/system/timers.target.wants/logrotate.timer 
[Unit]
Description=Daily rotation of log files
Documentation=man:logrotate(8) man:logrotate.conf(5)

[Timer]
OnCalendar=daily
AccuracySec=12h
Persistent=true

[Install]
WantedBy=timers.target

一日1回か。

しかしこの logrotate.timer にはコマンドも何もないので、service ファイルがあるのか。

$ find /etc/systemd/ -name "*logrotate*"
/etc/systemd/system/timers.target.wants/logrotate.timer

/etc/systemd にはないやん。

しかし /lib/systemd にはあった。

$ find /lib/systemd/ -name "*logrotate*"
/lib/systemd/system/logrotate.service
/lib/systemd/system/logrotate.timer

どうも、 /lib/systemd の方がオリジナルで、 /etc/systemd にもあればそちらが優先されるそうだ。

/usr/lib/systemd/system/と/etc/systemd/system/ - tsunokawaのはてなダイアリー
https://tsunokawa.hatenablog.com/entry/2018/10/05/013034

/lib/systemd の方は

ExecStart=/usr/sbin/logrotate /etc/logrotate.conf

となっていたので、systemctl としても logrotate は呼び出しているはずだ。

では、次は logrotate 自体を見ていこう。

/var/log には logrotate の付いたファイルがなかった。
その代わり、logrotate を実行したときの状態ファイルはあった。

$ ls -l /var/lib/logrotate/status
-rw-r--r-- 1 root root 1624 Apr 16 20:48 /var/lib/logrotate/status

たぶん VirtualBox を立ち上げたときの時刻だろう。 cat で見てもそのくらいの時間になっている項目がいくつかあった。

なので、systemctl から logrotate が実行されていないということはないと思う。
起動時だけ別ルートで呼び出すとかやっている可能性もなくはないが、あんまりそんなことはしないんじゃないかと思う。

うーん、 systemctl が起動したときには logrotate が動いている、 logrotate を単独で実行したときにはローテートが実行される、となると、 systemctl がタイマーのところで動いてくれていないということになるのか。

ならば再び systemctl に戻ろう。
timer はこの辺りだそうだ。

systemd/タイマー - ArchWiki
https://wiki.archlinux.jp/index.php/Systemd/%E3%82%BF%E3%82%A4%E3%83%9E%E3%83%BC

logrotate.timer で実行に関係がありそうなのはこの辺りか。

[Timer]
OnCalendar=daily
AccuracySec=12h
Persistent=truen

OnCalendar はカレンダーイベントに合わせて動作するための設定項目。
まあ、これは見たままだろう。

AccuracySec はこのページにないな。

systemd.timer(5) — Arch manual pages
https://man.archlinux.org/man/systemd.timer.5

"accuracy"は「正確さ」。
値のデフォルト値は 1分。

Within this time window, the expiry time will be placed at a host-specific, randomized, but stable position that is synchronized between all local timer units.

などと書いてあるので、その範囲内でランダムな時間で実行するということか？
デフォルトなら 1分以内ということだろう。
そしてここの設定なら・・・12時間以内？？

なるほど、ログを処理するだけだからあせることはないということか。
システムが暇なときにやってくれれば良いよ、というところなのだろう。

そして私がログがローテートしないと思ったのも、OnCalendar を "hourly" にして daemon-reload し、時間になるまで待って比較的すぐに確認していたからだろう。

毎時実行なのに 12時間以内にやればいいよとなったら、いつ実行されるかわからんわな。

hiro99ma blog

2022/04/16

[linux]思ったより logrotate が難しい

0 件のコメント:

コメントを投稿