diff --git a/ChangeLog b/ChangeLog index 8141921cc3..3848f5d0e6 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,11 @@ +水 10月 21 00:17:28 2009 NAKAMURA, Hiroshi + + * lib/logger.rb: imported upstream version (logger/1.2.7) see #2238. + * do not raise an exception even if log writing failed. + * do not raise ShiftingError if an aged file already exists. + (no ShiftingError will be raised from 1.2.7, just warn() instead) + * test/logger/test_logger.rb: ditto. + Tue Oct 20 22:29:06 2009 Keiju Ishitsuka * lib/matrix.rb: Bug fix. See detail [ruby-core:23598]. diff --git a/lib/logger.rb b/lib/logger.rb index 07699e7017..6c33f7b3be 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -1,11 +1,5 @@ # logger.rb - simple logging utility -# Copyright (C) 2000-2003, 2005 NAKAMURA, Hiroshi . - -require 'monitor' - -# = logger.rb -# -# Simple logging utility. +# Copyright (C) 2000-2003, 2005, 2008 NAKAMURA, Hiroshi . # # Author:: NAKAMURA, Hiroshi # Documentation:: NAKAMURA, Hiroshi and Gavin Sinclair @@ -15,10 +9,11 @@ require 'monitor' # Revision:: $Id$ # # See Logger for documentation. -# -# +require 'monitor' + + # == Description # # The Logger class provides a simple but sophisticated logging utility that @@ -180,7 +175,7 @@ require 'monitor' class Logger - VERSION = "1.2.6" + VERSION = "1.2.7" id, name, rev = %w$Id$ if name name = name.chomp(",v") @@ -191,7 +186,7 @@ class Logger ProgName = "#{name}/#{rev}" class Error < RuntimeError; end - class ShiftingError < Error; end + class ShiftingError < Error; end # not used after 1.2.7. just for compat. # Logging severity. module Severity @@ -334,10 +329,10 @@ class Logger progname ||= @progname if message.nil? if block_given? - message = yield + message = yield else - message = progname - progname = @progname + message = progname + progname = @progname end end @logdev.write( @@ -499,32 +494,44 @@ private @dev = @filename = @shift_age = @shift_size = nil @mutex = LogDeviceMutex.new if log.respond_to?(:write) and log.respond_to?(:close) - @dev = log + @dev = log else - @dev = open_logfile(log) - @dev.sync = true - @filename = log - @shift_age = opt[:shift_age] || 7 - @shift_size = opt[:shift_size] || 1048576 + @dev = open_logfile(log) + @dev.sync = true + @filename = log + @shift_age = opt[:shift_age] || 7 + @shift_size = opt[:shift_size] || 1048576 end end def write(message) - @mutex.synchronize do - if @shift_age and @dev.respond_to?(:stat) + begin + @mutex.synchronize do + if @shift_age and @dev.respond_to?(:stat) + begin + check_shift_log + rescue + warn("log shifting failed. #{$!}") + end + end begin - check_shift_log + @dev.write(message) rescue - raise Logger::ShiftingError.new("Shifting failed. #{$!}") + warn("log writing failed. #{$!}") end end - @dev.write(message) + rescue Exception => ignored + warn("log writing failed. #{ignored}") end end def close - @mutex.synchronize do - @dev.close + begin + @mutex.synchronize do + @dev.close rescue nil + end + rescue Exception => ignored + @dev.close rescue nil end end @@ -532,9 +539,9 @@ private def open_logfile(filename) if (FileTest.exist?(filename)) - open(filename, (File::WRONLY | File::APPEND)) + open(filename, (File::WRONLY | File::APPEND)) else - create_logfile(filename) + create_logfile(filename) end end @@ -547,8 +554,8 @@ private def add_log_header(file) file.write( - "# Logfile created on %s by %s\n" % [Time.now.to_s, Logger::ProgName] - ) + "# Logfile created on %s by %s\n" % [Time.now.to_s, Logger::ProgName] + ) end SiD = 24 * 60 * 60 @@ -561,8 +568,9 @@ private end else now = Time.now - if @dev.stat.mtime <= previous_period_end(now) - shift_log_period(now) + period_end = previous_period_end(now) + if @dev.stat.mtime <= period_end + shift_log_period(period_end) end end end @@ -573,19 +581,26 @@ private File.rename("#{@filename}.#{i}", "#{@filename}.#{i+1}") end end - @dev.close + @dev.close rescue nil 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 + def shift_log_period(period_end) + postfix = period_end.strftime("%Y%m%d") # YYYYMMDD age_file = "#{@filename}.#{postfix}" if FileTest.exist?(age_file) - raise RuntimeError.new("'#{ age_file }' already exists.") + # try to avoid filename crash caused by Timestamp change. + idx = 0 + # .99 can be overriden; avoid too much file search with 'loop do' + while idx < 100 + idx += 1 + age_file = "#{@filename}.#{postfix}.#{idx}" + break unless FileTest.exist?(age_file) + end end - @dev.close + @dev.close rescue nil File.rename("#{@filename}", age_file) @dev = create_logfile(@filename) return true @@ -672,12 +687,12 @@ private def start status = -1 begin - log(INFO, "Start of #{ @appname }.") - status = run + log(INFO, "Start of #{ @appname }.") + status = run rescue - log(FATAL, "Detected an exception. Stopping ... #{$!} (#{$!.class})\n" << $@.join("\n")) + log(FATAL, "Detected an exception. Stopping ... #{$!} (#{$!.class})\n" << $@.join("\n")) ensure - log(INFO, "End of #{ @appname }. (status: #{ status.to_s })") + log(INFO, "End of #{ @appname }. (status: #{ status.to_s })") end status end @@ -692,6 +707,8 @@ private # def logger=(logger) @log = logger + @log.progname = @appname + @log.level = @level end # @@ -726,6 +743,7 @@ private private def run + # TODO: should be an NotImplementedError raise RuntimeError.new('Method run must be defined in the derived class.') end end diff --git a/test/logger/test_logger.rb b/test/logger/test_logger.rb index a6c132d0f3..8ddcd242ba 100644 --- a/test/logger/test_logger.rb +++ b/test/logger/test_logger.rb @@ -6,9 +6,9 @@ require 'tempfile' class TestLoggerSeverity < Test::Unit::TestCase def test_enum logger_levels = Logger.constants - levels = [:WARN, :UNKNOWN, :INFO, :FATAL, :DEBUG, :ERROR] + levels = ["WARN", "UNKNOWN", "INFO", "FATAL", "DEBUG", "ERROR"] Logger::Severity.constants.each do |level| - assert(levels.include?(level)) + assert(levels.include?(level.to_s)) assert(logger_levels.include?(level)) end assert_equal(levels.size, Logger::Severity.constants.size) @@ -21,16 +21,19 @@ class TestLogger < Test::Unit::TestCase def setup @logger = Logger.new(nil) + @filename = __FILE__ + ".#{$$}" end - def test_const_progname - assert %r!\Alogger\.rb/\S+\z! === Logger::ProgName + def teardown + unless $DEBUG + File.unlink(@filename) if File.exist?(@filename) + end end class Log attr_reader :label, :datetime, :pid, :severity, :progname, :msg def initialize(line) - /\A(\w+), \[([^#]*)#(\d+)\]\s+(\w+) -- (\w*): ([\x0-\xff]*)/n =~ line + /\A(\w+), \[([^#]*)#(\d+)\]\s+(\w+) -- (\w*): ([\x0-\xff]*)/ =~ line @label, @datetime, @pid, @severity, @progname, @msg = $1, $2, $3, $4, $5, $6 end end @@ -262,28 +265,56 @@ class TestLogger < Test::Unit::TestCase end class TestLogDevice < Test::Unit::TestCase - def d(log) - Logger::LogDevice.new(log) + class LogExcnRaiser + def write(*arg) + raise 'disk is full' + end + + def close + end + + def stat + Object.new + end + end + + def setup + @filename = __FILE__ + ".#{$$}" + end + + def teardown + unless $DEBUG + File.unlink(@filename) if File.exist?(@filename) + end + end + + def d(log, opt = {}) + Logger::LogDevice.new(log, opt) end def test_initialize logdev = d(STDERR) assert_equal(STDERR, logdev.dev) assert_nil(logdev.filename) - assert_raise(TypeError) do + assert_raises(TypeError) do d(nil) end # - filename = __FILE__ + ".#{$$}" + logdev = d(@filename) begin - logdev = d(filename) - assert(File.exist?(filename)) + assert(File.exist?(@filename)) assert(logdev.dev.sync) - assert_equal(filename, logdev.filename) + assert_equal(@filename, logdev.filename) + logdev.write('hello') ensure logdev.close - File.unlink(filename) end + # create logfile whitch is already exist. + logdev = d(@filename) + logdev.write('world') + logfile = File.read(@filename) + assert_equal(2, logfile.split(/\n/).size) + assert_match(/^helloworld$/, logfile) end def test_write @@ -295,6 +326,15 @@ class TestLogDevice < Test::Unit::TestCase msg = r.read r.close assert_equal("msg2\n\n", msg) + # + logdev = d(LogExcnRaiser.new) + begin + assert_nothing_raised do + logdev.write('hello') + end + ensure + logdev.close + end end def test_close @@ -377,4 +417,88 @@ class TestLogDevice < Test::Unit::TestCase File.unlink(logfile1) File.unlink(logfile2) end + + def test_shifting_age_variants + logger = Logger.new(@filename, 'daily') + logger.info('daily') + logger.close + logger = Logger.new(@filename, 'weekly') + logger.info('weekly') + logger.close + logger = Logger.new(@filename, 'monthly') + logger.info('monthly') + logger.close + end + + def test_shifting_age + # shift_age other than 'daily', 'weekly', and 'monthly' means 'everytime' + yyyymmdd = Time.now.strftime("%Y%m%d") + filename1 = @filename + ".#{yyyymmdd}" + filename2 = @filename + ".#{yyyymmdd}.1" + filename3 = @filename + ".#{yyyymmdd}.2" + begin + logger = Logger.new(@filename, 'now') + assert(File.exist?(@filename)) + assert(!File.exist?(filename1)) + assert(!File.exist?(filename2)) + assert(!File.exist?(filename3)) + logger.info("0" * 15) + assert(File.exist?(@filename)) + assert(File.exist?(filename1)) + assert(!File.exist?(filename2)) + assert(!File.exist?(filename3)) + logger.warn("0" * 15) + assert(File.exist?(@filename)) + assert(File.exist?(filename1)) + assert(File.exist?(filename2)) + assert(!File.exist?(filename3)) + logger.error("0" * 15) + assert(File.exist?(@filename)) + assert(File.exist?(filename1)) + assert(File.exist?(filename2)) + assert(File.exist?(filename3)) + ensure + [filename1, filename2, filename3].each do |filename| + File.unlink(filename) if File.exist?(filename) + end + end + end +end + + +class TestLoggerApplication < Test::Unit::TestCase + def setup + @app = Logger::Application.new('appname') + @filename = __FILE__ + ".#{$$}" + end + + def teardown + unless $DEBUG + File.unlink(@filename) if File.exist?(@filename) + end + end + + def test_initialize + app = Logger::Application.new('appname') + assert_equal('appname', app.appname) + end + + def test_start + @app.set_log(@filename) + @app.level = Logger::UNKNOWN + @app.start # logs FATAL log + assert_equal(1, File.read(@filename).split(/\n/).size) + end + + def test_logger + @app.level = Logger::WARN + @app.set_log(@filename) + assert_equal(Logger::WARN, @app.logger.level) + @app.logger = logger = Logger.new(STDOUT) + assert_equal(logger, @app.logger) + assert_equal(Logger::WARN, @app.logger.level) + @app.log = @filename + assert(logger != @app.logger) + assert_equal(Logger::WARN, @app.logger.level) + end end