bm_sprintf.rb

require 'benchmark'

total = (ENV['TOTAL'] || 1000000).to_i

Benchmark.bmbm do |x|
  x.report("'%d'") do
    total.times { sprintf('%d', 10) }
  end

  x.report("'Hello %s, from %4.2f'") do
    total.times { sprintf('Hello %s, from %4.2f', 'world', 123.4567) }
  end
end

bm_sprintf_cheat.rb

require 'benchmark'

total = (ENV['TOTAL'] || 1000000).to_i

Benchmark.bmbm do |x|
  x.report("'%d'") do
    s = ::Rubinius::Sprinter.create('%d')
    total.times { s.call(10) }
  end

  x.report("'Hello %s, from %4.2f'") do
    s = ::Rubinius::Sprinter.create('Hello %s, from %4.2f')
    total.times { s.call('world', 123.4567) }
  end
end

gistfile3.txt

# MRI 1.8
% ruby bm_sprintf.rb              
Rehearsal ----------------------------------------------------------
'%d'                     0.780000   0.020000   0.800000 (  0.811397)
'Hello %s, from %4.2f'   1.570000   0.060000   1.630000 (  1.629475)
------------------------------------------------- total: 2.430000sec

                             user     system      total        real
'%d'                     0.770000   0.010000   0.780000 (  0.771868)
'Hello %s, from %4.2f'   1.570000   0.020000   1.590000 (  1.604871)

# RBX with my sprintf compiler, caching in a hash
% rbx bm_sprintf.rb                       
Rehearsal ----------------------------------------------------------
'%d'                     1.528095   0.004000   1.532095 (  1.421881)
'Hello %s, from %4.2f'   2.540159   0.004000   2.544159 (  2.498720)
------------------------------------------------- total: 4.076254sec

                             user     system      total        real
'%d'                     1.156072   0.008001   1.164073 (  1.169444)
'Hello %s, from %4.2f'   2.376149   0.016001   2.392150 (  2.397916)

# RBX with my sprintf compiler, with the benchmark compiling once
% rbx bm_sprintf_cheat.rb
Rehearsal ----------------------------------------------------------
'%d'                     0.720045   0.004000   0.724045 (  0.670018)
'Hello %s, from %4.2f'   1.700106   0.008001   1.708107 (  1.660630)
------------------------------------------------- total: 2.432152sec

                             user     system      total        real
'%d'                     0.524033   0.004000   0.528033 (  0.529791)
'Hello %s, from %4.2f'   1.488093   0.000000   1.488093 (  1.490796)

# RBX current implementation
% rbx bm_sprintf.rb
Rehearsal ----------------------------------------------------------
'%d'                    29.909869   0.224014  30.133883 ( 29.637982)
'Hello %s, from %4.2f'  59.963748   0.460029  60.423777 ( 60.481506)
------------------------------------------------ total: 90.557660sec

                             user     system      total        real
'%d'                    25.157572   0.040003  25.197575 ( 25.267517)
'Hello %s, from %4.2f'  58.859678   0.188011  59.047689 ( 59.216080)

# RBX with my sprintf compiler, no cache, compiling every call
% rbx bm_sprintf.rb                       
Rehearsal ----------------------------------------------------------
'%d'                   144.261016   1.076067 145.337083 (144.530423)
'Hello %s, from %4.2f' 256.524032   1.928121 258.452153 (259.039166)
----------------------------------------------- total: 403.789236sec

                             user     system      total        real
'%d'                   143.880992   1.416088 145.297080 (145.752931)
'Hello %s, from %4.2f' 262.876429   1.616101 264.492530 (265.335026)