A few people have asked me for the module I’ve been using to profile my code in my “Double Quotes vs. Single Quotes”:/2008/06/10/ruby-performance-use-double-quotes-vs-single-quotes article. It is merely a wrapper around “RubyProf”:http://ruby-prof.rubyforge.org/, dead simple and nothing worth commenting on, but since some keep asking – here it is:
require 'rubygems'
require 'ruby-prof'
module PeepcodeProfiler
def time_this(comment, &block)
RubyProf.measure_mode = RubyProf::PROCESS_TIME
RubyProf.start
yield
result = RubyProf.stop
puts "\nTimings for #{comment}"
printer = RubyProf::FlatPrinter.new(result)
printer.print(STDOUT, 0)
end
endI wrote this for some work on a “Scaling Rails” minibook for “Peepcode”:http://peepcode.com/, which I seem to be unable to finish. I hope Geoffrey forgives me.
UPDATE: As cremes pointed out below, these timings obviously only reflect the version of Ruby I was running at the time. (ruby 1.8.6 (2008-08-11 patchlevel 287) [universal-darwin9.0]). When using any other version of the interpreter, all bets are off.
Another interesting set of timings are the differences between the branching control statements @case-when@ and @if-else@. Here is a quick example:
require 'profilings'
include PeepcodeProfiler
###
# Case-when vs. If-Elsif-Else
###
time_this("case-when using strings") {
x = "10"
case x
when "1"
puts "it is #{x}"
when "2"
puts "it is #{x}"
when "3"
puts "it is #{x}"
when "4"
puts "it is #{x}"
when "5"
puts "it is #{x}"
when "6"
puts "it is #{x}"
when "7"
puts "it is #{x}"
when "8"
puts "it is #{x}"
when "9"
puts "it is #{x}"
when "10"
puts "it is #{x}"
end
}Timings for case when using strings Thread ID: 218880 Total: 0.000113 %self total self wait child calls name 36.28 0.00 0.00 0.00 0.00 10 Kernel#=== (ruby_runtime:0} 31.86 0.00 0.00 0.00 0.00 2 IO#write (ruby_runtime:0} 22.12 0.00 0.00 0.00 0.00 10 String#== (ruby_runtime:0} 9.73 0.00 0.00 0.00 0.00 1 Kernel#puts (ruby_runtime:0} 0.00 0.00 0.00 0.00 0.00 0 PeepcodeProfiler#time_this (./profilings.rb:8}
…and again the faster @if-elsif-else@:
time_this("if-elsif-else using strings") {
x = "10"
if x == "1"
puts "it is #{x}"
elsif x == "2"
puts "it is #{x}"
elsif x == "3"
puts "it is #{x}"
elsif x == "4"
puts "it is #{x}"
elsif x == "5"
puts "it is #{x}"
elsif x == "6"
puts "it is #{x}"
elsif x == "7"
puts "it is #{x}"
elsif x == "8"
puts "it is #{x}"
elsif x == "9"
puts "it is #{x}"
elsif x == "10"
puts "it is #{x}"
else
puts "it is #{x}"
end
}Timings for if elsif else using strings Thread ID: 218880 Total: 0.000049 %self total self wait child calls name 46.94 0.00 0.00 0.00 0.00 10 String#== (ruby_runtime:0} 30.61 0.00 0.00 0.00 0.00 2 IO#write (ruby_runtime:0} 22.45 0.00 0.00 0.00 0.00 1 Kernel#puts (ruby_runtime:0} 0.00 0.00 0.00 0.00 0.00 0 PeepcodeProfiler#time_this (./profilings.rb:8}
OK, obviously the @case-when@ version is slower because it does a compare for each value using the @===@ Kernel operator, which in turn calls the correct @==@ operator for the value type. Whereas the @if-elseif-else@ version doesn’t incur the overhead of the Kernel triple-equal operator for each comparison.
So I wonder if the same thing happens with a different object type:
time_this("case when using integers") {
x = 10
case x
when 1
puts "it is #{x}"
when 2
puts "it is #{x}"
when 3
puts "it is #{x}"
when 4
puts "it is #{x}"
when 5
puts "it is #{x}"
when 6
puts "it is #{x}"
when 7
puts "it is #{x}"
when 8
puts "it is #{x}"
when 9
puts "it is #{x}"
when 10
puts "it is #{x}"
end
}Timings for case when using integers Thread ID: 218880 Total: 0.000104 %self total self wait child calls name 46.15 0.00 0.00 0.00 0.00 10 Kernel#=== (ruby_runtime:0} 19.23 0.00 0.00 0.00 0.00 9 Fixnum#== (ruby_runtime:0} 15.38 0.00 0.00 0.00 0.00 2 IO#write (ruby_runtime:0} 15.38 0.00 0.00 0.00 0.00 1 Kernel#puts (ruby_runtime:0} 3.85 0.00 0.00 0.00 0.00 1 Fixnum#to_s (ruby_runtime:0} 0.00 0.00 0.00 0.00 0.00 0 PeepcodeProfiler#time_this (./profilings.rb:8}
Hmmm, bad news. Here we see the Kernel @===@ operator in the call stack again.
time_this("if elsif else using integers") {
x = 10
if x == 1
puts "it is #{x}"
elsif x == 2
puts "it is #{x}"
elsif x == 3
puts "it is #{x}"
elsif x == 4
puts "it is #{x}"
elsif x == 5
puts "it is #{x}"
elsif x == 6
puts "it is #{x}"
elsif x == 7
puts "it is #{x}"
elsif x == 8
puts "it is #{x}"
elsif x == 9
puts "it is #{x}"
elsif x == 10
puts "it is #{x}"
else
puts "it is #{x}"
end
}Timings for if elsif else using integers Thread ID: 218880 Total: 0.000057 %self total self wait child calls name 50.88 0.00 0.00 0.00 0.00 10 Fixnum#== (ruby_runtime:0} 26.32 0.00 0.00 0.00 0.00 2 IO#write (ruby_runtime:0} 15.79 0.00 0.00 0.00 0.00 1 Kernel#puts (ruby_runtime:0} 7.02 0.00 0.00 0.00 0.00 1 Fixnum#to_s (ruby_runtime:0} 0.00 0.00 0.00 0.00 0.00 0 PeepcodeProfiler#time_this (./profilings.rb:8}
Interesting. Even for a different object type, the @case@ statement incurs the overhead of the Kernel @===@ operator.
Now I’m not saying to always avoid the @case@ statement. It is really a judgement call. I typically prefer cleaner code over slight optimization benefits. However, in this case (no pun intended) @if-elsif-else@ is consistently about twice as fast as the @case-when@ statement. You be the judge for your own particular situation.
Take a look “here”:/2008/11/18/the-peepcode-profiler for the “Peepcode profiler”:/2008/11/18/the-peepcode-profiler that we use when doing our metrics. If you come up with interesting metrics please let us know. We are happy to publish them here, giving you the credit, or link to them from here.
Happy Hacking!!!
UPDATE: Peter Wagenet brought up a good point, noting that our metrics did not completely determine if the slower @case@ statement is indeed slower merely because it uses @===@ operator, or if there is more overhead involved with @case@. So here is our test…
time_this("if elsif else using integers with ===") {
x = 10
if x === 1
puts "it is #{x}"
elsif x === 2
puts "it is #{x}"
elsif x === 3
puts "it is #{x}"
elsif x === 4
puts "it is #{x}"
elsif x === 5
puts "it is #{x}"
elsif x === 6
puts "it is #{x}"
elsif x === 7
puts "it is #{x}"
elsif x === 8
puts "it is #{x}"
elsif x === 9
puts "it is #{x}"
elsif x === 10
puts "it is #{x}"
else
puts "it is #{x}"
end
}Timings for if elsif else using integers with === Thread ID: 218880 Total: 0.000081 %self total self wait child calls name 50.62 0.00 0.00 0.00 0.00 10 Kernel#=== (ruby_runtime:0} 23.46 0.00 0.00 0.00 0.00 9 Fixnum#== (ruby_runtime:0} 11.11 0.00 0.00 0.00 0.00 1 Kernel#puts (ruby_runtime:0} 11.11 0.00 0.00 0.00 0.00 2 IO#write (ruby_runtime:0} 3.70 0.00 0.00 0.00 0.00 1 Fixnum#to_s (ruby_runtime:0} 0.00 0.00 0.00 0.00 0.00 0 PeepcodeProfiler#time_this (./profilings.rb:8}
After running the test several times I have determined that using the @===@ operator is obviously, and consistently slower than @==@ alone. However, the @case@ statement is consistently slower still, than @if-elsif@ using the @===@ operator. Therefore @case@ does incur overhead beyond the simple use of @===@ by about 20%.