logroateの話

=====

アプリケーションサーバを並べてリクエストを受けていたんだけど、
ログの量が多すぎてCPU使い切る前にdiskがいっぱいになりそう。

でかいdiskをattachしてもいいんだけど、
金かけずに手っ取り早くできることはないかって見たときに
logrotate.dの設定の中にdelaycompressがあり、
1日前のログが圧縮されずにあったのでこれをはずすことに。

(logrotateのhourlyはcron周りいじるのが面倒であと回し)

調査ログ

logrotate.dに入ってるアプリケーションログの設定は

/path/to/production.log
{
  daily
  create
  missingok
  rotate 7
  compress
  dateext
  delaycompress

  lastaction
    unicorn_pid=/path/to/unicorn.pid
    test -s $pid && kill -USR1 "$(cat $unicorn_pid)"
  endscript
}

元のconfの作成の経緯はわからなかったので
ぱぱっと調べたlogrotateの動作は

1. firstaction script
2. prerotate script
3. rename
4. postrotate script
5. compress
6. lastaction script

な感じで、compressがlastactionの前にあるとしたら
既存の設定では

i. ログがrotate(rename) される
ii. ログの圧縮が実行される(結構時間がかかる)
iii. アプリケーションがシグナルを受け取りログを切り替える

という流れに...。
2のログの圧縮に時間がかかると
fluentd(v1)とかどうなるんだろうと思いそちらも見てみると

in_tail pluginでは

• timerとtail pathのstatの変化をtriggerにしてログファイルをチェック
• メモリ上の値とFile openした値をinodeとsizeで比較
• 変化があるとそちらをtail対象に変更
• 元のファイルはrotate_waitだけtailする
  • default 5秒

というわけで、compressが長いとまずいんじゃないか？と不安が。

現在も圧縮は数分単位でかかっているので、
既にログの取りこぼしがあるのではと思い確認してみるが特になし...

何か勘違いがありそうなので、logrotateの中身を確認してみると
認識が異なる点があった

1. firstaction script
2. prerotateSingleLog function

• 過去にrotateされたログのrename
• delaycompressがある場合はここで圧縮
  • 圧縮が完了すると元ログの削除
• rotate で指定された値を超えたログの削除

1. prerotate script
2. rotateSingleLog function

• 最新のファイルのrename
• createがあればファイルの作成

1. postrote script
2. postrotateSignleLog function

• renameされた最新のファイルの圧縮
  • 圧縮が完了すると元ログの削除

1. lastaction script

というわけで、実際は delaycompress は最新のファイルの
rename & create より早く圧縮が実施されているので問題なさそう

delaycompress だけ削除すると圧縮に時間がかかると
renaming からシグナルを送信が遅くなりそうだったので、
lastaction script から postrotate script に処理を移動することに。

delaycompress は man 見るとシグナルを受けてすぐログを離さない場合に使ってね
的なことが書いてあるので、つけるかつけないか気をつける必要はありそう。

今回の場合は
シグナルで比較的すぐにログの切り替えが発生するし、
圧縮からログの削除までは少し猶予がありそう、
fluentdは5秒くらいは古いログをケアしてくれそう
というわけで、大丈夫そう。

とりあえず入れた感じ、ぱっと見は問題なさそう。
問題あったら追記する。