From d17031f41a3deaf2bb1e9855a7f76521a974409d Mon Sep 17 00:00:00 2001 From: nahi Date: Sat, 20 Aug 2005 13:43:46 +0000 Subject: * lib/logger.rb (write, shift_log?, shift_log): file shifting race condition bug fixed. [ruby-dev:26764] * test/logger/test_logger.rb: tests. git-svn-id: svn+ssh://ci.ruby-lang.org/ruby/branches/ruby_1_8@9011 b2dd03c8-39d4-4d8f-98ff-823fe69b080e --- ChangeLog | 7 +++ lib/logger.rb | 129 ++++++++++++++++++++++----------------------- test/logger/test_logger.rb | 78 ++++++++++++++++++++++++--- 3 files changed, 141 insertions(+), 73 deletions(-) diff --git a/ChangeLog b/ChangeLog index df9603936f..7d39cdca13 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,10 @@ +Sat Aug 20 22:37:13 2005 NAKAMURA, Hiroshi + + * lib/logger.rb (write, shift_log?, shift_log): file shifting race + condition bug fixed. [ruby-dev:26764] + + * test/logger/test_logger.rb: tests. + Fri Aug 19 18:13:39 2005 Tanaka Akira * lib/time.rb (Time.apply_offset): fix a problem with last day of diff --git a/lib/logger.rb b/lib/logger.rb index 1162e31f3c..52e5a45684 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -1,4 +1,7 @@ -# +# logger.rb - saimple logging utility +# Copyright (C) 2000-2003, 2005 NAKAMURA, Hiroshi . + + # = logger.rb # # Simple logging utility. @@ -19,7 +22,6 @@ # # The Logger class provides a simple but sophisticated logging utility that # anyone can use because it's included in the Ruby 1.8.x standard library. -# For more advanced logging, see the "Log4r" package on the RAA. # # The HOWTOs below give a code-based overview of Logger's usage, but the basic # concept is as follows. You create a Logger object (output to a file or @@ -76,10 +78,6 @@ # specifying a program name in conjunction with the message. The next section # shows you how to achieve these things. # -# See http://raa.ruby-lang.org/list.rhtml?name=log4r for Log4r, which contains -# many advanced features like file-based configuration, a wide range of -# logging targets, simultaneous logging, and hierarchical logging. -# # # == HOWTOs # @@ -174,6 +172,11 @@ # There is currently no supported way to change the overall format, but you may # have some luck hacking the Format constant. # + + +require 'monitor' + + class Logger /: (\S+),v (\S+)/ =~ %q$Id$ ProgName = "#{$1}/#{$2}" @@ -490,6 +493,8 @@ private # def initialize(log = nil, opt = {}) @dev = @filename = @shift_age = @shift_size = nil + @mutex = Object.new + @mutex.extend(MonitorMixin) if log.respond_to?(:write) and log.respond_to?(:close) @dev = log else @@ -508,22 +513,25 @@ private # mixed. # def write(message) - if shift_log? - begin - shift_log - rescue - raise Logger::ShiftingError.new("Shifting failed. #{$!}") - end + @mutex.synchronize do + if @shift_age and @dev.respond_to?(:stat) + begin + check_shift_log + rescue + raise Logger::ShiftingError.new("Shifting failed. #{$!}") + end + end + @dev.write(message) end - - @dev.write(message) end # # Close the logging device. # def close - @dev.close + @mutex.synchronize do + @dev.close + end end private @@ -551,66 +559,57 @@ private SiD = 24 * 60 * 60 - def shift_log? - if !@shift_age or !@dev.respond_to?(:stat) - return false - end - if (@shift_age.is_a?(Integer)) - # Note: always returns false if '0'. - return (@filename && (@shift_age > 0) && (@dev.stat.size > @shift_size)) + 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) + shift_log_age + end else - now = Time.now - limit_time = case @shift_age - when /^daily$/ - eod(now - 1 * SiD) - when /^weekly$/ - eod(now - ((now.wday + 1) * SiD)) - when /^monthly$/ - eod(now - now.mday * SiD) - else - now - end - return (@dev.stat.mtime <= limit_time) + now = Time.now + if @dev.stat.mtime <= previous_period_end(now) + shift_log_period(now) + end end end - def shift_log - # At first, close the device if opened. - if @dev - @dev.close - @dev = nil - end - if (@shift_age.is_a?(Integer)) - (@shift_age-3).downto(0) do |i| - if (FileTest.exist?("#{@filename}.#{i}")) - File.rename("#{@filename}.#{i}", "#{@filename}.#{i+1}") - end - end - File.rename("#{@filename}", "#{@filename}.0") - else - now = Time.now - postfix_time = case @shift_age - when /^daily$/ - eod(now - 1 * SiD) - when /^weekly$/ - eod(now - ((now.wday + 1) * SiD)) - when /^monthly$/ - eod(now - now.mday * SiD) - else - now - end - postfix = postfix_time.strftime("%Y%m%d") # YYYYMMDD - age_file = "#{@filename}.#{postfix}" - if (FileTest.exist?(age_file)) - raise RuntimeError.new("'#{ age_file }' already exists.") - end - File.rename("#{@filename}", age_file) + 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 + File.rename("#{@filename}", "#{@filename}.0") + @dev = create_logfile(@filename) + return true + end + def shift_log_period(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 + @dev.close + File.rename("#{@filename}", age_file) @dev = create_logfile(@filename) return true end + def previous_period_end(now) + case @shift_age + when /^daily$/ + eod(now - 1 * SiD) + when /^weekly$/ + eod(now - ((now.wday + 1) * SiD)) + when /^monthly$/ + eod(now - now.mday * SiD) + else + now + end + end + def eod(t) Time.mktime(t.year, t.month, t.mday, 23, 59, 59) end diff --git a/test/logger/test_logger.rb b/test/logger/test_logger.rb index c953a89d9c..3528ff21e2 100644 --- a/test/logger/test_logger.rb +++ b/test/logger/test_logger.rb @@ -90,15 +90,9 @@ class TestLogger < Test::Unit::TestCase logger = Logger.new(dummy) log = log_add(logger, INFO, "foo") assert_match(/^\d\d\d\d-\d\d-\d\dT\d\d:\d\d:\d\d.\s*\d+ $/, log.datetime) - # [ruby-dev:24828] - #logger.datetime_format = "%d%b%Y@%H:%M:%S" - #log = log_add(logger, INFO, "foo") - #assert_match(/^\d\d\w\w\w\d\d\d\d@\d\d:\d\d:\d\d$/, log.datetime) - # - # don't run the next test at 23:59, or just run again if failed. - logger.datetime_format = "@%d%b%Y@" + logger.datetime_format = "%d%b%Y@%H:%M:%S" log = log_add(logger, INFO, "foo") - assert_equal(Time.now.strftime("@%d%b%Y@"), log.datetime) + assert_match(/^\d\d\w\w\w\d\d\d\d@\d\d:\d\d:\d\d$/, log.datetime) logger.datetime_format = "" log = log_add(logger, INFO, "foo") assert_match(/^$/, log.datetime) @@ -279,4 +273,72 @@ class TestLogDevice < Test::Unit::TestCase assert(w.closed?) r.close end + + def test_shifting_size + logfile = File.basename(__FILE__) + '_1.log' + logfile0 = logfile + '.0' + logfile1 = logfile + '.1' + logfile2 = logfile + '.2' + logfile3 = logfile + '.3' + File.unlink(logfile) if File.exist?(logfile) + File.unlink(logfile0) if File.exist?(logfile0) + File.unlink(logfile1) if File.exist?(logfile1) + File.unlink(logfile2) if File.exist?(logfile2) + logger = Logger.new(logfile, 4, 100) + logger.error("0" * 15) + assert(File.exist?(logfile)) + assert(!File.exist?(logfile0)) + logger.error("0" * 15) + assert(File.exist?(logfile0)) + assert(!File.exist?(logfile1)) + logger.error("0" * 15) + assert(File.exist?(logfile1)) + assert(!File.exist?(logfile2)) + logger.error("0" * 15) + assert(File.exist?(logfile2)) + assert(!File.exist?(logfile3)) + logger.error("0" * 15) + assert(!File.exist?(logfile3)) + logger.error("0" * 15) + assert(!File.exist?(logfile3)) + File.unlink(logfile) + File.unlink(logfile0) + File.unlink(logfile1) + File.unlink(logfile2) + + logfile = File.basename(__FILE__) + '_2.log' + logfile0 = logfile + '.0' + logfile1 = logfile + '.1' + logfile2 = logfile + '.2' + logfile3 = logfile + '.3' + logger = Logger.new(logfile, 4, 150) + logger.error("0" * 15) + assert(File.exist?(logfile)) + assert(!File.exist?(logfile0)) + logger.error("0" * 15) + assert(!File.exist?(logfile0)) + logger.error("0" * 15) + assert(File.exist?(logfile0)) + assert(!File.exist?(logfile1)) + logger.error("0" * 15) + assert(!File.exist?(logfile1)) + logger.error("0" * 15) + assert(File.exist?(logfile1)) + assert(!File.exist?(logfile2)) + logger.error("0" * 15) + assert(!File.exist?(logfile2)) + logger.error("0" * 15) + assert(File.exist?(logfile2)) + assert(!File.exist?(logfile3)) + logger.error("0" * 15) + assert(!File.exist?(logfile3)) + logger.error("0" * 15) + assert(!File.exist?(logfile3)) + logger.error("0" * 15) + assert(!File.exist?(logfile3)) + File.unlink(logfile) + File.unlink(logfile0) + File.unlink(logfile1) + File.unlink(logfile2) + end end -- cgit v1.2.3