Ubuntu18.04 logrotate – duplicate log entry

cronからこんなメールが届いた。

Date: Fri, 18 Sep 2020 06:27:17 +0900
From: Administrator root@hogeserver.hogeddns.jp
Subject: Cron test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
Body:
/etc/cron.daily/logrotate:
error: kopano-server:1 duplicate log entry for /var/log/kopano/server.log

実は前から届いていたが無視していたもの。きれいにしよう。

---

やること。

• 対処
• 原因の調査
  • cronの設定確認
  • logrotateの設定確認
  • logrotate設定が重複している理由の考察

　

対処

logrotateで、/var/log/kopano/kopano-serverに関する設定が重複していた。
他のシステムを参照し、そのシステムにないファイルを削除した。
※実際のコマンドは移動、念のためファイルを残し、動作確認が完了した時点で削除することにした。

$ sudo mv /etc/logrotate.d/kopano-server /root

　

原因の調査

cronの設定確認

/etc/crontabをみてみると、6:25に/etc/cron.dailyが実行される設定になっている。

test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )

test -x は実行可能なら真、でも/usr/sbin/anacronはない。

$ dpkg -l anacron
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name                     Version           Architecture      Description
+++-========================-=================-=================-=====================================================
un  anacron                  <none>            <none>            (no description available)

anacronがないので、|| によって次のコマンドが実行される。
(anacronがあったら何もしないということに)

次のコマンドが、ルートディレクトリに移動して、run-partsを実行。
/etc/cron.dailyディレクトリにある実行ファイルをファイル名の辞書順に実行する。–reportオプションにより、スクリプト実行前にファイル名が標準出力に出力される。

このことから、/etc/cron.daily/logrotate を実行したときに duplicate log entry が発生していることが分かる。

logrotateの設定確認

このスクリプトは実行環境を整えて、/usr/sbin/logrotate を実行している。
パラメーターには /etc/logrotate.conf が渡されている。
このconfファイルは、/etc/logrotate.d にあるファイルをインクルードしている。

$ ll /etc/logrotate.d
total 92
drwxr-xr-x   2 root root  4096 Sep 19 07:00 ./
drwxr-xr-x 131 root root 12288 Sep 19 07:01 ../
…
-rw-r--r--   1 root root  1773 Mar 22  2018 kopano
-rw-r--r--   1 root root   116 Mar 22  2018 kopano-server
…

ファイルが2つある。小さい方のファイルからみてみるか…。
/etc/logrotate.d/kopano-server

/var/log/kopano/server.log {
  rotate 5
  weekly
  postrotate
    /usr/bin/killall -HUP kopano-server
  endscript
}

1つだけファイルが定義されている。/var/log/kopano/server.log はエラーで示されたログファイルだ。

続いて、大きい方のファイルを見てみる。
/etc/logrotate.d/kopano

…
/var/log/kopano/server.log /var/log/kopano/audit.log {
        weekly
        missingok
        rotate 52
        compress
        delaycompress
        notifempty
        postrotate
            killall -HUP kopano-server 2> /dev/null || true
        endscript
}
…

確かに定義が重複している。この重複を検出して6:27にこのメールが送信されてきていたのだった。

logrotate設定が重複している理由の考察

この状態を見れば、/etc/logrotate.d/kopano-serverというファイルを消せば問題解決しそうだけれども、本来、どの形が正しいのかを確認したい。

ファイルがどのパッケージに含まれているのか確認する。

$ dpkg-query -S /etc/logrotate.d/kopano*
kopano-common: /etc/logrotate.d/kopano
kopano-server: /etc/logrotate.d/kopano-server

インストールしているパッケージにどちらも含まれている…。

ここで、他のサーバーのKopanoの状態を確認してみたら…kopano-serverパッケージには/etc/logrotate.d/kopano-serverが含まれていなかった。
ただ、このサーバーでもdpkg -Lでパッケージの中身をみると含まれているので、インストールスクリプトで重複を発見したら削除、的な処理が走るのかもしれない。

ということで、以下を実行して動きを確認してみた。

$ sudo mv /etc/logrotate.d/kopano-server /root
$ dpkg-query -S /etc/logrotate.d/kopano*
kopano-common: /etc/logrotate.d/kopano

dpkg-queryは実際に存在するファイルを表示してくれるんだと理解。
そして、どういうわけか/etc/logrotate.d/kopano-serverが残っていてこのエラーが発生していることが分かった。

セットアップスクリプト？の確認は面倒なので行わなかった。

さいごに

理由が分かれば対処はできるけれども、何故こうなったの？まで調査するとちょっと大変。でも、スクリプトのデバッグは…面倒くさすぎる。

割り切るタイミングの決め方で、知識の幅が変わってくると思った。