aegif Labo Blog: CentOS6.4でcatalina.outのlogrotateに失敗した話（と育休取ってますよという話）

こんにちは。昨年末に第二子が産まれててんやわんやの大谷です。

3年前にも同じ状況になっていたはずですが（第一子のときです）、諸々を完全に忘れていてミルクの作り方からオムツのかえ方、沐浴の仕方など、ほぼ0から覚えなおす日々を送っております。
が、幸いなことに弊社は父親でも（本人さえ望めば）育休を取得できるため、1月から2-3か月ほど育休を取得させてもらっています。育児休業と言っても全休ではないので、ある程度在宅orオフィスで仕事をして、残りは嫁と共に子供の面倒を見るという形になります。まあチームメンバーにはそれなりに迷惑を掛けることになるのですが、そこはごめんなさいということで…。
というわけで、本年も引き続きどうぞよろしくお願いいたします。

さて、2014年最初のエントリですが、CentOS6.4でTomcatのcatalina.outをログローテーションしようとしてうまくいかなかった話をしようと思います。結論から言うと、anacronのcron.dailyで動いているlogrotateの動作をSELinuxが邪魔していたというとても基本的かつ残念なお話しになっています…。年初から冴えない！

catalina.outのログローテーション設定

TomcatのJavaプロセスの標準出力、標準エラー出力をcatalina.outにリダイレクトしており（cataliha.shに記述されているとおりです）、このログをlogrotateを使ってローテーションさせます。

以下、具体的なログローテーションの設定方法です。

1. logrotate用設定ファイルの作成

はい、シンプルです。日次でローテーションして60日分ログを保管します。catalina.outはjavaプロセスがずっと掴んでいるため、copytruncateオプションを使っています。

# vi /etc/logrotate.d/tomcat

# logrotate file for Tomcat
/opt/liferay/tomcat/logs/catalina.out {
  missingok
  copytruncate
  daily
  dateext
  rotate 60
}

2. 設定ファイルの権限変更

権限を0644にしときます。

# chmod 0644 /etc/logrotate.d/tomcat

設定は以上です。続いて動作確認をしてみましょう。

logrotateの動作確認

動作確認には以下のように3つのレベルがあります。早速１つずつチェックしていきましょう。

1. logrotateの設定テスト

# logrotate -d /etc/logrotate.d/tomcat

このコマンドでlogrotateの実行をテストすることができます。テストなので実際に処理は行われません。出力結果に"log needs rotating"とあれば正しく設定されています。

2. logrotate単体での動作確認

# logrotate -f /etc/logrotate.d/tomcat

このコマンドで特定のログについてlogrotateを強制実行することができます。catalina.out-yyyymmdd というファイルにcatalina.outの内容がコピーされ、catalina.outが0バイトになっていればローテーション成功です。
過去の日付の名前のファイル（もちろんtouch -dでタイムスタンプも古くしておく）を予め用意しておけば、ログ削除のテストもできます。

ちなみに、立て続けにlogrotate -fを実行しても、2回目以降はローテーション処理が行われません。理由は以下の2つです。

前回ローテーションした日付が記録されている

/var/lib/logrotate.status に"/opt/liferay/tomcat/logs/catalina.out yyyy-mm-dd" のように記録されているので、再度実行する場合は編集して古い日付にしておきましょう

ローテーション先のファイル名が既に存在している

catalina.out-yyyymmddのような同名ファイルがあると処理をスキップするので、再度実行する場合はリネームしておきましょう

3. cron.dailyを通じた動作確認

# anacron -f

CentOS6.4の標準インストールでは、logrotateは日次のcron.dailyの1処理として実行され、cron.dailyの実行はanacronによってコントロールされています。そこで、このコマンドでcron.daily実行の強制スケジューリングを行います。
/var/log/cron に"Will run job `cron.daily' in xx min."と出力されるので、いつcron.dailyが実行されるかチェックしておきましょう。もちろん前述のlogrotate.status編集&ログリネームはやっておいてください。

その時間あたりに /var/log/cron をtailしていればlogrotateが実行されたことが分かるので、完了したらcatalina.outを確認してみましょう。先ほどと同様、ファイル catalina.out-yyyymmdd が生成されていればOKです。

実際に運用してみると…

さて、全ての動作確認をクリアしたので実際に運用してみよう。というわけで次の日にlogsフォルダを見てみると…はい、ありませんでした。ローテーションしたはずの catalina.out-yyyymmdd が無い！anacron -fのテストも通ったのに、何故か無い…

というわけで色々調べていったら確かにありましたよ原因。原因は、一番最初に話した通り、SELinuxでした。/var/lib/audit/audit.logを見ると、以下のようなログが出てました。

type=AVC msg=audit(1387149242.691:29032): avc: denied { write } for pid=3826 comm="logrotate" name="catalina.out" dev=dm-0 ino=87986 scontext=system_u:system_r:logrotate_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:admin_home_t:s0 tclass=file

はい。見事にlogrotateのcatalina.outへの書き込みが拒否されてます。こんなところに影響あるのかSELinux！

というわけで、SELinuxを無効化します。反映させるにはサーバ再起動が必要です（一時的に無効にするにはsetenforce 0でもOK）。

# vi /etc/sysconfig/selinux

SELINUX=disabled

これで一晩待てば、無事ローテーションしてるはず、というわけで、手元の環境では無事ローテーションが確認できました。

まとめ！

問答無用でSELinuxはOFF！とは言いませんが、必要に応じてONにしましょうというあまりにも基本的なまとめになってしまいましたが、同じ問題で悩んでいる人の参考になれば幸いです（いるのか！）。

aegif Labo Blog

Wednesday, January 8, 2014

CentOS6.4でcatalina.outのlogrotateに失敗した話（と育休取ってますよという話）