先日ログローテートしてるファイルがバイナリになってしまうという事象が発生した。
それについて色々と検証してみたので備忘録として残しておきます。
プログラムがログファイルを掴みっぱなしの状態でローテートされると発生する
早い話が、
アプリのプログラムがログファイルを掴んだままの状態でローテートがされた場合、
ローテート後、新たにログを吐き出す際にファイルポインタがローテートされる前の状態で保持されていて、
ファイルの先頭からそのポインタまでの行をバイナリで埋めることがある。
「え、まじで？」
となりますよね。
試してみましょう。
いざ実証
ログファイルを掴み続けるプログラムを作成
rotate_test.plを作成し下記の内容を記載します。
|
1 2 3 4 5 6 7 8 9 10 |
#! /usr/bin/perl use IO::Handle; open my $fh, ">", "/tmp/test.log"; $fh->autoflush; while() { print $fh "aaa\n"; sleep 1; } close $fh; |
を用意します。
open my $fh, ">", "/tmp/test.log";
のところで、
">"
こうしているのがミソです。この状態だとファイルを掴みっぱなしにすることができます。
蛇足ですが、
perlはデフォだと出力する内容をバッファリングした上でファイル出力するため、
$fh->autoflush;
で都度書き込むようにしてます。
こいつを、
perl rotate_test.pl
で実行してみます。
これで1秒毎に、
/tmp/test.log
というファイルに"aaa"という内容が出力され続けます。
いったん、
ctrl + c
で止めておきましょう。
手動でrotateさせる
基本的にログローテートは定期的に実行しているものなのですが、
今回はそんな定期実行を待ってられないので手動で実行させます。
/etc/logrotate.d/test
というファイルを作成し、下記の内容記載させます。
|
1 2 3 4 5 6 7 |
/tmp/test.log { daily rotate 2 missingok copytruncate } |
詳しい意味はググってみてくださいませ。
そしたら、
logrotate -f /etc/logrotate.d/test
で実行します。
（rootじゃないと実行できないかもです）
/tmp/test.log.1
が出来上がっていると思います。
ここからが本番
ターミナルを2つ開き、
片方では、
perl rotate_test.pl
を実行させてログを吐かせ続けましょう。
ある程度ログを吐いたら、
もう片方のターミナルで、
logrotate -f /etc/logrotate.d/app
を叩きます。
これで、
プログラムがファイルを掴んでいる状態で、ローテートを実行
という状況を再現できました。
確認
vi /tmp/test.log
でファイルを見ると、
先頭によくわからないバイナリがうめられていると思います。
アプリがログを掴み続けないようにする方法
(´・ω・`)知らんがな
って感じですが、
今回のプログラムの場合、
open my $fh, ">", "/tmp/test.log";
を
open my $fh, ">>", "/tmp/test.log";
という形追記風にすることで問題なくローテートされます。
以上です
半信半疑で試してみたのですが再現したのでなんか楽しかったです。
また下記のサイトの情報がとても参考になりました。
ありがてぇ、ありがてぇ。
今日の一言
自分でこうやって検証することって結構大事ってのはわかってはいてもなかなかいざ、
「やるぞ！」
とはならないんですよね。わかりますよ。