diff --git a/temporalio/Gemfile b/temporalio/Gemfile index 867613aa..e84225dc 100644 --- a/temporalio/Gemfile +++ b/temporalio/Gemfile @@ -25,6 +25,8 @@ group :development do gem 'rb_sys', '~> 0.9' gem 'rdoc' gem 'rubocop' + # Used to verify that ScopedLogger works with loggers whose #level is not an integer. + gem 'semantic_logger' gem 'sorbet-runtime' gem 'sqlite3' gem 'steep', '~> 1.10' diff --git a/temporalio/Gemfile.lock b/temporalio/Gemfile.lock index f6061501..1c0a299d 100644 --- a/temporalio/Gemfile.lock +++ b/temporalio/Gemfile.lock @@ -150,6 +150,8 @@ GEM prism (~> 1.7) ruby-progressbar (1.13.0) securerandom (0.4.1) + semantic_logger (5.1.0) + concurrent-ruby (~> 1.0) sorbet-runtime (0.6.13321) sqlite3 (2.9.5-arm64-darwin) sqlite3 (2.9.5-x86_64-linux-gnu) @@ -207,6 +209,7 @@ DEPENDENCIES rbs (~> 3.10) rdoc rubocop + semantic_logger sorbet-runtime sqlite3 steep (~> 1.10) @@ -278,6 +281,7 @@ CHECKSUMS rubocop-ast (1.49.1) sha256=4412f3ee70f6fe4546cc489548e0f6fcf76cafcfa80fa03af67098ffed755035 ruby-progressbar (1.13.0) sha256=80fc9c47a9b640d6834e0dc7b3c94c9df37f08cb072b7761e4a71e22cff29b33 securerandom (0.4.1) sha256=cc5193d414a4341b6e225f0cb4446aceca8e50d5e1888743fac16987638ea0b1 + semantic_logger (5.1.0) sha256=9a8170fc0212ad47ef29e0760219cf416cb5b9973061981733234f7148b6d6ea sorbet-runtime (0.6.13321) sha256=55ca445d39703284c2f14175a13a3ff085d247f4f16028076fbb7a83c715f7cc sqlite3 (2.9.5-arm64-darwin) sha256=d0cf444a70fc9395d513cfbcc1e6719e224aa645314e3824cb0474c721425aa2 sqlite3 (2.9.5-x86_64-linux-gnu) sha256=233dbcb6714148dd23bc5aeb33e8efd6eac974969564ddd5794c23d5f52b231e diff --git a/temporalio/lib/temporalio/scoped_logger.rb b/temporalio/lib/temporalio/scoped_logger.rb index fd4969a4..52c26145 100644 --- a/temporalio/lib/temporalio/scoped_logger.rb +++ b/temporalio/lib/temporalio/scoped_logger.rb @@ -42,6 +42,21 @@ def add(severity, message = nil, progname = nil) end alias log add + # returns the logger log level as an integer. + def level + lvl = super + + return lvl if lvl.is_a?(Integer) + + return Logger::UNKNOWN unless lvl.respond_to?(:upcase) + + if Logger::Severity.const_defined?(lvl.upcase, false) + Logger::Severity.const_get(lvl.upcase, false) + else + Logger::UNKNOWN + end + end + # @see Logger.debug def debug(progname = nil, &) add(Logger::DEBUG, nil, progname, &) diff --git a/temporalio/test/scoped_logger_test.rb b/temporalio/test/scoped_logger_test.rb index 83b27df9..cc72ca9c 100644 --- a/temporalio/test/scoped_logger_test.rb +++ b/temporalio/test/scoped_logger_test.rb @@ -1,9 +1,21 @@ # frozen_string_literal: true +require 'semantic_logger' require 'temporalio/scoped_logger' require 'test' class ScopedLoggerTest < Test + # Minimal logger-ish object whose level is whatever we want it to be. + class CustomLevelLogger + attr_reader :level + + def initialize(level) + @level = level + end + + def add(severity, message = nil, progname = nil); end + end + def test_logger_with_values # Default doesn't change anything out, = safe_capture_io do @@ -40,4 +52,70 @@ def test_logger_with_values assert(lines.one? { |l| l.include?('DEBUG') && l.end_with?("debug2 #{extra_vals.inspect}") }) assert(lines.one? { |l| l.include?('ERROR') && l.end_with?("exception1 #{extra_vals.inspect} (RuntimeError)") }) end + + def test_level_with_standard_logger + [Logger::DEBUG, Logger::INFO, Logger::WARN, Logger::ERROR, Logger::FATAL, Logger::UNKNOWN].each do |level| + logger = Temporalio::ScopedLogger.new(Logger.new(IO::NULL, level:)) + assert_instance_of(Integer, logger.level) + assert_equal(level, logger.level) + end + + # Logger itself accepts symbols/strings but normalizes them to integers, so those come through unchanged too + logger = Temporalio::ScopedLogger.new(Logger.new(IO::NULL, level: :warn)) + assert_instance_of(Integer, logger.level) + assert_equal(Logger::WARN, logger.level) + end + + def test_level_with_semantic_logger + { + debug: Logger::DEBUG, + info: Logger::INFO, + warn: Logger::WARN, + error: Logger::ERROR, + fatal: Logger::FATAL + }.each do |semantic_level, expected_level| + inner = SemanticLogger::Logger.new('ScopedLoggerTest', semantic_level) + # Sanity check on the premise of this test: semantic_logger reports its level as a symbol + assert_instance_of(Symbol, inner.level) + + logger = Temporalio::ScopedLogger.new(inner) + assert_instance_of(Integer, logger.level) + assert_equal(expected_level, logger.level) + end + + # semantic_logger levels with no ::Logger counterpart (e.g. :trace) fall back to UNKNOWN + logger = Temporalio::ScopedLogger.new(SemanticLogger::Logger.new('ScopedLoggerTest', :trace)) + assert_instance_of(Integer, logger.level) + assert_equal(Logger::UNKNOWN, logger.level) + end + + def test_level_with_other_non_integer_levels + # Strings are upcased and looked up just like symbols + logger = Temporalio::ScopedLogger.new(CustomLevelLogger.new('warn')) + assert_instance_of(Integer, logger.level) + assert_equal(Logger::WARN, logger.level) + + # Anything unrecognized, or that cannot even be upcased, is UNKNOWN rather than an error + ['nonsense', :nonsense, nil, 1.5, Object.new].each do |level| + logger = Temporalio::ScopedLogger.new(CustomLevelLogger.new(level)) + assert_instance_of(Integer, logger.level) + assert_equal(Logger::UNKNOWN, logger.level) + end + end + + def test_logging_with_semantic_logger + inner = SemanticLogger::Logger.new('ScopedLoggerTest', :info) + logger = Temporalio::ScopedLogger.new(inner) + logger.scoped_values_getter = proc { { some_key: 'some_value' } } + + logged = [] + inner.define_singleton_method(:log) { |log| logged << log } + + logger.info('info1') + logger.error('error1') + logger.debug('debug1') + + assert_equal([Logger::INFO, Logger::ERROR], logged.map { |log| Logger::Severity.const_get(log.level.upcase) }) + assert(logged.none? { |log| log.message.to_s.include?('debug1') }) + end end