Browsing the blog archives for August, 2009.

#songsincode (twitter geek fun)

programming

This blog is about twitter hastags. To learn more about twitter hashtags, go here.

So #songsincode has been ruling the twitter trends for a day now). Didn’t follow it? No worries – here’s a recent blog with some good (early) ones.

Basically, it was the most fun I have had reading hashtags. Today, after lunch I took a plunge too :)

Original tweet here:

(you.breath + you.move).each { i.missing(you) }

Original tweet here:

while ( time(you.reverse) < = 1.minute )
  i = you.steps_behind(2)
end

Oh don’t tell me I was so bad you could not even guess the songs (Every Breath You Take and Two Steps Behind.

Add the first comment

Guarded logging in Ruby?

programming

Assuming you know about “guarded logging”, a Java logging best practise. If not, get an overview in this IBM article or in this blog.

Basically it is the practice of checking if a particular log message will indeed be outputted to the log (based on the severity level) before calling the log statement. This is a performance improvement.

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

So I heard from one of my colleagues that Ruby’s logging performance can also be improved the same way, by putting the message in a block (instead of just passing it as an string arg to the method):

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

See various ways to log a message at the ruby-docs (search for “How to log a message” in that page).
I looked into the source-code and, just like in Java, the first thing that is done is to check the severity and return (true) if the severity is higher than the message’s. So like in Java, it should not have any effect (except creating the strings etc.).

Just to test it out, I wrote a benchmark test:

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

Here’s what I noticed:

  • with n (the number of logging calls) set to < = 10,000, there was really no difference between the three ways:
    $ 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
    
  • with n set to 100,000: It looked like the simplest way to log (with a string-arg) still performs the best:
    $ 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
        

Final takeaway: it really does not make that big a difference and keeping it simple (with a string-arg) should work. If you are worried about performance, this probably is not a trick that will give you a big bang for the buck.

Add the first comment

Photos: Hamilton Viewpoint Park and Alki Beach, West Seattle

on life

On a photo uploading spree today.

The first album consists photos from Hamilton Park and Alki Beach, a beautiful area in West Seattle. Because of it’s location, you get great views of Seattle and the Harbor from here, specially great in the evening.

Hamilton Viewpoint Park: See details here and the Seattle gov parks page.

The full album (only 26 pics – easy to click through and to add comments too) is on my smugmug site: http://arnab-o-scope.smugmug.com/gallery/9163956_kwkf7.

Here are a few excerpts:

Add the first comment