logrotateのしわざ 2003.3.27

     子供の頃、お寺の住職から聞いた話。その昔、豊臣秀吉公が、何の手柄だったか忘れたが、曽呂利新左衛門(そろりしんざえもん)に褒美をつかわすという事になり、何が欲しいかと訪ねる。曽呂利新左衛門、なかなかに頓知の聞いた人物で、米1粒を頂きたい、そして明日は米2粒、その次の日は4粒、そのまた次の日は8粒。日を追う毎に倍々の米粒を欲しいと申し出る。それを聞いた秀吉公、なんとたわいもない事、望みを聞いてつかわそう、とおっしゃったとか。

     この望みが非常に問題を含んだものであることは、説明するまでもなかろう。半年もたたずして、日本全国の米を集めても、その望みに応えられなくなることは想像に難くない。ネズミ講も似た話、いわゆるネズミ算の問題である。

     話し変わって、ここ一月、ちょっとした病を患い何もする気が起こらずに、自宅のサーバーの動作監視を怠っていた。久しぶりにpsコマンドで動作プロセスを確認して見ると、毎朝4時過ぎに動作する/etc/cron.daily/の中のlogrotateプロセスが、24時間を過ぎても終了せずに残っている。これが一つではなく幾つも動いたまま。取り合えず、killした上で、/usr/sbin/logrotate -dv /etc/logrotate.conf と手動で、デバッグオプションを付けて起動してみた。すると/var/log/mailman/ディレクトリのログファイルの処理でだんまりになる。/var/log/mailman/に移動し、lsコマンドを叩いてみると、数分間もディスクアクセスした後、ずらずらずらっと、error.1.1.1.1......., error.2.1.... のようなファイル一覧がスクリーンを流れる。その数、数千、数万以上か。一体何が起こったのか?

     logrotateコマンドの動作を制御するファイルを納めた/etc/logroate.d/ディレクトリの中のmailmanの設定を見てみると、ログをローテートする対象ファイルの指定が"/var/log/mailman/*"とワイルドカード指定となっている。/var/log/mailman/のログディレクトリには、システムインストール直後には、errorという名前のファイルが一つだけ存在する。/etc/logrotate.confでは4世代のログをローテートする設定になっている。以上から/var/log/mailman/ディレクトリの中に数千以上のファイルが出来上がったメカニズムは次のとおりと想像できる。

     一番最初、一個のファイル/var/log/mailman/errorをlogrotateは、errorとerror.1の2つのファイルにローテートする。次の動作の時、logrotateは errorとerror.1とerror.2と2世代ローテートする。これで終われば問題ないが、対象ファイルが"/var/log/mailman/*"とワイルド指定されているため、2回目の動作の時に、error.1 のローテートも行い、error.1.1というファイルを生成してしまう。3回目の時は、error、error.1、error.2、error.3、error.1.1、error.1.2、error.2.1、error.1.1.1とファイルが出来る。その次には、.... まだ4回目なのに書くのも面倒な程ファイルができる。こんな調子で10回、20回と繰り返せば一体どうなるか。そう、曽呂利新左衛門の再来である。高速なCPU、豊富なメモリを搭載したマシンが、24時間かかっても処理できない程のファイルが、いつしか生成されてしまうのである。

     修正は簡単、/var/log/mailman/の中のファイルを削除するか、ローテート対象を/var/log/mailman/*のワイルドカード指定から/var/log/mailman/errorと正しい指定に変更すれば良い。さて、/var/log/mailman/の中のファイルの削除が大変、/var/log/mailman/ディレクトリでrm *としても、コマンドライン引数の展開エラーが出て削除できない。/var/log/ディレクトリにて rm -r mailman と、一旦デイレクトリごと削除し、mkdir mailman とディレクトリを作り直して完了。その後のサーバーの調子はすこぶる良い。