Fix default Ruby logger formatter usage

The default Ruby logger formatter expects a timestamp as a second
argument to format it and include it in the message. We were passing an
integer instead to the present formatter, making it fail if the present
formatter is the default Ruby one.

This commit substitutes those 0s with `Time.now` calls.

.changesets/fix-default-ruby-logger-formatter-usage.md

@@ -0,0 +1,6 @@
+---
+bump: "patch"
+type: "fix"
+---
+
+Fixed an error when using our Logging feature with Ruby's default logger formatter.

lib/appsignal/logger.rb

@@ -9,6 +9,13 @@ class Logger < ::Logger # rubocop:disable Metrics/ClassLength
     PLAINTEXT = 0
     LOGFMT = 1
     JSON = 2
+    SEVERITY_MAP = {
+      DEBUG => 2,
+      INFO => 3,
+      WARN => 5,
+      ERROR => 6,
+      FATAL => 7
+    }.freeze
 
     # Create a new logger instance
     #
@@ -25,7 +32,7 @@ def initialize(group, level: INFO, format: PLAINTEXT)
     # We support the various methods in the Ruby
     # logger class by supplying this method.
     # @api private
-    def add(severity, message = nil, group = nil) # rubocop:disable Metrics/CyclomaticComplexity
+    def add(severity, message = nil, group = nil)
       severity ||= UNKNOWN
       return true if severity < level
       group = @group if group.nil?
@@ -38,24 +45,11 @@ def add(severity, message = nil, group = nil) # rubocop:disable Metrics/Cyclomat
         end
       end
       return if message.nil?
-      message = formatter.call(severity, 0, group, message) if formatter
-      severity_number = case severity
-                        when DEBUG
-                          2
-                        when INFO
-                          3
-                        when WARN
-                          5
-                        when ERROR
-                          6
-                        when FATAL
-                          7
-                        else
-                          0
-                        end
+      message = formatter.call(severity, Time.now, group, message) if formatter
+
       Appsignal::Extension.log(
         group,
-        severity_number,
+        SEVERITY_MAP.fetch(severity, 0),
         @format,
         message,
         Appsignal::Utils::Data.generate({})
@@ -71,7 +65,7 @@ def debug(message = nil, attributes = {})
       return if DEBUG < level
       message = yield if message.nil? && block_given?
       return if message.nil?
-      message = formatter.call(DEBUG, 0, @group, message) if formatter
+      message = formatter.call(DEBUG, Time.now, @group, message) if formatter
       Appsignal::Extension.log(
         @group,
         2,
@@ -89,7 +83,7 @@ def info(message = nil, attributes = {})
       return if INFO < level
       message = yield if message.nil? && block_given?
       return if message.nil?
-      message = formatter.call(INFO, 0, @group, message) if formatter
+      message = formatter.call(INFO, Time.now, @group, message) if formatter
       Appsignal::Extension.log(
         @group,
         3,
@@ -107,7 +101,7 @@ def warn(message = nil, attributes = {})
       return if WARN < level
       message = yield if message.nil? && block_given?
       return if message.nil?
-      message = formatter.call(WARN, 0, @group, message) if formatter
+      message = formatter.call(WARN, Time.now, @group, message) if formatter
       Appsignal::Extension.log(
         @group,
         5,
@@ -125,7 +119,7 @@ def error(message = nil, attributes = {})
       return if ERROR < level
       message = yield if message.nil? && block_given?
       return if message.nil?
-      message = formatter.call(ERROR, 0, @group, message) if formatter
+      message = formatter.call(ERROR, Time.now, @group, message) if formatter
       Appsignal::Extension.log(
         @group,
         6,
@@ -143,7 +137,7 @@ def fatal(message = nil, attributes = {})
       return if FATAL < level
       message = yield if message.nil? && block_given?
       return if message.nil?
-      message = formatter.call(FATAL, 0, @group, message) if formatter
+      message = formatter.call(FATAL, Time.now, @group, message) if formatter
       Appsignal::Extension.log(
         @group,
         7,

spec/lib/appsignal/logger_spec.rb

@@ -115,14 +115,29 @@
 
       context "with a formatter set" do
         before do
-          logger.formatter = proc do |_level, _timestamp, _appname, message|
-            "formatted: '#{message}'"
+          Timecop.freeze(Time.local(2023))
+          logger.formatter = logger.formatter = proc do |_level, timestamp, _appname, message|
+            # This line replicates the behaviour of the Ruby default Logger::Formatter
+            # which expects a timestamp object as a second argument
+            # https://github.com/ruby/ruby/blob/master/lib/logger/formatter.rb#L15-L17
+            time = timestamp.strftime("%Y-%m-%dT%H:%M:%S.%6N")
+            "formatted: #{time} '#{message}'"
           end
         end
 
+        after do
+          Timecop.return
+        end
+
         it "should log with a level, message and group" do
           expect(Appsignal::Extension).to receive(:log)
-            .with("group", method[1], 0, "formatted: 'Log message'", instance_of(Appsignal::Extension::Data))
+            .with(
+              "group",
+              method[1],
+              0,
+              "formatted: 2023-01-01T00:00:00.000000 'Log message'",
+              instance_of(Appsignal::Extension::Data)
+            )
           logger.send(method[0], "Log message")
         end
       end