Exception on logger.error({ payload: '', foo: 'bar' }) (trying to log an arbitrary hash with payload key)

[Drowze]

Environment

• Ruby Version: 3.1.2
• Semantic Logger Version: 4.12.0

Expected Behavior

I'd expect SemanticLogger to be fully compatible with ::Logger, so I'd expect no error to be raised.
Perhaps detecting it's an arbitrary hash and considering it as a message (i.e. treat it the same as logger.error(message: { payload: '', foo: 'bar' }) and maybe also raise a warning pointing to bad use of payload keyword) would be a good choice.

Actual Behavior

Logger.new($stdout).error({payload: '', foo: 'bar'})
# E, [2022-11-17T21:51:37.400739 #74531] ERROR -- : {:payload=>"", :foo=>"bar"}

require 'semantic_logger'
SemanticLogger.add_appender(io: $stdout)
SemanticLogger['a'].error({ payload: '', foo: 'bar' })
# exception raised...

stacktrace:

/Users/Drowze/.asdf/installs/ruby/3.1.2/lib/ruby/gems/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/log.rb:77:in `assign': unknown keyword: :foo (ArgumentError)
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/lib/ruby/gems/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/base.rb:333:in `log_internal'
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/lib/ruby/gems/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/concerns/compatibility.rb:44:in `add'
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/lib/ruby/gems/3.1.0/gems/semantic_logger-4.12.0/lib/semantic_logger/logger.rb:71:in `log'
        from (irb):12:in `<main>'
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/lib/ruby/gems/3.1.0/gems/irb-1.4.1/exe/irb:11:in `<top (required)>'
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/bin/irb:25:in `load'
        from /Users/Drowze/.asdf/installs/ruby/3.1.2/bin/irb:25:in `<main>'

---

Note: this happened on a real codebase when I was installing rails_semantic_logger in our project. I had a change similar to the following to fix it:

      Rails.logger.info(
-       message: "#{self.class.name}##{method}",
-       payload: message.payload,
-       headers: message.headers.except(:key)
+       "#{self.class.name}##{method}",
+       payload: {
+         payload: message.payload,
+         headers: message.headers.except(:key)
+       }
      )

[reidmorrison]

Correct, payload is a reserved keyword for Semantic Logger and must be a Hash. Strings are not permitted.

[Drowze]

Would treating keyword arguments and positional arguments differently be an option? E.g.:

positional arguments:

SemanticLogger['a'].error({ payload: '', foo: 'bar' })

# same as:
SemanticLogger['a'].error(payload: { payload: '', foo: 'bar' })

keyword arguments:

SemanticLogger['a'].error(payload: '', foo: 'bar')

# raises error

I guess this might be a breaking change though

[duien]

I was just bitten by this in a way that felt very much like incorrect behavior. My code (using rails_semantic_logger) is something like:

log_params = { subject: 'foo', payload: } 
Rails.logger.info("my message", log_params)

Adding the key payload to the hash causes logging to fail with an ArgumentError. I found documentation that discusses the different ways to call the standard logging API, but it wasn't clear from that documentation that payload is a reserved keyword when using positional arguments. In this case, I am very clearly not using the "pass everything in a hash" style, since I've passed the message as a positional argument, and it feels pretty dangerous that I could introduce exceptions in logging based the keys present in the hash I'm trying to log. There are a lot of use-cases where that hash is based on user input or data assembled from different sources, which makes this feel particularly dangerous.

The difference in how I'm calling the logger here felt different enough from the original example that it seemed worth verifying if this behavior is intended in the case of positional arguments as well.