Performance question

sorry for the cross-post from RoR, but I actually think this is more
of a ruby question.

I got sidetracked while benchmarking ruby factorial code:

I put all that code into test_fact.rb and ran with:

ruby test_fact.rb
rails runner test_fact.rb #from a fresh rails app
rails runner test_fact.rb #from a mature rails app

here are the respective results:

              user     system      total        real  # ruby

recursive: 8.660000 0.040000 8.700000 ( 8.888191)
iterative: 6.770000 0.030000 6.800000 ( 6.892491)
functional: 6.240000 0.030000 6.270000 ( 6.334801)

              user     system      total        real # rails_f

recursive: 10.140000 0.070000 10.210000 ( 10.760008)
iterative: 8.750000 0.050000 8.800000 ( 9.050677)
functional: 8.200000 0.040000 8.240000 ( 8.477966)

              user     system      total        real # rails_m

recursive: 17.400000 0.170000 17.570000 ( 17.792121)
iterative: 15.730000 0.140000 15.870000 ( 16.233311)
functional: 15.450000 0.160000 15.610000 ( 16.245557)

I profiled it as well and the function calls were identical, just
slower.

This feels like a ruby issue that rails brings out in spades, I’m
wondering if anyone here has some insight as to what’s going on.

  • kevin

On Jan 27, 2011, at 12:55 PM, klochner wrote:

rails runner test_fact.rb #from a mature rails app
iterative: 8.750000 0.050000 8.800000 ( 9.050677)
This feels like a ruby issue that rails brings out in spades, I’m
wondering if anyone here has some insight as to what’s going on.

Not every runtime we behave the same. You didn’t mention which Ruby
runtime you are using (MRI 1.8.x, MRI 1.9.x, JRuby 1.?, Rubinius, etc.).

No one can even start to answer your question without knowing the Ruby
you are using.

Secondly, the Ruby code examples you pointed to aren’t even necessarily
testing what you think they are. The “iterative” and “functional”
examples are probably a test of how fast the runtime can yield a block,
or iterate a range, or any number of things. I wouldn’t use that code to
extrapolate any larger meaning about runtime performance.

cr

On Jan 27, 11:37am, Chuck R. [email protected] wrote:

Not every runtime we behave the same. You didn’t mention which Ruby runtime you
are using

No one can even start to answer your question without knowing the Ruby you are
using.

Ruby Enterprise Edition - ruby 1.8.7 (2010-04-19 patchlevel 253)

Secondly, the Ruby code examples you pointed to aren’t even necessarily testing
what you think they are.

Ignoring the between-test comparisons, there is clearly a slowdown
after loading rails. My guess is that it has to do with the size of
ObjectSpace causing a slowdown in function lookup, but again, I was
hoping someone here would have a more concrete understanding.

On Fri, Jan 28, 2011 at 8:59 AM, Kirk H. [email protected] wrote:

are still the same for any 1.8.x. When a garbage collection cycle
starts, everything else stops. While it is running Ruby has to walk
through it’s heaps, examining everything that looks like an object
that it can find.

The more stuff that is in there, the longer this takes. If there is a
lot of stuff in there, the impact can be significant.

I totally agree with you Kirk…but…

I just want to add that not all Ruby GC impls are equal. While lots
of garbage will have an effect on any GC, some GC’s just do a better
job. JRuby GC times are generally a smaller percentage of execution
than the amount of time MRI spends collecting. JRuby also allows
parallel and concurrent collection (JVM allows a variety of plugable
GCs) which reduces GC pauses by pushing collection onto separate
processor cores. Even without using the parallel or concurrent
collectors the percentage pauses are much shorter mostly due to
generational collection.

-Tom

On Thu, Jan 27, 2011 at 1:10 PM, klochner [email protected] wrote:

Ignoring the between-test comparisons, there is clearly a slowdown
after loading rails. My guess is that it has to do with the size of
ObjectSpace causing a slowdown in function lookup, but again, I was
hoping someone here would have a more concrete understanding.

Garbage collection.

REE has some optimizations to how it manages GC, but the fundamentals
are still the same for any 1.8.x. When a garbage collection cycle
starts, everything else stops. While it is running Ruby has to walk
through it’s heaps, examining everything that looks like an object
that it can find.

The more stuff that is in there, the longer this takes. If there is a
lot of stuff in there, the impact can be significant.

You can readily see this yourself within an irb session.

irb(main):001:0> require ‘benchmark’
=> true
irb(main):002:0> junk = []
=> []
irb(main):003:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
0.780000 0.000000 0.780000 ( 0.977218)
=> true
irb(main):004:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
0.780000 0.000000 0.780000 ( 0.796975)
=> true
irb(main):005:0> 10000.times {|n| junk << n.to_s}
=> 10000
irb(main):006:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
1.120000 0.000000 1.120000 ( 1.266903)
=> true
irb(main):007:0> 20000.times {|n| junk << n.to_s}
=> 20000
irb(main):008:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
1.900000 0.020000 1.920000 ( 2.125608)
=> true
irb(main):009:0> 40000.times {|n| junk << n.to_s}
=> 40000
irb(main):010:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
2.360000 0.010000 2.370000 ( 2.441193)
=> true
irb(main):011:0> 1000000.times {|n| junk << n.to_s}
=> 1000000
irb(main):012:0> Benchmark.bm {|bm| bm.report {1000.times {GC.start}}}
user system total real
32.970000 0.250000 33.220000 ( 36.181590)
=> true

Kirk H.
Developer
Engine Y.

On Fri, Jan 28, 2011 at 10:17 AM, Thomas E Enebo [email protected]
wrote:

Sorry Kirk you were probably specifically talking about Ruby impls
based on MRI 1.8.x derived codebases and not in the more general
sense. My info may still be interesting to someone, but it was
specifically about JRuby and how it can handle GC’ing workloads.

Yeah, I should have worded it more specifically. I was talking about
MRI based 1.8.x’s. :slight_smile:

Kirk H.

On Jan 28, 9:27am, Kirk H. [email protected] wrote:

Kirk H.
Thanks a ton guys, this is all great info.

  • kevin

Sorry Kirk you were probably specifically talking about Ruby impls
based on MRI 1.8.x derived codebases and not in the more general
sense. My info may still be interesting to someone, but it was
specifically about JRuby and how it can handle GC’ing workloads.

-Tom