Add ActiveSupport tagged logging support

Our logger did not support Rails ActiveSupport tagged logging yet. This was because our logger didn't listen to the `tagged`, `push_tags` and `pop_tags` methods. Implement these methods to have the logger that wraps our logger call these methods to set tags. The format is the same as Rails formats it: `[My tag value]` I decide not to set these as attributes, because they're only values. They have no key and the value can be anything and change frequently.
appsignal · Dec 5, 2024 · 72955eb · 72955eb
1 parent ad83dd6
commit 72955eb
Show file tree

Hide file tree

Showing 3 changed files with 136 additions and 0 deletions.
diff --git a/.changesets/add-rails-activesupport-tagged-logging.md b/.changesets/add-rails-activesupport-tagged-logging.md
@@ -0,0 +1,14 @@
+---
+bump: patch
+type: add
+---
+
+Support Rails/ActiveSupport tagged logging. When tags are set in apps using `Rails.logger.tagged { ... }` or with the `Rails.application.config.log_tags = [...]` config option, these tags are now included in the collected log messages.
+
+```ruby
+Rails.logger.tagged(["Tag 1", "Tag 2"]) { Rails.logger.info("My message") }
+```
+
+Reports this log message:
+
+> [Tag 1] [Tag 2] My message
diff --git a/lib/appsignal/logger.rb b/lib/appsignal/logger.rb
@@ -38,6 +38,7 @@ def initialize(group, level: INFO, format: PLAINTEXT, attributes: {})
       @mutex = Mutex.new
       @default_attributes = attributes
       @appsignal_attributes = {}
+      @tags = []
     end
 
     # We support the various methods in the Ruby
@@ -58,6 +59,11 @@ def add(severity, message = nil, group = nil)
       end
       return if message.nil?
 
+      if @tags.any?
+        formatted_tags = @tags.map { |tag| "[#{tag}]" }
+        message = "#{formatted_tags.join(" ")} #{message}"
+      end
+
       message = formatter.call(severity, Time.now, group, message) if formatter
 
       unless message.is_a?(String)
@@ -144,6 +150,29 @@ def fatal(message = nil, attributes = {})
       add_with_attributes(FATAL, message, @group, attributes)
     end
 
+    # Listen to ActiveSupport tagged logging tags set with `Rails.logger.tagged`.
+    def tagged(tags)
+      @tags.append(*tags)
+      yield self
+    ensure
+      @tags.pop(tags.length)
+    end
+
+    # Listen to ActiveSupport tagged logging tags set with `Rails.config.log_tags`.
+    def push_tags(tags)
+      @tags.append(*tags)
+    end
+
+    # Remove a set of ActiveSupport tagged logging tags set with `Rails.config.log_tags`.
+    def pop_tags(count = 1)
+      @tags.pop(count)
+    end
+
+    # Remove all ActiveSupport tagged logging tags set with `Rails.config.log_tags`.
+    def clear_tags!
+      @tags.clear
+    end
+
     # When using ActiveSupport::TaggedLogging without the broadcast feature,
     # the passed logger is required to respond to the `silence` method.
     # In our case it behaves as the broadcast feature of the Rails logger, but

diff --git a/spec/lib/appsignal/logger_spec.rb b/spec/lib/appsignal/logger_spec.rb
@@ -232,4 +232,97 @@
       logger.error(error)
     end
   end
+
+  if DependencyHelper.rails_present?
+    describe "tagged logging" do
+      it "logs messages with tags from logger.tagged" do
+        expect(Appsignal::Extension).to receive(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[My tag] [My other tag] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+
+        appsignal_logger = Appsignal::Logger.new("group")
+        logger = ActiveSupport::TaggedLogging.new(appsignal_logger)
+        logger.tagged("My tag", "My other tag") { logger.info("Some message") }
+      end
+
+      it "logs messages with tags from Rails.application.config.log_tags" do
+        allow(Appsignal::Extension).to receive(:log)
+
+        appsignal_logger = Appsignal::Logger.new("group")
+        logger = ActiveSupport::TaggedLogging.new(appsignal_logger)
+
+        # This is how Rails sets the `log_tags` values
+        logger.push_tags(["Request tag", "Second tag"])
+        logger.tagged("First message", "My other tag") { logger.info("Some message") }
+        expect(Appsignal::Extension).to have_received(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[Request tag] [Second tag] [First message] [My other tag] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+
+        # Logs all messsages within the time between `push_tags` and `pop_tags`
+        # with the same set tags
+        logger.tagged("Second message") { logger.info("Some message") }
+        expect(Appsignal::Extension).to have_received(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[Request tag] [Second tag] [Second message] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+
+        # This is how Rails clears the `log_tags` values
+        # It will no longer includes those tags in new log messages
+        logger.pop_tags(2)
+        logger.tagged("Third message") { logger.info("Some message") }
+        expect(Appsignal::Extension).to have_received(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[Third message] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+      end
+
+      it "clears all tags with clear_tags!" do
+        allow(Appsignal::Extension).to receive(:log)
+
+        appsignal_logger = Appsignal::Logger.new("group")
+        logger = ActiveSupport::TaggedLogging.new(appsignal_logger)
+
+        # This is how Rails sets the `log_tags` values
+        logger.push_tags(["Request tag", "Second tag"])
+        logger.tagged("First message", "My other tag") { logger.info("Some message") }
+        expect(Appsignal::Extension).to have_received(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[Request tag] [Second tag] [First message] [My other tag] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+
+        logger.clear_tags!
+        logger.tagged("First message", "My other tag") { logger.info("Some message") }
+        expect(Appsignal::Extension).to have_received(:log)
+          .with(
+            "group",
+            3,
+            0,
+            "[First message] [My other tag] Some message\n",
+            Appsignal::Utils::Data.generate({})
+          )
+      end
+    end
+  end
 end