Edited at

Loggerを使用している場合にFakeFSを使ったらNotImplementedErrorが発生する

More than 3 years have passed since last update.


Intro

FakeFS

tee_loggerというGemのテストをしていて、RSpecでFakeFS使ったらはまったのでメモしておく。

require 'logger'

require 'fakefs'

Logger.new('log.log') # => NotImplementedError: NotImplementedError


原因

NotImplementedError: NotImplementedError

{your_app_path}/vendor/bundle/ruby/2.2.0/gems/fakefs-0.6.7/lib/fakefs/file.rb:462:in `flock'

flockはFakeFSではエラーを返すように実装されている。

https://github.com/defunkt/fakefs/blob/master/lib/fakefs/file.rb#L461

    def flock(*)

fail NotImplementedError
end

なぜにLogger.newで怒られるのかというと、ログファイルを文字列で指定したため、Loggerの中でファイル作成、オープンした際にflockを実行しているため。


対応

とりあえず下記のようにして回避した。

file.sync = trueはファイルを閉じるかfile.flushとかしないとファイルに書き込まれないため。

Loggerの中でファイル操作した場合も@dev.sync = trueとかlogdev.sync = trueとかしてる。

require 'logger'

require 'fakefs'

file = File.open('log.log', 'w+')
file.sync = true
logger = Logger.new(file)
logger.debug 'hello'


Loggerのソースを追ってみる

まずLogger.newで下記のinitializeが実行される。

https://github.com/ruby/ruby/blob/ruby_2_2/lib/logger.rb#L311

  def initialize(logdev, shift_age = 0, shift_size = 1048576)

@progname = nil
@level = DEBUG
@default_formatter = Formatter.new
@formatter = nil
@logdev = nil
if logdev
@logdev = LogDevice.new(logdev, :shift_age => shift_age,
:shift_size => shift_size)
end
end

で、LogDevice.newで下記のinitialize

https://github.com/ruby/ruby/blob/ruby_2_2/lib/logger.rb#L578

    def initialize(log = nil, opt = {})

@dev = @filename = @shift_age = @shift_size = nil
@mutex = LogDeviceMutex.new
if log.respond_to?(:write) and log.respond_to?(:close)
@dev = log
else
@dev = open_logfile(log)
@dev.sync = true
@filename = log
@shift_age = opt[:shift_age] || 7
@shift_size = opt[:shift_size] || 1048576
@next_rotate_time = next_rotate_time(Time.now, @shift_age) unless @shift_age.is_a?(Integer)
end
end

logdevにファイル名の文字列を渡しているのでlogも文字列。

よってif log.respond_to?(:write) and log.respond_to?(:close)はfalseなのでopen_logfileが実行される。

https://github.com/ruby/ruby/blob/ruby_2_2/lib/logger.rb#L626

    def open_logfile(filename)

begin
open(filename, (File::WRONLY | File::APPEND))
rescue Errno::ENOENT
create_logfile(filename)
end
end

で、ファイルが存在しないのでrescuecrate_logfileの実行になり

https://github.com/ruby/ruby/blob/ruby_2_2/lib/logger.rb#L626

    def create_logfile(filename)

begin
logdev = 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

で、flock


未確認事項

https://github.com/ruby/ruby/blob/ruby_2_2/lib/logger.rb#L680

上記でもflockが見えるけど、そこまでは追いかけてません。