semantic_logger icon indicating copy to clipboard operation
semantic_logger copied to clipboard

Unable to modify appenders or formatters without restarting the application.

Open todd-a-jacobs opened this issue 3 years ago • 2 comments
trafficstars

Environment

  • Ruby 3.1.0
  • semantic_logger 4.9.0
  • Vanilla Ruby in a standard IRB console

Expected Behavior

  1. Logging to IO streams (especially $stdout and $stderr) should be modifiable or at least replaceable.
  2. Formatters for a logging instance should be modifiable without having to restart the application.
  3. Using separate named loggers as a workaround should allow modifying the application name.

Actual Behavior

Unable to Modify or Replace an Appender

There doesn't seem to be an obvious interface for changing the output or formatting for an appender defined directly on SemanticLogger, and attempting to change the format results in an error. As an example, if I want to change a particular log line from the color formatter to JSON, I get a logged error (not an exception):

SemanticLogger::Appenders -- Ignoring attempt to add a second console appender: SemanticLogger::Appender::IO since it would result in duplicate console output.

This will reproduce the error:

require 'semantic_logger'
require 'securerandom'

@uuid = SecureRandom.uuid

SemanticLogger.default_level = :trace
SemanticLogger.add_appender(io: $stderr, formatter: :color)

logger = SemanticLogger["irb"]

orig_payload = {foo: 1, bar: 2}
SemanticLogger.tagged(@uuid) do
  logger.info "insert message here", payload: orig_payload
end

SemanticLogger.add_appender(io: $stderr, formatter: :json)
#=> 2022-01-29 18:19:00.243800 W [44340:25120] SemanticLogger::Appenders -- Ignoring attempt to add a second console appender: SemanticLogger::Appender::IO since it would result in duplicate console output.

There aren't any accessible variables to remove, replace, or modify an appender once it's been defined, either:

SemanticLogger.instance_variables
#=> [:@application, :@environment, :@default_level, :@default_level_index, :@backtrace_level, :@backtrace_level_index, :@sync]

logger.instance_variables
#=> [:@filter, :@name, :@level_index, :@level]

As a result, the only way I've found to change formatters is to have completely separate loggers defined. For example:

color = SemanticLogger::Appender::IO.new($stderr, formatter: :color)
json  = SemanticLogger::Appender::IO.new($stderr, formatter: :json)

color.info
#=> 2022-01-29 18:27:10.621756 I [44461:97100] SemanticLogger::Appender::IO -- foo

json.info "foo"
{"host":"host.local","application":"Semantic Logger","timestamp":"2022-01-29T23:27:16.841482Z","level":"info","level_index":2,"pid":44461,"thread":"97100","name":"SemanticLogger::Appender::IO","message":"foo"}

Unable to Modify the Application Name with Named IO Loggers

Furthermore, setting the application when defining the appender this way or even after the fact looks like it works, but doesn't.

color.application = "irb"
#=> "irb"

color.application
#=> "irb"

color.info "foo"
2022-01-29 18:37:47.534302 I [44667:31340] SemanticLogger::Appender::IO -- foo

todd-a-jacobs avatar Jan 29 '22 23:01 todd-a-jacobs

Using the public interface for Semantic Logger is the best approach: https://github.com/reidmorrison/semantic_logger/blob/master/lib/semantic_logger/semantic_logger.rb#L175

SemanticLogger.appenders returns the list of registered appenders. https://github.com/reidmorrison/semantic_logger/blob/master/lib/semantic_logger/semantic_logger.rb#L191

SemanticLogger.application= can be used to set the global application name.

reidmorrison avatar Jan 31 '22 21:01 reidmorrison

SemanticLogger.appenders returns the list of registered appenders. https://github.com/reidmorrison/semantic_logger/blob/master/lib/semantic_logger/semantic_logger.rb#L191

I think the problem I was trying to address is the inability to delete or modify an appender once defined. For example, the following works, but isn't obvious or well-documented:

SemanticLogger.add_appender io: $stderr
SemanticLogger.appenders.count
#=> 1

SemanticLogger.appenders.pop
SemanticLogger.appenders
#=> []

Thank you for pointing me in the right direction. I didn't realize that #appenders provided Array-like behavior (including the very useful #SemanticLogger.clear_appenders! method) and that I could remove an appender with these methods. It definitely solved my immediate problem.

I'm not sure if I understand the gem's internals well enough to implement a public interface for deleting appenders, although I might take a stab at it. Otherwise, would you be willing to accept a pull request against the README to make the process of appender management and deletion more obvious? I'd be more than happy to offer one.

todd-a-jacobs avatar Feb 02 '22 00:02 todd-a-jacobs

Todd, I think you may have missed what Reid was saying? Or did I misunderstand you? There is already a public interface on SemanticLogger for deleting an appender.

I encountered a similar need, and my approach was to store the appender in a variable and then delete it later. Here is a script that illustrates deleting appenders both ways:

#!/usr/bin/env ruby

require 'semantic_logger'

io_appender   = SemanticLogger::Appender::IO.new($stdout)
file_appender = SemanticLogger::Appender::File.new('/dev/null')

SemanticLogger.add_appender(appender: io_appender)
SemanticLogger.add_appender(appender: file_appender)

appenders = SemanticLogger.appenders
puts "appenders is a #{appenders.class} and its ancestors are:\n#{appenders.class.ancestors.inspect}.\n\n"

puts "Starting with #{SemanticLogger.appenders.size} appenders:"
puts appenders
puts

puts 'Now deleting the IO appender using the appenders array...'
appenders.delete(io_appender)

puts "The remaining appenders are:"
puts appenders

puts "\nAnd now deleting the remaining File appender using the SemanticLogger.remove_appender:"
SemanticLogger.remove_appender(file_appender)
puts "The remaining appenders are:"
p appenders

Output is:

appenders is a SemanticLogger::Appenders and its ancestors are:
[SemanticLogger::Appenders, Concurrent::Array, Array, Enumerable, Object, Kernel, BasicObject].

Starting with 2 appenders:
#<SemanticLogger::Appender::IO:0x00007f7899f66f58>
#<SemanticLogger::Appender::File:0x00007f7899f09240>

Now deleting the IO appender using the appenders array...
The remaining appenders are:
#<SemanticLogger::Appender::File:0x00007f7899f09240>

And now deleting the remaining File appender using the SemanticLogger.remove_appender:
The remaining appenders are:
[]

keithrbennett avatar Oct 16 '22 11:10 keithrbennett

Regarding not being able to change a formatter after the appender has been constructed, this may actually be a good thing. Assuming that multiple threads are writing to the log, it would be possible for messages other than the intended ones to have their formats changed. Also, calls to change the formatter from multiple threads might collide, overwriting each other. Having separate loggers for the separate formats, the way you did, may be the best solution.

That said, I guess there could be times when the developer, knowing his or her application would not suffer from any of these risks (as in an application with only one logging thread), would still want to modify the formatter. Perhaps a replace_formatter! method with a descriptive warning comment would be good.

keithrbennett avatar Oct 16 '22 12:10 keithrbennett

@todd-a-jacobs Also, beware of using the Appenders object directly, as in your Appenders.pop example; for example, to remove an appender (for the remainder of the application's runtime), SemanticLogger.remove_appender is better than direct manipulation of the Appenders object because it will also close the appender, and maybe perform other cleanup in the future. I think this is why @reidmorrison suggested using the SemanticLogger methods instead.

keithrbennett avatar Dec 26 '22 09:12 keithrbennett