安全なログローテーション
ログローテーションの落とし穴
Rails でのデフォルトのロガーは、Ruby 標準添付の Logger クラスを少し変えたものである。ログのサイズが大きくなったとき、サイズやら日付やらを基準にログのアーカイブ化を行う(ログローテーション)することが多い。一番簡単な方法は
みたいなやり方だ。しかし、複数の Ruby インスタンスがひとつのログファイルを共有すると、うまく動かないのだ。典型的なのは Mongrel Cluster で複数の Rails インスタンスを運用している状況だ。ログローテーションが起こった直後から、"Status: 500 Internal Server Error" というエラーメッセージを吐いて Rails アプリが動かなくなってしまう。
これは、Logger がローテーション時に、
- 現行のログファイルをアーカイブログファイルにリネームし、((例) development.log => development.log.20071007)
- 現行のログファイル名と同名のファイル名を新たに作成する ((例) development.log を新規作成)
という手順を実行しているからである。複数の Ruby インスタンスのひとつ(プロセスAと呼ぼう)が何らかの基準に基づいて、ログローテーションを行った後でも、他の Ruby インスタンス(プロセスBと呼ぼう)は、古いログファイル(上の例ではリネームされた development.log.20071007) を現行のログファイルと認識している。プロセスAがログローテーションを行ったにもかかわらず、プロセスB は自分へのログ書き込み指令の際に、さらにもういちどログローテーションを行おうとする。しかし、すでにリネームされたアーカイブ用のログファイルが存在するのでエラーとなるのだ。
パッチ
上の問題を解決するために下のようなパッチを書いてみた。Rails では、とりあえず config/environment.rb の末尾に配置すればよい。(Rails は必須ではなく、Ruby 単体からもこのパッチは利用できる)
# 複数の Ruby インスタンスがひとつのログファイルを共有している状況で、 # 安全にログローテーションを実現する。 require 'fileutils' class Logger::LogDevice def shift_log_age_with_safe_log_rotation (@shift_age-3).downto(0) do |i| if FileTest.exist?("#{@filename}.#{i}") File.rename("#{@filename}.#{i}", "#{@filename}.#{i+1}") end end FileUtils.cp("#{@filename}", "#{@filename}.0") File.truncate @filename, 0 add_log_header(@dev) return true end def shift_log_period_with_safe_log_rotation(now) postfix = previous_period_end(now).strftime("%Y%m%d") # YYYYMMDD age_file = "#{@filename}.#{postfix}" if FileTest.exist?(age_file) raise RuntimeError.new("'#{ age_file }' already exists.") end FileUtils.cp("#{@filename}", age_file) File.truncate @filename, 0 add_log_header(@dev) return true end alias_method :shift_log_age_without_safe_log_rotation, :shift_log_age alias_method :shift_log_age, :shift_log_age_with_safe_log_rotation alias_method :shift_log_period_without_safe_log_rotation, :shift_log_period alias_method :shift_log_period, :shift_log_period_with_safe_log_rotation end
要するに
- 現行のログファイルをアーカイブログファイルにコピーし、(≒ cp development.log development.log.20071007)
- 現行のログファイルのファイルサイズを0にする。 (≒ cat < /dev/null > development.log)
としているだけである。現行のログファイルの実体が変更されないため、複数 Ruby インスタンスに共有されても誤動作しないはずである。