Figured this out after a lot of monkeying-around (I mean script/console).

Situation:

• I have two tables (Revisions has_many Inputs)
• I can load Revisions and then for each I can find Inputs, but quickly found out that for my situation, it leads to a lot of queries. So I want to load the required fields from both tables together

:joins is the only way to do this, using :includes does NOT respect the select clause. Here is the gist I created:

Admittedly, this is hacky, too hacky for my comfort. Comment/suggest a better/cleaner solution?

Note: Found out that there is a gem to do this: ar-select-with-include

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.

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.