From 06e580576388d7c1cc52e8b14b624dd44cc0a308 Mon Sep 17 00:00:00 2001 From: Francesco Belladonna Date: Thu, 14 Aug 2025 16:32:18 -0700 Subject: [PATCH 1/2] Add child logger with instance named tags support --- CHANGELOG.md | 2 ++ docs/api.md | 14 ++++++++++++++ lib/semantic_logger/base.rb | 17 ++++++++++++++++- lib/semantic_logger/loggable.rb | 6 +++++- test/loggable_test.rb | 14 ++++++++++++++ test/logger_test.rb | 13 +++++++++++++ 6 files changed, 64 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fc9a74d4..3483b8c4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,8 @@ This project adheres to [Semantic Versioning](http://semver.org/). ## [unreleased] +- Add child logger with instance named tags support + ## [4.17.0] - Correct `source_code_uri` URL diff --git a/docs/api.md b/docs/api.md index c7423f60..587d81fc 100644 --- a/docs/api.md +++ b/docs/api.md @@ -633,4 +633,18 @@ Or, when using a Gemfile: gem "semantic_logger", require: "semantic_logger/sync" ~~~ +### Child Logger + +It is possible to create child loggers with pre-set instance tags. +Any log message emitted by a logger with pre-set instance tags will include these tags along with the message data. + +~~~ruby +logger = SemanticLogger["MyClass"] +child_logger1 = logger.child(tag1: "value1", tag2: "value2") +child_logger2 = child_logger1.child(tag3: "value3") + +# Will include tag1, tag2, tag3 and tag4 in the output +child_logger2.info("Some message", tag4: "value4") +~~~ + ### [Next: Testing ==>](testing.html) diff --git a/lib/semantic_logger/base.rb b/lib/semantic_logger/base.rb index fb8cc6bf..184fda0f 100644 --- a/lib/semantic_logger/base.rb +++ b/lib/semantic_logger/base.rb @@ -7,7 +7,7 @@ module SemanticLogger class Base # Class name to be logged - attr_accessor :name, :filter + attr_accessor :name, :filter, :child_named_tags # Set the logging level for this logger # @@ -250,6 +250,14 @@ def should_log?(log) meets_log_level?(log) && !filtered?(log) end + # Creates a new logger with the given instance named tags + def child(**named_tags) + new_named_tags = child_named_tags.merge(named_tags) + new_logger = dup + new_logger.child_named_tags = new_named_tags + new_logger + end + private # Initializer for Abstract Class SemanticLogger::Base @@ -290,6 +298,7 @@ def initialize(klass, level = nil, filter = nil) else self.level = level end + @child_named_tags = {} end # Return the level index for fast comparisons @@ -349,6 +358,9 @@ def log_internal(level, index, message = nil, payload = nil, exception = nil) end end + # Add child named tags to the log + log.payload = child_named_tags.merge(log.payload || {}) + # Log level may change during assign due to :on_exception_level self.log(log) if should_log && should_log?(log) end @@ -389,6 +401,9 @@ def measure_internal(level, index, message, params) # Extract options after block completes so that block can modify any of the options payload = params[:payload] + # Add child named tags + payload = child_named_tags.merge(payload || {}) + # May return false due to elastic logging should_log = log.assign( message: message, diff --git a/lib/semantic_logger/loggable.rb b/lib/semantic_logger/loggable.rb index bb3dd31a..267c1177 100644 --- a/lib/semantic_logger/loggable.rb +++ b/lib/semantic_logger/loggable.rb @@ -42,7 +42,7 @@ def self.included(base) # Returns [SemanticLogger::Logger] class level logger def self.logger - @semantic_logger ||= SemanticLogger[self] + @semantic_logger ||= SemanticLogger[self].child(**@logger_child_named_tags) end # Replace instance class level logger @@ -114,6 +114,10 @@ def #{method_name}(*args, &block) true end + def logger_child(**named_tags) + @logger_child_named_tags = named_tags + end + private # Dynamic Module to intercept method calls for measuring purposes. diff --git a/test/loggable_test.rb b/test/loggable_test.rb index b052e37f..3210e536 100644 --- a/test/loggable_test.rb +++ b/test/loggable_test.rb @@ -27,6 +27,14 @@ class TestAttribute include SemanticLogger::Loggable end + class TestChildClassLogger + include SemanticLogger::Loggable + + TAG_DATA = {tag1: "value1", tag2: "value2"}.freeze + + logger_child(**TAG_DATA) + end + describe SemanticLogger::Loggable do describe "inheritance" do it "should give child classes their own logger" do @@ -79,5 +87,11 @@ class TestAttribute TestAttribute.new.logger.is_a?(SemanticLogger::Logger) end end + + describe "sample child class logger" do + it "has child named tags set" do + assert_equal TestChildClassLogger::TAG_DATA, TestChildClassLogger.logger.child_named_tags + end + end end end diff --git a/test/logger_test.rb b/test/logger_test.rb index 8c6e2249..4bd6df89 100644 --- a/test/logger_test.rb +++ b/test/logger_test.rb @@ -153,5 +153,18 @@ def self.call(log) end end end + + describe ".child" do + it "creates a child logger" do + tag_data = {tag1: "value1", tag2: "value2"} + child_logger = logger.child(**tag_data) + child_logger.info("hello world") + + assert_equal tag_data, child_logger.child_named_tags + assert log = child_logger.events.first + assert_equal "hello world", log.message + assert_equal tag_data, log.payload + end + end end end From 6180f10e3a6b19586cf9f3181b14c0455fbf8683 Mon Sep 17 00:00:00 2001 From: Francesco Belladonna Date: Mon, 18 Aug 2025 16:29:20 -0700 Subject: [PATCH 2/2] tmp commit --- lib/semantic_logger/base.rb | 39 ++++++++++++------- lib/semantic_logger/formatters/raw.rb | 4 ++ lib/semantic_logger/log.rb | 8 +++- lib/semantic_logger/loggable.rb | 4 +- lib/semantic_logger/logger.rb | 6 ++- lib/semantic_logger/subscriber.rb | 8 +++- .../test/capture_log_events.rb | 6 +++ lib/semantic_logger/test/minitest.rb | 4 +- test/loggable_test.rb | 4 +- test/logger_test.rb | 34 ++++++++++++---- 10 files changed, 86 insertions(+), 31 deletions(-) diff --git a/lib/semantic_logger/base.rb b/lib/semantic_logger/base.rb index 184fda0f..83f5b2ba 100644 --- a/lib/semantic_logger/base.rb +++ b/lib/semantic_logger/base.rb @@ -6,8 +6,18 @@ # module SemanticLogger class Base + # Creates a copy of an existing logger. + # This method can be overridden by subclasses to provide a specialized implementation. + # `child` logger uses this method. + def self.copy(instance) + raise ArgumentError, "Cannot copy instances different from #{self}" if instance.class != self + + instance.dup + end + # Class name to be logged - attr_accessor :name, :filter, :child_named_tags + attr_accessor :name, :filter + attr_reader :instance_named_tags # Set the logging level for this logger # @@ -252,12 +262,19 @@ def should_log?(log) # Creates a new logger with the given instance named tags def child(**named_tags) - new_named_tags = child_named_tags.merge(named_tags) - new_logger = dup - new_logger.child_named_tags = new_named_tags + new_named_tags = instance_named_tags.merge(named_tags) + new_logger = self.class.copy(self) + new_logger.instance_named_tags = new_named_tags new_logger end + protected + + def instance_named_tags=(named_tags) + # Prevent accidental mutation of log named tags + @instance_named_tags = named_tags.dup.freeze + end + private # Initializer for Abstract Class SemanticLogger::Base @@ -283,7 +300,7 @@ def child(**named_tags) # (/\AExclude/ =~ log.message).nil? # end # end - def initialize(klass, level = nil, filter = nil) + def initialize(klass, level = nil, filter = nil, instance_named_tags = {}) # Support filtering all messages to this logger instance. unless filter.nil? || filter.is_a?(Regexp) || filter.is_a?(Proc) || filter.respond_to?(:call) raise ":filter must be a Regexp, Proc, or implement :call" @@ -298,7 +315,7 @@ def initialize(klass, level = nil, filter = nil) else self.level = level end - @child_named_tags = {} + self.instance_named_tags = instance_named_tags end # Return the level index for fast comparisons @@ -334,7 +351,7 @@ def log_internal(level, index, message = nil, payload = nil, exception = nil) payload = nil end - log = Log.new(name, level, index) + log = Log.new(name, level, index, instance_named_tags) should_log = if exception.nil? && payload.nil? && message.is_a?(Hash) # All arguments as a hash in the message. @@ -358,9 +375,6 @@ def log_internal(level, index, message = nil, payload = nil, exception = nil) end end - # Add child named tags to the log - log.payload = child_named_tags.merge(log.payload || {}) - # Log level may change during assign due to :on_exception_level self.log(log) if should_log && should_log?(log) end @@ -388,7 +402,7 @@ def measure_internal(level, index, message, params) exception = e ensure # Must use ensure block otherwise a `return` in the yield above will skip the log entry - log = Log.new(name, level, index) + log = Log.new(name, level, index, instance_named_tags) exception ||= params[:exception] message = params[:message] if params[:message] duration = @@ -401,9 +415,6 @@ def measure_internal(level, index, message, params) # Extract options after block completes so that block can modify any of the options payload = params[:payload] - # Add child named tags - payload = child_named_tags.merge(payload || {}) - # May return false due to elastic logging should_log = log.assign( message: message, diff --git a/lib/semantic_logger/formatters/raw.rb b/lib/semantic_logger/formatters/raw.rb index 44fffa9f..bff647b1 100644 --- a/lib/semantic_logger/formatters/raw.rb +++ b/lib/semantic_logger/formatters/raw.rb @@ -64,6 +64,10 @@ def tags # Named Tags def named_tags hash[:named_tags] = log.named_tags if log.named_tags && !log.named_tags.empty? + # TODO: Test + # TODO: Different hash entry instead? + # Always overrides thread named_tags with instance_named_tags + hash[:named_tags] = hash.fetch(:named_tags, {}).merge(log.instance_named_tags) if log.instance_named_tags && !log.instance_named_tags.empty? end # Duration diff --git a/lib/semantic_logger/log.rb b/lib/semantic_logger/log.rb index 406a6a73..05856c2f 100644 --- a/lib/semantic_logger/log.rb +++ b/lib/semantic_logger/log.rb @@ -28,6 +28,9 @@ module SemanticLogger # tags # Any tags active on the thread when the log call was made # + # instance_named_tags + # Any named tags active on the logger instance when the log call was made + # # level_index # Internal index of the log level # @@ -55,16 +58,17 @@ class Log attr_accessor :level, :level_index, :name, :message, :time, :duration, :payload, :exception, :thread_name, :backtrace, - :tags, :named_tags, :context, + :tags, :named_tags, :instance_named_tags, :context, :metric, :metric_amount, :dimensions - def initialize(name, level, index = nil) + def initialize(name, level, index = nil, instance_named_tags = {}) @level = level @thread_name = Thread.current.name @name = name @time = Time.now @tags = SemanticLogger.tags @named_tags = SemanticLogger.named_tags + @instance_named_tags = instance_named_tags @level_index = index.nil? ? Levels.index(level) : index end diff --git a/lib/semantic_logger/loggable.rb b/lib/semantic_logger/loggable.rb index 267c1177..9159e754 100644 --- a/lib/semantic_logger/loggable.rb +++ b/lib/semantic_logger/loggable.rb @@ -42,7 +42,7 @@ def self.included(base) # Returns [SemanticLogger::Logger] class level logger def self.logger - @semantic_logger ||= SemanticLogger[self].child(**@logger_child_named_tags) + @semantic_logger ||= SemanticLogger[self].child(**@logger_instance_named_tags) end # Replace instance class level logger @@ -115,7 +115,7 @@ def #{method_name}(*args, &block) end def logger_child(**named_tags) - @logger_child_named_tags = named_tags + @logger_instance_named_tags = named_tags end private diff --git a/lib/semantic_logger/logger.rb b/lib/semantic_logger/logger.rb index 083295de..14c82f93 100644 --- a/lib/semantic_logger/logger.rb +++ b/lib/semantic_logger/logger.rb @@ -56,7 +56,11 @@ def self.sync? # regular expression. All other messages will be ignored # Proc: Only include log messages where the supplied Proc returns true # The Proc must return true or false - def initialize(klass, level = nil, filter = nil) + # + # instance_named_tags + # Named tags to be added to all log messages for this logger instance + # Default: {} + def initialize(klass, level = nil, filter = nil, instance_named_tags = {}) super end diff --git a/lib/semantic_logger/subscriber.rb b/lib/semantic_logger/subscriber.rb index ab811136..7392e35e 100644 --- a/lib/semantic_logger/subscriber.rb +++ b/lib/semantic_logger/subscriber.rb @@ -108,8 +108,12 @@ def console_output? # metrics: [Boolean] # Whether to log metric only entries with this subscriber. # Default: false + # + # instance_named_tags: [Hash] + # Named tags to be added to all log messages for this subscriber + # Default: {} def initialize(level: nil, formatter: nil, filter: nil, application: nil, environment: nil, host: nil, - metrics: false, &block) + metrics: false, instance_named_tags: {}, &block) self.formatter = block || formatter @application = application @environment = environment @@ -118,7 +122,7 @@ def initialize(level: nil, formatter: nil, filter: nil, application: nil, enviro # Subscribers don't take a class name, so use this class name if a subscriber # is logged to directly. - super(self.class, level, filter) + super(self.class, level, filter, instance_named_tags) end # Return the level index for fast comparisons. diff --git a/lib/semantic_logger/test/capture_log_events.rb b/lib/semantic_logger/test/capture_log_events.rb index dc07b59f..ad5ae875 100644 --- a/lib/semantic_logger/test/capture_log_events.rb +++ b/lib/semantic_logger/test/capture_log_events.rb @@ -20,6 +20,12 @@ module Test # end # end class CaptureLogEvents < SemanticLogger::Subscriber + def self.copy(instance) + new_instance = super + new_instance.events = [] + new_instance + end + attr_accessor :events # By default collect all log levels, and collect metric only log events. diff --git a/lib/semantic_logger/test/minitest.rb b/lib/semantic_logger/test/minitest.rb index 87394e4a..12d78032 100644 --- a/lib/semantic_logger/test/minitest.rb +++ b/lib/semantic_logger/test/minitest.rb @@ -20,12 +20,13 @@ def semantic_logger_events(deprecated_klass = nil, klass: deprecated_klass, sile logger.events end + # TODO: Add instance_named_tags # Verify a single log event has all the required attributes. def assert_semantic_logger_event(event, level: nil, name: nil, message: nil, message_includes: nil, payload: nil, payload_includes: nil, exception: nil, exception_includes: nil, backtrace: nil, thread_name: nil, tags: nil, named_tags: nil, context: nil, - level_index: nil, duration: nil, time: nil, + instance_named_tags: nil, level_index: nil, duration: nil, time: nil, metric: nil, metric_amount: nil, dimensions: nil) assert event, "No log event occurred" @@ -35,6 +36,7 @@ def assert_semantic_logger_event(event, level: nil, name: nil, message: nil, mes assert_semantic_logger_entry(event, :thread_name, thread_name) assert_semantic_logger_entry(event, :tags, tags) assert_semantic_logger_entry(event, :named_tags, named_tags) + assert_semantic_logger_entry(event, :instance_named_tags, instance_named_tags) assert_semantic_logger_entry(event, :context, context) assert_semantic_logger_entry(event, :metric, metric) assert_semantic_logger_entry(event, :metric_amount, metric_amount) diff --git a/test/loggable_test.rb b/test/loggable_test.rb index 3210e536..0c6beb91 100644 --- a/test/loggable_test.rb +++ b/test/loggable_test.rb @@ -89,8 +89,8 @@ class TestChildClassLogger end describe "sample child class logger" do - it "has child named tags set" do - assert_equal TestChildClassLogger::TAG_DATA, TestChildClassLogger.logger.child_named_tags + it "has instance named tags set" do + assert_equal TestChildClassLogger::TAG_DATA, TestChildClassLogger.logger.instance_named_tags end end end diff --git a/test/logger_test.rb b/test/logger_test.rb index 4bd6df89..832df08f 100644 --- a/test/logger_test.rb +++ b/test/logger_test.rb @@ -155,15 +155,35 @@ def self.call(log) end describe ".child" do - it "creates a child logger" do - tag_data = {tag1: "value1", tag2: "value2"} - child_logger = logger.child(**tag_data) + it "creates a child logger with instance named tags merged with parent" do + parent_tag_data = {parent_tag: "parent_value"} + child_tag_data = {tag1: "value1", tag2: "value2"} + parent_logger = logger.child(**parent_tag_data) + child_logger = parent_logger.child(**child_tag_data) + child_logger.info("hello world") - assert_equal tag_data, child_logger.child_named_tags - assert log = child_logger.events.first - assert_equal "hello world", log.message - assert_equal tag_data, log.payload + assert_equal parent_tag_data, parent_logger.instance_named_tags + assert_equal parent_tag_data.merge(child_tag_data), child_logger.instance_named_tags + end + + it "outputs log entries with different instance named tags from the parent" do + parent_tag_data = {parent_tag: "parent_value"} + child_tag_data = {tag1: "value1", tag2: "value2"} + parent_logger = logger.child(**parent_tag_data) + child_logger = parent_logger.child(**child_tag_data) + + parent_logger.info("hello parent") + + assert log_parent = parent_logger.events.first + assert_equal "hello parent", log_parent.message + assert_equal parent_tag_data, log_parent.instance_named_tags + + child_logger.info("hello child") + + assert log_child = child_logger.events.first + assert_equal "hello child", log_child.message + assert_equal parent_tag_data.merge(child_tag_data), log_child.instance_named_tags end end end