How do you add a Logger to a class and specify a formatter?

Since the logging has changed, I’m trying to set a logger for a cake task class and also specify a formatter. I see from the docs the recommend way is to use a constant:

class ProcessImages
  Log = ::Log.for("ProcessImages")

  def call
    Log.info { "Processsing images...")
    # ...
  end

end

Previously I was able to set a formatter this way:

backend = ::Log::IOBackend.new
backend.formatter = ::Log::Formatter.new do |entry, io|
  io << entry.timestamp.to_s("%Y-%m-%d %H:%M:%S.%L") << "\t"
  io << entry.severity.label.center(7) << "\t"
  io << entry.message
end
Log.setup_from_env(backend: backend)

However, I’m not sure where this code goes now that Log is a class-level constant.

That initialization code works fine.

Maybe there is another Log.setup_* call in your code that is wiping out your intended initialization?

I’ve accidentally run setup on logging multiple times too.
@bcardiff it might be nice to Log a warning message if it’s initialized more than once

The log messages only show up in STDOUT after the (long running) process has ended. Is there a way to flush after each message? Similar to Ruby’s $stdout.sync=true?

class ProcessImages
  Log = ::Log.for("ProcessImages", :debug)

  def initialize
    initialize_log_backend_formatter
  end

  def initialize_log_backend_formatter
    backend = ::Log::IOBackend.new
    backend.formatter = ::Log::Formatter.new do |entry, io|
      io << entry.timestamp.to_s("%Y-%m-%d %H:%M:%S.%L") << "\t"
      io << entry.severity.label.center(7) << "\t"
      io << entry.message
    end
    Log.backend = backend
  end
  
  def call
    Log.info { "Processing images..." }
    # ...
  end

  # ...

end
1 Like

If that’s what you want you can do STDOUT.sync = true (which also works in Ruby)

The only way I can think of to accomplish that is that Log.setup methods would receive a lock parameter that will cause all other Log.setup calls to fail. But I don’t like the design of that. Do you have any other suggestion @stakach?

There is a bit of tension between having sane defaults and allowing customization. Also, during specs some might want to reconfigure logs.

If the logs would be setup via configuration files instead of code there would be less confusion. But we choose to allow code configuration at this initial stage.

I was thinking that we allow multiple log.setup calls, just output a warning if they are run more than once.
You can still modify bindings after setup using Log.builder.bind which works well, but running setup more than once is probably undesirable.

Maybe add an ENV var to if you expect to call setup more than once that can be used to suppress warnings

Both frameworks and std-lib can define a default Log.setup configuration. The issue here is that due to file requirement order you might misconfigure without knowing.

Maybe Log.setup can emit a Log.debug with the current configuration: "Reconfiguring log: #{callee.join(";")}".

That way, if there was an output in a place you expect, at least you will a notice that the log is been reconfigured.

1 Like