From 10dff8dd0223cb1f2e328ef646688afaf894de00 Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Sun, 15 Jan 2023 08:29:38 -0800 Subject: [PATCH 1/6] Add thread-local log level, fixes #84 --- CHANGELOG.md | 4 ++++ lib/logger.rb | 38 +++++++++++++++++------------------- lib/logger/severity.rb | 23 ++++++++++++++++++++++ test/logger/test_severity.rb | 32 ++++++++++++++++++++++++++++++ 4 files changed, 77 insertions(+), 20 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c02ceaa..2a77035 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,7 @@ +# HEAD + +* Add thread-local log levels using `Logger#with_level` [#84](https://github.com/ruby/logger/issue/84) + # 1.4.2 * Document that shift_age of 0 disables log file rotation [#43](https://github.com/ruby/logger/pull/43) (thanks to jeremyevans) diff --git a/lib/logger.rb b/lib/logger.rb index cafebc5..b2b32e3 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -380,7 +380,9 @@ class Logger include Severity # Logging severity threshold (e.g. Logger::INFO). - attr_reader :level + def level + Thread.current[@key] || @level + end # Sets the log level; returns +severity+. # See {Log Level}[rdoc-ref:Logger@Log+Level]. @@ -395,25 +397,20 @@ class Logger # Logger#sev_threshold= is an alias for Logger#level=. # def level=(severity) - if severity.is_a?(Integer) - @level = severity - else - case severity.to_s.downcase - when 'debug' - @level = DEBUG - when 'info' - @level = INFO - when 'warn' - @level = WARN - when 'error' - @level = ERROR - when 'fatal' - @level = FATAL - when 'unknown' - @level = UNKNOWN - else - raise ArgumentError, "invalid log level: #{severity}" - end + @level = Severity.coerce(severity) + end + + # Adjust the log level during the block execution for the current Thread only + # + # logger.with_level(:debug) do + # logger.debug { "Hello" } + # end + def with_level(severity, &block) + current, Thread.current[@key] = level, Severity.coerce(severity) + begin + yield + ensure + Thread.current[@key] = current end end @@ -583,6 +580,7 @@ def initialize(logdev, shift_age = 0, shift_size = 1048576, level: DEBUG, self.datetime_format = datetime_format self.formatter = formatter @logdev = nil + @key = "__log_level_#{object_id}" if logdev && logdev != File::NULL @logdev = LogDevice.new(logdev, shift_age: shift_age, shift_size: shift_size, diff --git a/lib/logger/severity.rb b/lib/logger/severity.rb index b38afb7..3188bf6 100644 --- a/lib/logger/severity.rb +++ b/lib/logger/severity.rb @@ -15,5 +15,28 @@ module Severity FATAL = 4 # An unknown message that should always be logged. UNKNOWN = 5 + + def self.coerce(severity) + if severity.is_a?(Integer) + severity + else + case severity.to_s.downcase + when 'debug' + DEBUG + when 'info' + INFO + when 'warn' + WARN + when 'error' + ERROR + when 'fatal' + FATAL + when 'unknown' + UNKNOWN + else + raise ArgumentError, "invalid log level: #{severity}" + end + end + end end end diff --git a/test/logger/test_severity.rb b/test/logger/test_severity.rb index dad6347..e1069c8 100644 --- a/test/logger/test_severity.rb +++ b/test/logger/test_severity.rb @@ -3,6 +3,8 @@ require 'logger' class TestLoggerSeverity < Test::Unit::TestCase + include Logger::Severity + def test_enum logger_levels = Logger.constants levels = ["WARN", "UNKNOWN", "INFO", "FATAL", "DEBUG", "ERROR"] @@ -23,4 +25,34 @@ def test_level_assignment assert(logger.level) == Logger::Severity.const_get(level) end end + + def test_thread_local_level + logger = Logger.new(nil) + logger.level = INFO # default level + other = Logger.new(nil) + other.level = ERROR # default level + + assert_equal(other.level, ERROR) + logger.with_level(:WARN) do + assert_equal(other.level, ERROR) + assert_equal(logger.level, WARN) + + logger.with_level(DEBUG) do # verify reentrancy + assert_equal(logger.level, DEBUG) + + Thread.new do + assert_equal(logger.level, INFO) + logger.with_level(:WARN) do + assert_equal(other.level, ERROR) + assert_equal(logger.level, WARN) + end + assert_equal(logger.level, INFO) + end.join + + assert_equal(logger.level, DEBUG) + end + assert_equal(logger.level, WARN) + end + assert_equal(logger.level, INFO) + end end From 3fbe592f9fa50805d8c05aea9447b3f21c08d428 Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Thu, 9 Feb 2023 09:02:42 -0800 Subject: [PATCH 2/6] Refactor to store levels in weakmap, hash lookup --- lib/logger.rb | 10 +++++----- lib/logger/severity.rb | 28 ++++++++++++---------------- 2 files changed, 17 insertions(+), 21 deletions(-) diff --git a/lib/logger.rb b/lib/logger.rb index b2b32e3..b238f58 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -381,7 +381,7 @@ class Logger # Logging severity threshold (e.g. Logger::INFO). def level - Thread.current[@key] || @level + @tll[Thread.current] || @level end # Sets the log level; returns +severity+. @@ -405,12 +405,12 @@ def level=(severity) # logger.with_level(:debug) do # logger.debug { "Hello" } # end - def with_level(severity, &block) - current, Thread.current[@key] = level, Severity.coerce(severity) + def with_level(severity) + current, @tll[Thread.current] = level, Severity.coerce(severity) begin yield ensure - Thread.current[@key] = current + @tll[Thread.current] = current end end @@ -580,7 +580,7 @@ def initialize(logdev, shift_age = 0, shift_size = 1048576, level: DEBUG, self.datetime_format = datetime_format self.formatter = formatter @logdev = nil - @key = "__log_level_#{object_id}" + @tll = ObjectSpace::WeakMap.new # thread-local levels if logdev && logdev != File::NULL @logdev = LogDevice.new(logdev, shift_age: shift_age, shift_size: shift_size, diff --git a/lib/logger/severity.rb b/lib/logger/severity.rb index 3188bf6..fe4cefe 100644 --- a/lib/logger/severity.rb +++ b/lib/logger/severity.rb @@ -16,26 +16,22 @@ module Severity # An unknown message that should always be logged. UNKNOWN = 5 + LEVELS = { + "debug" => DEBUG, + "info" => INFO, + "warn" => WARN, + "error" => ERROR, + "fatal" => FATAL, + "unknown" => UNKNOWN, + } + private_constant :LEVELS + def self.coerce(severity) if severity.is_a?(Integer) severity else - case severity.to_s.downcase - when 'debug' - DEBUG - when 'info' - INFO - when 'warn' - WARN - when 'error' - ERROR - when 'fatal' - FATAL - when 'unknown' - UNKNOWN - else - raise ArgumentError, "invalid log level: #{severity}" - end + k = severity.to_s.downcase + LEVELS[k] || raise(ArgumentError, "invalid log level: #{severity}") end end end From b2e38cf675092b5ff17f751030c15fce795adefc Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Thu, 9 Feb 2023 16:15:43 -0800 Subject: [PATCH 3/6] Use plain hash --- lib/logger.rb | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/lib/logger.rb b/lib/logger.rb index b238f58..e8258e5 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -406,11 +406,15 @@ def level=(severity) # logger.debug { "Hello" } # end def with_level(severity) - current, @tll[Thread.current] = level, Severity.coerce(severity) + prev, @tll[Thread.current] = level, Severity.coerce(severity) begin yield ensure - @tll[Thread.current] = current + if prev + @tll[Thread.current] = prev + else + @ttl.delete(Thread.current) + end end end @@ -580,7 +584,7 @@ def initialize(logdev, shift_age = 0, shift_size = 1048576, level: DEBUG, self.datetime_format = datetime_format self.formatter = formatter @logdev = nil - @tll = ObjectSpace::WeakMap.new # thread-local levels + @tll = {} # thread-local levels if logdev && logdev != File::NULL @logdev = LogDevice.new(logdev, shift_age: shift_age, shift_size: shift_size, From a8cd90733047bfd75ffc5c2849d83e4ca70de4d3 Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Thu, 9 Feb 2023 16:50:39 -0800 Subject: [PATCH 4/6] refactoring --- lib/logger.rb | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/lib/logger.rb b/lib/logger.rb index e8258e5..b8ce179 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -381,7 +381,7 @@ class Logger # Logging severity threshold (e.g. Logger::INFO). def level - @tll[Thread.current] || @level + @level_override[Fiber.current] || @level end # Sets the log level; returns +severity+. @@ -400,20 +400,20 @@ def level=(severity) @level = Severity.coerce(severity) end - # Adjust the log level during the block execution for the current Thread only + # Adjust the log level during the block execution for the current Fiber only # # logger.with_level(:debug) do # logger.debug { "Hello" } # end def with_level(severity) - prev, @tll[Thread.current] = level, Severity.coerce(severity) + prev, @level_override[Fiber.current] = level, Severity.coerce(severity) begin yield ensure if prev - @tll[Thread.current] = prev + @level_override[Fiber.current] = prev else - @ttl.delete(Thread.current) + @level_override.delete(Fiber.current) end end end @@ -584,7 +584,7 @@ def initialize(logdev, shift_age = 0, shift_size = 1048576, level: DEBUG, self.datetime_format = datetime_format self.formatter = formatter @logdev = nil - @tll = {} # thread-local levels + @level_override = {} if logdev && logdev != File::NULL @logdev = LogDevice.new(logdev, shift_age: shift_age, shift_size: shift_size, From dbed92b30210985f8b8f24e0c8cec2c66cd498b0 Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Thu, 9 Feb 2023 16:52:13 -0800 Subject: [PATCH 5/6] Update lib/logger/severity.rb Co-authored-by: Samuel Williams --- lib/logger/severity.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/logger/severity.rb b/lib/logger/severity.rb index fe4cefe..e96fb0d 100644 --- a/lib/logger/severity.rb +++ b/lib/logger/severity.rb @@ -30,8 +30,8 @@ def self.coerce(severity) if severity.is_a?(Integer) severity else - k = severity.to_s.downcase - LEVELS[k] || raise(ArgumentError, "invalid log level: #{severity}") + key = severity.to_s.downcase + LEVELS[key] || raise(ArgumentError, "invalid log level: #{severity}") end end end From 0b1ad4b10d53dac2378aa17a407d81bb3b4ae7ae Mon Sep 17 00:00:00 2001 From: Mike Perham Date: Thu, 9 Feb 2023 17:02:11 -0800 Subject: [PATCH 6/6] polish --- CHANGELOG.md | 2 +- lib/logger.rb | 1 + 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2a77035..8960ad3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,6 @@ # HEAD -* Add thread-local log levels using `Logger#with_level` [#84](https://github.com/ruby/logger/issue/84) +* Support fiber-local log levels using `Logger#with_level` [#84](https://github.com/ruby/logger/issue/84) # 1.4.2 diff --git a/lib/logger.rb b/lib/logger.rb index b8ce179..4940999 100644 --- a/lib/logger.rb +++ b/lib/logger.rb @@ -10,6 +10,7 @@ # # A simple system for logging messages. See Logger for more documentation. +require 'fiber' require 'monitor' require 'rbconfig'