Unit 1, Lesson 21
In Progress
Benchmark-IPS
Video transcript & code
In episode #322 we met the Ruby standard Benchmark class, and learned how to use it to check the performance of difference kinds of code. As I said then, the standard benchmark library is the most important one to know, because it's always available to you.
But there are other benchmarking tools in the Ruby universe. Today we're going to meet one of them.
Here's some code that I wrote the other day in order to test some different Ruby dynamic method dispatch schemes against each other.
Event = Struct.new(:name, :source, :args)
class TestBed
attr_reader :event_log
def initialize
@event_log = []
end
end
class HardcodeTestbed < TestBed
def call(event)
case event.name
when :foo
handle_foo(event)
when :bar
handle_bar(event)
when :baz
handle_baz(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTestbed < TestBed
def call(event)
handler_name = "handle_#{event.name}"
__send__(handler_name, event) if respond_to?(handler_name)
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = method_name.to_sym
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
__send__(handler_method, event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class BindTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = instance_method(method_name)
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
handler_method.bind(self).call(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class CodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"when :#{event_name} then handle_#{event_name}(event)"
}.join("\n")
class_eval %{
def call(event)
case event.name
#{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class IfCodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"event.name.equal?(:#{event_name}) then handle_#{event_name}(event)"
}.join("\nelsif ")
class_eval %{
def call(event)
if #{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
def do_test(klass)
testbed = klass.new
testbed.call(e1 = Event[:foo])
testbed.call(e2 = Event[:bar])
testbed.call(e3 = Event[:baz])
testbed.call(Event[:buz])
unless testbed.event_log == [e1, e2, e3]
fail "#{klass}: #{testbed.event_log.inspect}"
end
end
classes = [
HardcodeTestbed,
SendTestbed,
SendTableTestbed,
BindTableTestbed,
CodeGenTestbed,
IfCodeGenTestbed,
]
width = classes.map(&:name).map(&:size).max
require "benchmark"
n = 1000_000
Benchmark.bmbm(16) do |x|
classes.each do |klass|
x.report(klass.name) do
n.times do
do_test(klass)
end
end
end
end
Let's run this, just to remind ourselves what Benchmark output looks like. I'll fast forward a bit so we don't have to wait too long.
$ ruby bench.rb
Rehearsal ----------------------------------------------------
HardcodeTestbed 1.870000 0.000000 1.870000 ( 1.868746)
SendTestbed 4.640000 0.000000 4.640000 ( 4.634629)
SendTableTestbed 2.660000 0.000000 2.660000 ( 2.664021)
BindTableTestbed 4.000000 0.000000 4.000000 ( 3.997878)
CodeGenTestbed 1.810000 0.000000 1.810000 ( 1.816788)
IfCodeGenTestbed 2.090000 0.000000 2.090000 ( 2.097692)
------------------------------------------ total: 17.070000sec
user system total real
HardcodeTestbed 1.790000 0.000000 1.790000 ( 1.784674)
SendTestbed 4.820000 0.000000 4.820000 ( 4.825172)
SendTableTestbed 2.560000 0.000000 2.560000 ( 2.557152)
BindTableTestbed 4.060000 0.010000 4.070000 ( 4.061611)
CodeGenTestbed 1.960000 0.000000 1.960000 ( 1.966116)
IfCodeGenTestbed 2.120000 0.000000 2.120000 ( 2.114812)
While Benchmark is quite useful, there are some areas it could stand some improvement. Some of the nitpicks we might point out include:
- In order to get meaningful aggregate data, we have to manually come up with a good number of repetitions, through trial and error. Then we need to arrange for the code to be repeated that many times.
- As we noticed in that other episode, if we want the results to be
correctly aligned, we have to tell the
#bmbmmethod how long the longest title will be. - When looking at the results, there's no way to tell whether the runtime was mostly consistent across repetitions, or whether certain repetitions contributed to a disproportionate amount of the overall runtime.
- The results are shown in the same order that we ran the tests. Benchmark doesn't give us any help sorting them by runtime.
The benchmark-ips Gem by Evan Phoenix is an extension to Benchmark that addresses all of these complaints. And converting our code to use it couldn't be simpler.
First, after installing the gem, we require benchmark/ips instead of plain benchmark.
Then we replace the #bmbm method with #ips. We remove the label width argument. We won't be needing it anymore.
Then, we get rid of the repetition count and the code that uses it. We won't be needing them anymore either.
Event = Struct.new(:name, :source, :args)
class TestBed
attr_reader :event_log
def initialize
@event_log = []
end
end
class HardcodeTestbed < TestBed
def call(event)
case event.name
when :foo
handle_foo(event)
when :bar
handle_bar(event)
when :baz
handle_baz(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTestbed < TestBed
def call(event)
handler_name = "handle_#{event.name}"
__send__(handler_name, event) if respond_to?(handler_name)
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = method_name.to_sym
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
__send__(handler_method, event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class BindTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = instance_method(method_name)
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
handler_method.bind(self).call(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class CodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"when :#{event_name} then handle_#{event_name}(event)"
}.join("\n")
class_eval %{
def call(event)
case event.name
#{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class IfCodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"event.name.equal?(:#{event_name}) then handle_#{event_name}(event)"
}.join("\nelsif ")
class_eval %{
def call(event)
if #{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
def do_test(klass)
testbed = klass.new
testbed.call(e1 = Event[:foo])
testbed.call(e2 = Event[:bar])
testbed.call(e3 = Event[:baz])
testbed.call(Event[:buz])
unless testbed.event_log == [e1, e2, e3]
fail "#{klass}: #{testbed.event_log.inspect}"
end
end
classes = [
HardcodeTestbed,
SendTestbed,
SendTableTestbed,
BindTableTestbed,
CodeGenTestbed,
IfCodeGenTestbed,
]
width = classes.map(&:name).map(&:size).max
require "benchmark/ips"
Benchmark.ips do |x|
classes.each do |klass|
x.report(klass.name) do
do_test(klass)
end
end
end
And that's it. Let's run this code.
The first thing we see is a rehearsal round. The IPS in Benchmark-IPS stands for "iterations per second". At this point, the gem is doing some dry runs to calculate how many repetitions will be needed to get an accurate iterations per second count.
Then it starts benchmarking for real.
$ ruby bench2.rb
Calculating -------------------------------------
HardcodeTestbed 36.851k i/100ms
SendTestbed 19.509k i/100ms
SendTableTestbed 29.388k i/100ms
BindTableTestbed 20.717k i/100ms
CodeGenTestbed 39.082k i/100ms
IfCodeGenTestbed 35.313k i/100ms
-------------------------------------------------
HardcodeTestbed 599.624k (± 1.9%) i/s - 3.022M
SendTestbed 263.969k (± 4.2%) i/s - 1.327M
SendTableTestbed 409.964k (± 2.5%) i/s - 2.057M
BindTableTestbed 242.405k (± 7.4%) i/s - 1.222M
CodeGenTestbed 575.384k (± 5.3%) i/s - 2.892M
IfCodeGenTestbed 493.219k (± 5.1%) i/s - 2.472M
First off, we can see that the results are nicely aligned without any assistance from us. Each line has a few different columns. The first column is the most important: it's the number of iterations per second the code being tested was able to complete. The higher the number, the faster the code.
Next up is the percent of standard deviation that the times exhibited. This tells us how variable each iteration was compared to others. These numbers are fairly low, meaning that the repetitions were pretty consistent, and don't have outliers skewing the results.
At the end of the line, we see the total number of iterations Benchmark-IPS actually ran in order to get its iterations-per-second average.
We've already seen a number of ways that this gem improves on the baseline Benchmark library. But Benchmark-IPS has one more trick up its sleeve.
We can send another message call on the reporter object, the #compare! message.
Event = Struct.new(:name, :source, :args)
class TestBed
attr_reader :event_log
def initialize
@event_log = []
end
end
class HardcodeTestbed < TestBed
def call(event)
case event.name
when :foo
handle_foo(event)
when :bar
handle_bar(event)
when :baz
handle_baz(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTestbed < TestBed
def call(event)
handler_name = "handle_#{event.name}"
__send__(handler_name, event) if respond_to?(handler_name)
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class SendTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = method_name.to_sym
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
__send__(handler_method, event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class BindTableTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods[$1.to_sym] = instance_method(method_name)
end
super
end
def self.handler_methods
@handler_methods ||= {}
end
def call(event)
if (handler_method = self.class.handler_methods[event.name])
handler_method.bind(self).call(event)
end
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class CodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"when :#{event_name} then handle_#{event_name}(event)"
}.join("\n")
class_eval %{
def call(event)
case event.name
#{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
class IfCodeGenTestbed < TestBed
def self.method_added(method_name)
if method_name.to_s =~ /\Ahandle_(.+)\z/
handler_methods << $1
regenerate_dispatch_method
end
super
end
def self.handler_methods
@handler_methods ||= []
end
def self.regenerate_dispatch_method
dispatch_table = handler_methods.map { |event_name|
"event.name.equal?(:#{event_name}) then handle_#{event_name}(event)"
}.join("\nelsif ")
class_eval %{
def call(event)
if #{dispatch_table}
end
end
}
end
def handle_foo(event)
event_log << event
end
def handle_bar(event)
event_log << event
end
def handle_baz(event)
event_log << event
end
end
def do_test(klass)
testbed = klass.new
testbed.call(e1 = Event[:foo])
testbed.call(e2 = Event[:bar])
testbed.call(e3 = Event[:baz])
testbed.call(Event[:buz])
unless testbed.event_log == [e1, e2, e3]
fail "#{klass}: #{testbed.event_log.inspect}"
end
end
classes = [
HardcodeTestbed,
SendTestbed,
SendTableTestbed,
BindTableTestbed,
CodeGenTestbed,
IfCodeGenTestbed,
]
width = classes.map(&:name).map(&:size).max
require "benchmark/ips"
Benchmark.ips do |x|
classes.each do |klass|
x.report(klass.name) do
do_test(klass)
end
end
x.compare!
end
When we run the benchmark again, we see a new section in the output.
$ ruby bench3.rb
Calculating -------------------------------------
HardcodeTestbed 38.468k i/100ms
SendTestbed 20.666k i/100ms
SendTableTestbed 29.470k i/100ms
BindTableTestbed 22.667k i/100ms
CodeGenTestbed 39.616k i/100ms
IfCodeGenTestbed 38.571k i/100ms
-------------------------------------------------
HardcodeTestbed 576.640k (± 1.3%) i/s - 2.885M
SendTestbed 268.347k (± 1.3%) i/s - 1.343M
SendTableTestbed 412.413k (± 1.0%) i/s - 2.063M
BindTableTestbed 224.491k (±26.8%) i/s - 1.020M
CodeGenTestbed 459.260k (±15.1%) i/s - 2.258M
IfCodeGenTestbed 501.894k (± 9.4%) i/s - 2.507M
Comparison:
HardcodeTestbed: 576640.3 i/s
IfCodeGenTestbed: 501894.0 i/s - 1.15x slower
CodeGenTestbed: 459260.2 i/s - 1.26x slower
SendTableTestbed: 412412.6 i/s - 1.40x slower
SendTestbed: 268347.3 i/s - 2.15x slower
BindTableTestbed: 224491.1 i/s - 2.57x slower
The comparison section helpfully sorts the results from fastest to slowest. And for each one, it tells us exactly what percentage slower than the first it is. We no longer have to do any math ourselves in order to see exactly how big a speed-up a given optimization buys us.
Now, there is one thing missing in these results, that we had in the baseline Benchmark results. We can no longer see a breakdown of system, user, and wallclock time. So Benchmark-IPS is not a total replacement for the standard benchmark methods.
But for many benchmarking purposes, it's exactly what we need, and it does all the busywork for us. When comparing approaches for their performance, Benchmark-IPS is a great tool to keep in our back pockets.
And that's it for today. Happy hacking!
Responses