mirror of
https://github.com/ruby/ruby.git
synced 2022-11-09 12:17:21 -05:00

Issue only occurs in JRuby 9.3.0.0 and Windows and the full
console output is:
log rotation inter-process lock failed. D:\log.txt -> D:\log.txt.0: The process cannot access the file because it is being used by another process.
log writing failed. closed stream
log writing failed. closed stream
...
19fc734638
205 lines
5.6 KiB
Ruby
205 lines
5.6 KiB
Ruby
# frozen_string_literal: true
|
|
|
|
require_relative 'period'
|
|
|
|
class Logger
|
|
# Device used for logging messages.
|
|
class LogDevice
|
|
include Period
|
|
|
|
attr_reader :dev
|
|
attr_reader :filename
|
|
include MonitorMixin
|
|
|
|
def initialize(log = nil, shift_age: nil, shift_size: nil, shift_period_suffix: nil, binmode: false)
|
|
@dev = @filename = @shift_age = @shift_size = @shift_period_suffix = nil
|
|
@binmode = binmode
|
|
mon_initialize
|
|
set_dev(log)
|
|
if @filename
|
|
@shift_age = shift_age || 7
|
|
@shift_size = shift_size || 1048576
|
|
@shift_period_suffix = shift_period_suffix || '%Y%m%d'
|
|
|
|
unless @shift_age.is_a?(Integer)
|
|
base_time = @dev.respond_to?(:stat) ? @dev.stat.mtime : Time.now
|
|
@next_rotate_time = next_rotate_time(base_time, @shift_age)
|
|
end
|
|
end
|
|
end
|
|
|
|
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
|
|
|
|
def close
|
|
begin
|
|
synchronize do
|
|
@dev.close rescue nil
|
|
end
|
|
rescue Exception
|
|
@dev.close rescue nil
|
|
end
|
|
end
|
|
|
|
def reopen(log = nil)
|
|
# reopen the same filename if no argument, do nothing for IO
|
|
log ||= @filename if @filename
|
|
if log
|
|
synchronize do
|
|
if @filename and @dev
|
|
@dev.close rescue nil # close only file opened by Logger
|
|
@filename = nil
|
|
end
|
|
set_dev(log)
|
|
end
|
|
end
|
|
self
|
|
end
|
|
|
|
private
|
|
|
|
def set_dev(log)
|
|
if log.respond_to?(:write) and log.respond_to?(:close)
|
|
@dev = log
|
|
if log.respond_to?(:path)
|
|
@filename = log.path
|
|
end
|
|
else
|
|
@dev = open_logfile(log)
|
|
@dev.sync = true
|
|
@dev.binmode if @binmode
|
|
@filename = log
|
|
end
|
|
end
|
|
|
|
def open_logfile(filename)
|
|
begin
|
|
File.open(filename, (File::WRONLY | File::APPEND))
|
|
rescue Errno::ENOENT
|
|
create_logfile(filename)
|
|
end
|
|
end
|
|
|
|
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
|
|
logdev.binmode if @binmode
|
|
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
|
|
|
|
def add_log_header(file)
|
|
file.write(
|
|
"# Logfile created on %s by %s\n" % [Time.now.to_s, Logger::ProgName]
|
|
) if file.size == 0
|
|
end
|
|
|
|
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
|
|
|
|
if /mswin|mingw|cygwin/ =~ RbConfig::CONFIG['host_os']
|
|
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
|
|
|
|
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
|
|
|
|
def shift_log_period(period_end)
|
|
suffix = period_end.strftime(@shift_period_suffix)
|
|
age_file = "#{@filename}.#{suffix}"
|
|
if FileTest.exist?(age_file)
|
|
# try to avoid filename crash caused by Timestamp change.
|
|
idx = 0
|
|
# .99 can be overridden; avoid too much file search with 'loop do'
|
|
while idx < 100
|
|
idx += 1
|
|
age_file = "#{@filename}.#{suffix}.#{idx}"
|
|
break unless FileTest.exist?(age_file)
|
|
end
|
|
end
|
|
@dev.close rescue nil
|
|
File.rename("#{@filename}", age_file)
|
|
@dev = create_logfile(@filename)
|
|
return true
|
|
end
|
|
end
|
|
end
|