Guarded loggin examples, for use in http://www.arnab-deka.com/posts/2009/08/guarded-logging-in-ruby/

benchmarking_example.rb

require 'benchmark'
require 'logger'

class LoggerBenchmark
  def initialize
    @logger = Logger.new("/dev/null")
  end

  def benchmark
    n = 10000
    # I use bmbm method and not bm here
    # so the effects of initializing etc. are abstracted away
    Benchmark.bmbm do |x|
      x.report("with block") do
        n.times do |i|
          # trying to do *some* arithmetic here
          # so there is *some* work for string-creation
          @logger.warn { "logging with block - #{rand * 1000 % i}" }
        end
      end

      x.report("with string") do
        n.times do |i|
          @logger.warn "logging with string - #{rand * 1000 % i}"
        end
      end

      x.report("with severity check") do
        n.times do |i|
          if @logger.warn?
            @logger.warn("logging with severity check - #{rand * 1000 % i}")
          end
        end
      end

    end
  end
end

LoggerBenchmark.new.benchmark

example.java

if( logger.isLoggable(Level.INFO) ) {
    logger.info( "this is a " + "info" + "message" );
}

example.rb

logger.debug { "this is a " + "debug" + "message" }

results_medium_n.sh

$ time ruby logger_benchmark.rb
Rehearsal ---------------------------------------------------------------
with block            7.630000   1.030000   8.660000 (  8.669890)
with string           6.410000   0.840000   7.250000 (  7.270509)
with severity check   6.570000   0.890000   7.460000 (  7.472230)
----------------------------------------------------- total: 23.370000sec

                                  user     system      total        real
with block            6.760000   0.930000   7.690000 (  7.697947)
with string           6.320000   0.870000   7.190000 (  7.190802)
with severity check   6.460000   0.930000   7.390000 (  7.394368)
ruby logger_benchmark.rb  40.20s user 5.50s system 99% cpu 45.755 total

results_small_n.sh

$ time ruby logger_benchmark.rb
Rehearsal —————————————————————
with block            1.340000   0.160000   1.500000 (  1.500111)
with string           0.740000   0.110000   0.850000 (  0.845971)
with severity check   0.650000   0.080000   0.730000 (  0.736908)
—————————————————— total: 3.080000sec

                                  user     system      total        real
with block            0.670000   0.100000   0.770000 (  0.765206)
with string           0.640000   0.080000   0.720000 (  0.715421)
with severity check   0.660000   0.080000   0.740000 (  0.733024)
ruby logger_benchmark.rb  4.72s user 0.62s system 99% cpu 5.351 total