Posted at

Rubyでのログローテーション

More than 1 year has passed since last update.


tl;dr

RubyのLoggerクラスのログローテーションの実装を調べた勉強メモです。


仕様

RubyのLoggerクラスはログローテーションの機能が入っています。

Rubyist Magazine - 標準添付ライブラリ紹介 【第 2 回】 Logger が参考になります。

例えば

Logger.new('foo.log', 'daily') 

と呼び出せば、日毎にローテーションします。


実装の概説


疑問

ログローテーションの実装で気になるのは


  • ログをローテーションするトリガー

  • ローテーションの書き込みロック

の二点です。


Loggerの実装


  • 毎書き込み毎にローテーションするかのチェック

  • ローテーション中に他のスレッドから書き込みされないように、Synchronizationで保護

  • 他プロセスからの書き込みはOSのファイルロックで保護


処理の流れ

実際の順序は多少入れ替わっています。


  1. ログの書き込みAPIはSynchronizationを使って、マルチスレッドの衝突を回避している

  2. 書き込む直前に、ローテーション対象か判定する

  3. ローテーションが必要な場合は


    1. ファイルのロックを取得する(Windowsの場合は違う。何もしていない?)

    2. ファイルをリネームする

    3. 新しいログファイルを作る



  4. ログを書き込む


実装の詳細

ソースコードを見ながら参照


Synchronization

https://github.com/ruby/ruby/blob/f2aa7f409aa2130888ceed21d128523e4392084a/lib/logger.rb#L686

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します。


ローテーションする?

https://github.com/ruby/ruby/blob/f2aa7f409aa2130888ceed21d128523e4392084a/lib/logger.rb#L773

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が数値であれば、サイズでチェック、そうでなければ日付でチェックします。


ローテーション


ファイルロック

https://github.com/ruby/ruby/blob/f2aa7f409aa2130888ceed21d128523e4392084a/lib/logger.rb#L788

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)で排他ロックします。

他プロセスからの読み書きを禁止します。


ファイルリネーム

https://github.com/ruby/ruby/blob/f2aa7f409aa2130888ceed21d128523e4392084a/lib/logger.rb#L824

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を追加します。


新しいログファイルを作る

https://github.com/ruby/ruby/blob/f2aa7f409aa2130888ceed21d128523e4392084a/lib/logger.rb#L752

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