Honor Logger#level overrides

[georgeclaghorn]

We attempt to override Logger#level in Rails’s Logger subclass to allow setting a different level per thread (and thus per request). But Logger#add checks the new message’s severity against the @level instance variable, so overriding #level doesn’t have the intended effect. (We also prepend a check against #level to #add, so you can only set the thread-local level greater than or equal to @level, not less. We’d like to allow setting any thread-local level.)

This patch modifies Logger#add to check #level so that third-party loggers can customize how the current level is determined without needing to reimplement #add or juggle multiple underlying Logger instances.

[ioquatix]

What's the perf impact? I assume it's minimal, but it's the only thing that might block this being merged. Can you show it's minimal?

[georgeclaghorn]

Yes, it’s minimal:

Warming up --------------------------------------
                ivar    18.201k i/100ms
              method    18.234k i/100ms
Calculating -------------------------------------
                ivar    196.802k (± 4.3%) i/s -    982.854k in   5.004753s
              method    197.455k (± 2.5%) i/s -      1.003M in   5.082262s

Comparison:
              method:   197455.1 i/s
                ivar:   196801.8 i/s - same-ish: difference falls within error

Benchmarking script

require 'benchmark/ips'
require 'logger'

class Logger
  def add_using_method(severity, message = nil, progname = nil)
    severity ||= UNKNOWN
    if @logdev.nil? or severity < level
      return true
    end
    if progname.nil?
      progname = @progname
    end
    if message.nil?
      if block_given?
        message = yield
      else
        message = progname
        progname = @progname
      end
    end
    @logdev.write(
      format_message(format_severity(severity), Time.now, progname, message))
    true
  end
end

logger = Logger.new(File.open("/dev/null", "w"))

Benchmark.ips do |x|
  x.config :time => 5, :warmup => 2

  x.report("ivar")   { logger.add(Logger::DEBUG, "Test") }
  x.report("method") { logger.add_using_method(Logger::DEBUG, "Test") }

  x.compare!
end

[ioquatix]

Change is minimal, doesn't appear to break backwards compatibility, and performance impact is minimal.

[ioquatix]

I am happy with this.