logrotateのcopytruncateによる記入漏れ検証

はじめに

アルバイトのajikiです。ログを管理するのにloglotateを使う際、ログファイルにクローズを要求できないために、前のログファイルに永久に書き込まれてしまうという場合があります。そんな時に、copytruncateオプションを使えば、別ファイルにコピー＆中身の削除をしてくれるので便利です。古いログを吐き出すときは

1. ログ1をログ2に複製して別で残す
2. ログ1の中身を削除し、ログ1への記録が再開する

となっているためコピー＆切り捨ての短い空白の時間が発生するわけですが、この「ログ出力しながらのtruncateはどの程度の出力頻度までなら漏れなく記録できるのか？」 という疑問について検証してみました。

実行環境

awsのec2を使用しており、スペックは以下の通りとなっております。

インスタンス	t3.micro
メモリ	2GB
CPU	2コア
ebsタイプ	gp2

先に結論から

ひとまず、結論としては毎秒350件以上の書き込みを行うと漏れが発生するという結果になりました。実行環境に依存して、一定件数以上で漏れが発生することがあるため気を付けましょう。以下で検証の詳細を説明します。

ログローテーションとは?

”ログローテーションとは、システムが残す時系列の記録データ（ログ）が際限なく増えることを防ぐために、一定の容量や期間ごとに古いログを削除したり新しいログで上書きすること。また、そのような機能。”

ログは、特定のストレージに記録していく方式だと、いつの間にか容量を圧迫して、正常な動作に支障をきたす原因になることがあります。そうならないために、一定期間を過ぎたり、ファイルサイズが一定の容量を超えたら自動的に最も古いログを削除したりすることを"ログローテーション"といいます。これらのログを残す機能は、ソフトウェア自身に元々備わっていて、設定を有効にすることで自動的にローテートできる場合もありますが、そうでない場合も専用のツールを導入することで外部からローテートさせることができます。Linuxでは「loglotate」というツールが有名です。

loglotateの設定

/home/dev/logrotate_test.log {
  ifempty
  missingok
  rotate 8
  compress
  delaycompress
  copytruncate
  olddir old_log
  createolddir
}

設定ファイルの中身です。今回は "/etc/logrotate.d/logrotate_test" として設置しました。内容は、以下の通りとなっています。

項目	意味
/home/dev/logrotate_test.log	対象ログのファイルパスを指定
ifempty	ログファイルが空の場合は新規作成する
missingok	対象のログファイルが存在しない場合でもエラーを吐かずに次の処理に進む
rotate n	n周期分のログファイルを消さずに残す
compress	古いログをgzip圧縮する
delaycompress	1周期分のログは圧縮しない
copytruncate	既存ログファイル名を変更、新規ログファイルを作成するのではなく、既存ログファイルを複製、中身を削除する
olddir old_log	古いログを特定のディレクトリに移動する
createolddir	olddirで指定したディレクトリが無い場合は新規作成する

検証方法

1. インクリメントしながら定期的にログを記録するshell起動
2. sleep 1
3. `loglotate -f 設定ファイルパス` でローテーションさせる
4. sleep 1
5. 起動したshellを停止
6. 過去ログ最終行と最新ログ先頭行の数字に抜けがないかチェック

以上の工程で検証しました。

余談

検証には↓のようなshellを使って引数にsleepする間隔を指定しながら行いました。0.002と指定すると、500件書き込まれるのが期待だったのですが、334件しか書き込まれていませんでした。おそらく読み込みなどが要因で0.3秒近くロスしていました。

定期的にlogに出力するshell

$ cat logrotate_test.sh
i=1
while true
do
  echo $i
  sleep $1
  i=$(($i+1));
done

truncateの記入漏れチェック用shell

$ cat correct_check_logrotate.sh
echo -n > logrotate_test.log
bash logrotate_test.sh $1 > logrotate_test.log &
sleep 1
logrotate -f /etc/logrotate.d/logrotate_test
sleep 1
pkill -f logrotate_test.sh
echo "↓old_log最終行"
tail -n 1 old_log/logrotate_test.log.1
echo "↓new_log先頭行"
head -n 1 logrotate_test.log

実行結果

$ bash correct_check_logrotate.sh 0.0015
↓old_log最終行
379
↓new_log先頭行
381
$ bash correct_check_logrotate.sh 0.002
↓old_log最終行
334
↓new_log先頭行
335

検証結果

結論で先に述べた通り、毎秒350件以上の書き込みを行うと漏れが発生し毎秒300件ぐらいだと漏れが発生しないという結果になりました。ログ管理の参考になれば幸いです。