Guarding Logger Statements In Ruby

December 9, 2009

Whether you are a Java or a Ruby programmer, I'm sure you are familiar with this idiom:

require 'logger'

log = Logger.new(STDOUT)
log.level = Logger::INFO

log.debug("hello")
log.info("Done")

That's a simple logger where the log level is set to info, so the debug statement isn't logged, but the info statement is. One gotcha to look out for is something like this:

require 'logger'

log = Logger.new(STDOUT)
log.level = Logger::INFO

def fib(n)
  if n < 1
    0
  elsif n < 2
    1
  else
    fib(n-1) + fib(n-2)
  end
end

log.debug("fib(30) => #{fib(30)}")
log.info("Done")

This also just logs "Done", but it take more than a few seconds to do so. The reason why is that even though you aren't logging the string that gets passed to debug, the ruby interpreter still has to incur the cost of generating the string and passing it to debug, where it gets ignored.

If you are an old Java programmer like me, you'll probably know you can fix it like this:

require 'logger'

log = Logger.new(STDOUT)
log.level = Logger::INFO

def fib(n)
  if n < 1
    0
  elsif n < 2
    1
  else
    fib(n-1) + fib(n-2)
  end
end

if log.debug?
  log.debug("fib(30) => #{fib(30)}")
end
log.info("Done")

That works, but it's not the Ruby way of doing it. It's the idiomatic way of doing it in Java, but that is due to the fact that Java doesn't have anonymous functions nor a concise syntax for creating them. The Ruby way of doing it is:

require 'logger'

log = Logger.new(STDOUT)
log.level = Logger::INFO

def fib(n)
  if n < 1
    0
  elsif n < 2
    1
  else
    fib(n-1) + fib(n-2)
  end
end

log.debug { "fib(30) => #{fib(30)}" }
log.info("Done")

The difference between this version and the original is that instead of passing a string to debug, we pass a block that returns a string when it is called. We don't have to wrap it in an if statement because the block can be conditionally evaluated based on the current log level.

The difference between the if statement and the block is admittedly minor. That being said, prefer the block syntax. :)

The important thing to remember is that if you have a debug statement that does any kind of calculating, pass it a block instead of just a string to avoid the overhead associated with unnecessarily building the string.

Posted in Technology | Tags RubyOnRails, Ruby, Java | 2 Comments

Active Record Random

August 30, 2009

Are you looking for a way to select a random record that plays nice with named scope in your Rails app? Throw this into config/initializers/active_record_random.rb:

class ActiveRecord::Base
  def self.random
    if (c = count) > 0
      first(:offset => rand(c)) 
    end
  end
end

Now you can call random the same way you would call first or all. That means you can do Widget.random to get a random widget or Widget.fancy.random, to get a random fancy widget, assuming you have defined the fancy named scope for Widget.

Posted in Technology | Tags NamedScope, RubyOnRails, Ruby, Rails | 6 Comments