tl;dr
RubyのLoggerクラスのログローテーションの実装を調べた勉強メモです。
仕様
RubyのLoggerクラスはログローテーションの機能が入っています。
Rubyist Magazine - 標準添付ライブラリ紹介 【第 2 回】 Logger が参考になります。
例えば
Logger.new('foo.log', 'daily')
と呼び出せば、日毎にローテーションします。
実装の概説
疑問
ログローテーションの実装で気になるのは
- ログをローテーションするトリガー
- ローテーションの書き込みロック
の二点です。
Loggerの実装
- 毎書き込み毎にローテーションするかのチェック
- ローテーション中に他のスレッドから書き込みされないように、Synchronizationで保護
- 他プロセスからの書き込みはOSのファイルロックで保護
処理の流れ
実際の順序は多少入れ替わっています。
- ログの書き込みAPIはSynchronizationを使って、マルチスレッドの衝突を回避している
- 書き込む直前に、ローテーション対象か判定する
- ローテーションが必要な場合は
- ファイルのロックを取得する（Windowsの場合は違う。何もしていない？）
- ファイルをリネームする
- 新しいログファイルを作る
- ログを書き込む
実装の詳細
ソースコードを見ながら参照
Synchronization
def write(message)
begin
synchronize do
if @shift_age and @dev.respond_to?(:stat)
begin
check_shift_log
rescue
warn("log shifting failed. #{$!}")
end
end
begin
@dev.write(message)
rescue
warn("log writing failed. #{$!}")
end
end
rescue Exception => ignored
warn("log writing failed. #{ignored}")
end
end
writeの先頭でsynchronizeして、次にcheck_shift_logします。
ローテーションする？
def check_shift_log
if @shift_age.is_a?(Integer)
# Note: always returns false if '0'.
if @filename && (@shift_age > 0) && (@dev.stat.size > @shift_size)
lock_shift_log { shift_log_age }
end
else
now = Time.now
if now >= @next_rotate_time
@next_rotate_time = next_rotate_time(now, @shift_age)
lock_shift_log { shift_log_period(previous_period_end(now, @shift_age)) }
end
end
end
@shift_ageが数値であれば、サイズでチェック、そうでなければ日付でチェックします。
ローテーション
ファイルロック
if /mswin|mingw/ =~ RUBY_PLATFORM
def lock_shift_log
yield
end
else
def lock_shift_log
retry_limit = 8
retry_sleep = 0.1
begin
File.open(@filename, File::WRONLY | File::APPEND) do |lock|
lock.flock(File::LOCK_EX) # inter-process locking. will be unlocked at closing file
if File.identical?(@filename, lock) and File.identical?(lock, @dev)
yield # log shifting
else
# log shifted by another process (i-node before locking and i-node after locking are different)
@dev.close rescue nil
@dev = open_logfile(@filename)
@dev.sync = true
end
end
rescue Errno::ENOENT
# @filename file would not exist right after #rename and before #create_logfile
if retry_limit <= 0
warn("log rotation inter-process lock failed. #{$!}")
else
sleep retry_sleep
retry_limit -= 1
retry_sleep *= 2
retry
end
end
rescue
warn("log rotation inter-process lock failed. #{$!}")
end
end
mswin|mingw、つまりWindowsでは何もしません。
そうでなければlock.flock(File::LOCK_EX)で排他ロックします。
他プロセスからの読み書きを禁止します。
ファイルリネーム
def shift_log_age
(@shift_age-3).downto(0) do |i|
if FileTest.exist?("#{@filename}.#{i}")
File.rename("#{@filename}.#{i}", "#{@filename}.#{i+1}")
end
end
@dev.close rescue nil
File.rename("#{@filename}", "#{@filename}.0")
@dev = create_logfile(@filename)
return true
end
@shift_ageの数だけログを残すために、***.n ファイルの n をひとつずつ増やして行きます。
その後、現在のログファイルのファイル名の末尾に、.0を追加します。
新しいログファイルを作る
def create_logfile(filename)
begin
logdev = File.open(filename, (File::WRONLY | File::APPEND | File::CREAT | File::EXCL))
logdev.flock(File::LOCK_EX)
logdev.sync = true
add_log_header(logdev)
logdev.flock(File::LOCK_UN)
rescue Errno::EEXIST
# file is created by another process
logdev = open_logfile(filename)
logdev.sync = true
end
logdev
end
File.openでログファイルを作って、ヘッダーを書き込んで、作ったファイルオブジェクトを返します。
ログを書き込む
writeメソッドに戻って、@dev.write(message)します。
Loggerの使われ方
多くのWebアプリケーションフレームワークはLoggerインスタンスを受け取ります。Ruby共通のログローテーションの仕組みが使えます。
Ruby on Rails
Ruby on Railsで使われているActiveSupport::Loggerは、RubyのLoggerクラスを継承しています。
Rack
RackのRack::CommonLoggerは
logger can be any class, including the standard library Logger, and is expected to have either write or << method
とあり、writeメソッドか<<メソッドを持っているクラスはなんでも指定できます。Loggerクラス（writeメソッドを持っている）か、IOクラス（<<を持っている）を想定していそうです。
実際の実装はこんな感じです。
if logger.respond_to?(:write)
logger.write(msg)
else
logger << msg
end