Ruby Inline over two times slower under 1.9 than under 1.8?

[Shot (Piotr Szotkowski)]

I’m starting to dip my toes in non-Ruby coding (for performance reasons)
and began with looking at the (simplest) choice of Ruby Inline.

Interestingly, while my own number-crunching code seems to be generally
three times faster in Ruby 1.9 than in Ruby 1.8, the attached script
– a slightly altered Corey Hoffstein’s example¹ – seems to be actually
running its Ruby part slightly slower under Ruby 1.9, and over two times
slower when it comes to its C part:

$ ruby -v sort.rb; ruby sort.rb; ruby sort.rb
ruby 1.8.7 (2009-09-11 patchlevel 202) [x86_64-linux]
Ruby Time: 68.987515
Inline Time: 7.591179
Ruby Time: 67.758257
Inline Time: 7.371522
Ruby Time: 68.420539
Inline Time: 7.361452

$ ruby -v sort.rb; ruby sort.rb; ruby sort.rb
ruby 1.9.1p243 (2009-07-16) [x86_64-linux]
Ruby Time: 80.945370503
Inline Time: 17.813790662
Ruby Time: 75.493231541
Inline Time: 16.430632733
Ruby Time: 74.406748965
Inline Time: 17.018331102

What could be the culprit of this speed difference?

(Note that the C part is using the C++ Boost library – but I doubt this
matters much, as the code is the same in both cases, and the resulting
.so file seems to be interchaneable between the two Ruby versions.)

¹ http://coreyhoffstein.com/2009/06/16/sorting-with-ruby-rubyinline-and-thrust/

— Shot
--
ruby.about.com thinks ‘trollop’ is an inappropriate
name for a gem? Wait till they meet me in person.
                                   [William Morgan]

[Ryan Davis-2]

On Nov 3, 2009, at 04:46 , Shot (Piotr Szotkowski) wrote:

> I’m starting to dip my toes in non-Ruby coding (for performance  
> reasons)
> and began with looking at the (simplest) choice of Ruby Inline.
>
> Interestingly, while my own number-crunching code seems to be  
> generally
> three times faster in Ruby 1.9 than in Ruby 1.8, the attached script
> – a slightly altered Corey Hoffstein’s example¹ – seems to be actually
> running its Ruby part slightly slower under Ruby 1.9, and over two  
> times
> slower when it comes to its C part:

I'm not seeing that in a simpler case (factorial in example.rb from  
RubyInline). So maybe it is less method dispatch time and more ruby  
internals manipulation time?

505 % multiruby example.rb

VERSION = 1.8.6-p368
CMD     = ~/.multiruby/install/1.8.6-p368/bin/ruby example.rb

# of iterations = 1000000, n = 5
                           user     system      total        real
null_time             0.110000   0.000000   0.110000 (  0.111362)
c                     0.780000   0.010000   0.790000 (  0.798776)
c-raw                 0.820000   0.000000   0.820000 (  0.824597)
c-alias               0.810000   0.000000   0.810000 (  0.826391)
pure ruby             3.120000   0.000000   3.120000 (  3.121989)

RESULT = 0

VERSION = 1.8.7-p72
CMD     = ~/.multiruby/install/1.8.7-p72/bin/ruby example.rb

# of iterations = 1000000, n = 5
                           user     system      total        real
null_time             0.140000   0.000000   0.140000 (  0.141250)
c                     0.890000   0.000000   0.890000 (  0.897377)
c-raw                 0.950000   0.010000   0.960000 (  0.975901)
c-alias               0.990000   0.000000   0.990000 (  1.033289)
pure ruby             3.260000   0.020000   3.280000 (  3.331565)

RESULT = 0

VERSION = 1.8.7-p160
CMD     = ~/.multiruby/install/1.8.7-p160/bin/ruby example.rb

# of iterations = 1000000, n = 5
                           user     system      total        real
null_time             0.120000   0.000000   0.120000 (  0.119509)
c                     0.870000   0.000000   0.870000 (  0.881604)
c-raw                 0.870000   0.000000   0.870000 (  0.876080)
c-alias               0.900000   0.010000   0.910000 (  0.921587)
pure ruby             3.330000   0.010000   3.340000 (  3.357289)

RESULT = 0

VERSION = 1.8.7-p174
CMD     = ~/.multiruby/install/1.8.7-p174/bin/ruby example.rb

# of iterations = 1000000, n = 5
                           user     system      total        real
null_time             0.120000   0.000000   0.120000 (  0.125070)
c                     0.950000   0.000000   0.950000 (  0.959735)
c-raw                 0.860000   0.000000   0.860000 (  0.868117)
c-alias               0.990000   0.010000   1.000000 (  1.004241)
pure ruby             3.550000   0.010000   3.560000 (  3.589039)

RESULT = 0

VERSION = 1.9.1-p129
CMD     = ~/.multiruby/install/1.9.1-p129/bin/ruby example.rb

# of iterations = 1000000, n = 5
                           user     system      total        real
null_time             0.150000   0.000000   0.150000 (  0.148261)
c                     0.350000   0.010000   0.360000 (  0.365500)
c-raw                 0.350000   0.000000   0.350000 (  0.356689)
c-alias               0.350000   0.000000   0.350000 (  0.352744)
pure ruby             1.090000   0.010000   1.100000 (  1.133433)

RESULT = 0

TOTAL RESULT = 0 failures out of 5

Passed: 1.9.1-p129, 1.8.7-p72, 1.8.7-p160, 1.8.6-p368, 1.8.7-p174
Failed:

[Shot (Piotr Szotkowski)]

Ryan Davis:

> On Nov 3, 2009, at 04:46 , Shot (Piotr Szotkowski) wrote:

>> I’m starting to dip my toes in non-Ruby coding (for performance
>> reasons) and began with looking at the (simplest) choice of Ruby
>> Inline.

>> Interestingly, while my own number-crunching code seems to be
>> generally three times faster in Ruby 1.9 than in Ruby 1.8, the
>> attached script – a slightly altered Corey Hoffstein’s example¹
>> – seems to be actually running its Ruby part slightly slower under
>> Ruby 1.9, and over two  times slower when it comes to its C part:

> I'm not seeing that in a simpler case (factorial in example.rb from
> RubyInline). So maybe it is less method dispatch time and more ruby
> internals manipulation time?

Hm, you might be quite right, as I’m seeing almost exactly the
below results with my 1.8.7-p202+r22308 and 1.9.1-p243+r22308:

> VERSION = 1.8.7-p160
> CMD     = ~/.multiruby/install/1.8.7-p160/bin/ruby example.rb

> # of iterations = 1000000, n = 5
>                           user     system      total        real
> null_time             0.120000   0.000000   0.120000 (  0.119509)
> c                     0.870000   0.000000   0.870000 (  0.881604)
> c-raw                 0.870000   0.000000   0.870000 (  0.876080)
> c-alias               0.900000   0.010000   0.910000 (  0.921587)
> pure ruby             3.330000   0.010000   3.340000 (  3.357289)

> VERSION = 1.9.1-p129
> CMD     = ~/.multiruby/install/1.9.1-p129/bin/ruby example.rb

> # of iterations = 1000000, n = 5
>                           user     system      total        real
> null_time             0.150000   0.000000   0.150000 (  0.148261)
> c                     0.350000   0.010000   0.360000 (  0.365500)
> c-raw                 0.350000   0.000000   0.350000 (  0.356689)
> c-alias               0.350000   0.000000   0.350000 (  0.352744)
> pure ruby             1.090000   0.010000   1.100000 (  1.133433)

ruby 1.8.7 (2009-09-11 patchlevel 202) [x86_64-linux]
# of iterations = 1000000, n = 5
                          user     system      total        real
null_time             0.120000   0.000000   0.120000 (  0.115550)
c                     0.800000   0.000000   0.800000 (  0.805067)
c-raw                 0.820000   0.000000   0.820000 (  0.818312)
c-alias               0.820000   0.000000   0.820000 (  0.821886)
pure ruby             3.040000   0.010000   3.050000 (  3.044264)

ruby 1.9.1p243 (2009-07-16) [x86_64-linux]
# of iterations = 1000000, n = 5
                          user     system      total        real
null_time             0.120000   0.000000   0.120000 (  0.120553)
c                     0.330000   0.000000   0.330000 (  0.335894)
c-raw                 0.330000   0.000000   0.330000 (  0.322273)
c-alias               0.320000   0.000000   0.320000 (  0.324713)
pure ruby             1.110000   0.000000   1.110000 (  1.108753)
# of iterations = 1000000, n = 5

I guess the lesson here is to benchmark my actual code (rather than
arbitrary examples) and see what differences I’ll find there. :)

BTW: http://zenspider.com/ZSS/Products/RubyInline/ mentions running
‘make bench’ to benchmark RubyInline (which doesn’t work for me) and
http://zenspider.com/ZSS/Products/Download.html is a bit behind with
the ‘Current Version’ info.

— Shot, who’s off to play with RubyToC now. :)
--
C++ (from Bjarne Stroustrup, a compatriot of DHH, and who at the time
was at Bell/ATT Labs) is like Häagen Dazs Ice Cream; you think it’s from
Scandanavia, but it’s really an industrial product from New Jersey.
[Rick DeNatale on classification of languages by geographic origin, ruby-talk]

[rogerdpack]

> — Shot, who’s off to play with RubyToC now. :)

Shameless plug: Also checkout http://github.com/rdp/crystalizer
:)
-r
--
Posted via http://www.ruby-forum.com/.

[Shot (Piotr Szotkowski)]

Roger Pack:

>> — Shot, who’s off to play with RubyToC now. :)

…and who can’t, for some reason, get the canonical example
from http://zenspider.com/ZSS/Products/RubyInline/ to work.

First, it couldn’t find Inline::Ruby::RubyToC, then some grepping
told me ‘RubyToC is dead, use RubyToAnsiC’, but when I required
ruby_to_ansi_c and switched the RubyToC.translate call to
RubyToAnsiC.translate I get the following:

/home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/RubyToC-1.0.0.5/lib/type_checker.rb:129:in `bootstrap': undefined method `add' for #<SexpProcessor::Environment:0x7f15a2e303c8 @env=[{}]> (NoMethodError)



> Shameless plug: Also checkout http://github.com/rdp/crystalizer

Checked it and it does seem to work under my hand-compiled
1.8.7-p202+r22308, but an attempt to install it under
1.9.1-p243+r22308 first ended in it trying to look for
/home/shot/opt/ruby-1.9.1-p243/include/ruby-1.9.1/node.h
(while node.h is in /home/shot/opt/ruby-1.9.1-p243 and
/home/shot/opt/ruby-1.9.1-p243/include/ruby-1.9.1/ruby-1.9.1-p243)
and once I symlinked one of them to the required location I get



$ RUBY_SOURCE_DIR=/home/shot/opt/ruby.git gem install crystalizer
Building native extensions.  This could take a while...
ERROR:  Error installing crystalizer:
        ERROR: Failed to build gem native extension.

/home/shot/opt/ruby-1.9.1-p243/bin/ruby extconf.rb install crystalizer error: undefined method `each' for #<String:0x000000019a3d00>

Gem files will remain installed in /home/shot/opt/ruby-1.9.1-p243/lib/ruby/gems/1.9.1/gems/rubynode-0.1.5 for inspection.
Results logged to /home/shot/opt/ruby-1.9.1-p243/lib/ruby/gems/1.9.1/gems/rubynode-0.1.5/ext/rubynode_ext/gem_make.out



I have the v1_9_1_243 tag checked out in the /home/shot/opt/ruby.git
repo, so it should work; also, irb says this Ruby version does have
String#each…

— Shot
--
IMO, the primary historical significance of Unix is that it marks
the time in computer history where CPUs became so cheap that it was
possible to build an operating system without adult supervision.
                                               [Russ Holsclaw, afc]

[rogerdpack]

Shot (Piotr Szotkowski) wrote:
> Roger Pack:
>
>>> — Shot, who’s off to play with RubyToC now. :)
>
> …and who can’t, for some reason, get the canonical example
> from http://zenspider.com/ZSS/Products/RubyInline/ to work.

here's a working example (well worked once upon a time).

http://betterlogic.com/roger/?p=1849

The disadvantage to ruby2c seems to be that it only works for methods
that "appear" to take floats and int [?]


> Checked it and it does seem to work under my hand-compiled
> 1.8.7-p202+r22308, but an attempt to install it under
> 1.9.1-p243+r22308 first ended in it trying to look for

Wow you're the first to ever even try it out besides myself.  Yeah not
1.9 compat yet [sorry].
-r
--
Posted via http://www.ruby-forum.com/.

[Caleb Clausen]

On 11/12/09, Roger Pack <rogerpack2005@...> wrote:
> Wow you're the first to ever even try it out besides myself.  Yeah not
> 1.9 compat yet [sorry].

Yet? Are you planning to release a 1.9-compatible version of
crystalizer? I had thought it was hopeless, since you're dependant on
2 libraries which won't ever be ported to 1.9...

[rogerdpack]

> Yet? Are you planning to release a 1.9-compatible version of
> crystalizer? I had thought it was hopeless, since you're dependant on
> 2 libraries which won't ever be ported to 1.9...

It's actually pretty high on the "to do" list, though who knows if I'll
ever get there.
I'll probably just use #source_location to extract the source and call
out to 1.8.6 to return me its ruby node (and cache the result, thus
fewer call outs necessary over time).

The hard part is actually getting the C code to compile in 1.9--that
could take awhile and is unfamiliar territory.

-r
--
Posted via http://www.ruby-forum.com/.

[Shot (Piotr Szotkowski)]

First, thanks a lot to you and Ryan Davis for all your great help!
I feel really ungrateful, using your work and not being able to repay
you in any way, only coming up with problems instead. I hope some day
to be much more on the giving end of the community.

Roger Pack:

> Shot (Piotr Szotkowski) wrote:

>> …and who can’t, for some reason, get the canonical example
>> from http://zenspider.com/ZSS/Products/RubyInline/ to work.

> here's a working example (well worked once upon a time).
> http://betterlogic.com/roger/?p=1849

$ gem which ruby_to_ruby_c
(checking gem RubyToC-1.0.0.5 for ruby_to_ruby_c)
/home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/RubyToC-1.0.0.5/lib/ruby_to_ruby_c.rb

Fortunately, I noticed the 1.0.0.5 version not
matching 1.0.0.7 in the example and cd-ed to
/home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby2c-1.0.0.7
instead. Still, with RubyToC being higher on the gem searchpath (?):

>> RubyParser.new.parse(File.read 'hello.rb')
NoMethodError: undefined method `clear' for nil:NilClass
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-2.0.4/lib/ruby_parser_extras.rb:938:in `reset'
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-2.0.4/lib/ruby_parser_extras.rb:766:in `reset'
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-2.0.4/lib/ruby_parser_extras.rb:345:in `initialize'
  from (irb):5:in `new'
  from (irb):5

After uninstalling RubyToC (and, I assume, ruby_parser falling back
to ruby2c) the above blog example works, both in 1.8.7-p202+r22308
and 1.9.1-p243+r22308. Is there a ‘conflicts’ flag for gems, so that
ruby_parser can specify that it (as far as I understand) works with
ruby2c 1.0.0.7 but not with RubyToC 1.0.0.5?

> The disadvantage to ruby2c seems to be that it only works
> for methods that "appear" to take floats and int [?]

I haven’t yet checked this, but I’ll check and report once/if I end
up going down this road. After experimenting a bit with all these
nice automagic approaches I think I’ll end up with either a good old
D extension or hand-coded inline C, as I’d really prefer something that
‘just works’ in 1.9 MRI (and JRuby is not there yet with 1.9 support,
unfortunately – although I’ll give it one more chance). :)

>> Checked it and it does seem to work under my hand-compiled
>> 1.8.7-p202+r22308, but an attempt to install it under
>> 1.9.1-p243+r22308 first ended in it trying to look for

> Wow you're the first to ever even try it out
> besides myself. Yeah not 1.9 compat yet [sorry].

Ah, ok. The readme does say ‘note: not 1.9 compat’, but I misread
http://github.com/rdp/crystalizer/blob/master/results as sporting
1.9 results *with* Crystalizer, so naïvely thought that maybe the
README is outdated. :)

— Shot
--
I don’t suffer from insanity; I enjoy every minute of it.
                                   [Lieven Marchand, asr]

[rogerdpack]

>> here's a working example (well worked once upon a time).
>> http://betterlogic.com/roger/?p=1849
>
> $ gem which ruby_to_ruby_c
> (checking gem RubyToC-1.0.0.5 for ruby_to_ruby_c)
> /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/RubyToC-1.0.0.5/lib/ruby_to_ruby_c.rb
>
> Fortunately, I noticed the 1.0.0.5 version not
> matching 1.0.0.7 in the example and cd-ed to
> /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby2c-1.0.0.7
> instead. Still, with RubyToC being higher on the gem searchpath (?):
>
>>> RubyParser.new.parse(File.read 'hello.rb')
> NoMethodError: undefined method `clear' for nil:NilClass

Hmm. Maybe a bug in ruby parser?


> After uninstalling RubyToC (and, I assume, ruby_parser falling back
> to ruby2c) the above blog example works, both in 1.8.7-p202+r22308
> and 1.9.1-p243+r22308. Is there a ‘conflicts’ flag for gems, so that
> ruby_parser can specify that it (as far as I understand) works with
> ruby2c 1.0.0.7 but not with RubyToC 1.0.0.5?

So RubyToC 1.0.0.5 only works with an older version of ruby_parser, is
that right?
-r
--
Posted via http://www.ruby-forum.com/.

[Shot (Piotr Szotkowski)]

Roger Pack:

>>> here's a working example (well worked once upon a time).
>>> http://betterlogic.com/roger/?p=1849

>>>> RubyParser.new.parse(File.read 'hello.rb')
>> NoMethodError: undefined method `clear' for nil:NilClass

> Hmm. Maybe a bug in ruby parser?

Argh, sorry, I mis-pasted. The problem is with RubyToRubyC#process.

With just ruby2c 1.0.0.7:

>> RubyParser.new.parse(File.read 'hello.rb')
=> s(:class, :Hello, …
>> RubyToRubyC.new.process(RubyParser.new.parse(File.read 'hello.rb'))
=> "// class Hello < …

With also RubyToC 1.0.0.5:

>> RubyParser.new.parse(File.read 'hello.rb')
=> s(:class, :Hello, …
>> RubyToRubyC.new.process(RubyParser.new.parse(File.read 'hello.rb'))
NoMethodError: undefined method `clear' for nil:NilClass
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-2.0.4/lib/ruby_parser_extras.rb:938:in `reset'

Apparently, ‘require 'ruby_to_ruby_c'’ pulls in RubyToC’s
ruby_to_ruby_c.rb (rather than ruby2c’s – wich makes sense,
as R comes before r when sorting), and it’s the one that can’t
handle the same Sexp.

> So RubyToC 1.0.0.5 only works with an older
> version of ruby_parser, is that right?

I get the above with ruby_parser 2.0.0
as well. With ruby_parse 1.0.0 I get

>> RubyToAnsiC.new.process(RubyParser.new.parse(File.read 'hello.rb'))
NoMethodError: undefined method `[]' for nil:NilClass
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-1.0.0/lib/ruby_lexer.rb:2510:in `dynamic?'
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/gems/1.8/gems/ruby_parser-1.0.0/lib/ruby_lexer.rb:191:in `gettable'
  from lib/ruby_parser.y:1429:in `_reduce_426'
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/1.8/racc/parser.rb:331:in `__send__'
  from /home/shot/opt/ruby-1.8.7-svn/lib/ruby/1.8/racc/parser.rb:331:in `_racc_do_reduce'

(Note: I’m not that fluent yet with all the RubyToRubyC vs. RubyToAnsiC
details, so my reasoning might be very flawed above. Do let me know if
you want me to test anything specific; all I can say for sure is that
ruby2c 1.0.0.7 works with ruby_parser 2.0.4’s output.)

— Shot
--
Founding member of the Hyphenation Society, a grassroots-based,
not-for-profit, locally-owned-and-operated, cooperatively-managed,
modern-American-English-usage-improvement association.
                                                       [Rick Moen]

[Charles Oliver Nutter-4]

On Sat, Nov 14, 2009 at 8:27 AM, Shot (Piotr Szotkowski) <shot@...> wrote:
> I haven’t yet checked this, but I’ll check and report once/if I end
> up going down this road. After experimenting a bit with all these
> nice automagic approaches I think I’ll end up with either a good old
> D extension or hand-coded inline C, as I’d really prefer something that
> ‘just works’ in 1.9 MRI (and JRuby is not there yet with 1.9 support,
> unfortunately – although I’ll give it one more chance). :)

We've never said that 1.9 support is done, largely because it's hard
to say what "done" actually means with 1.9.2 adding and changing many
things. But if there's specific problems, please report them...we're
actively trying to improve it.

- Charlie

[Shot (Piotr Szotkowski)]

Charles Oliver Nutter:

> On Sat, Nov 14, 2009 at 8:27 AM, Shot (Piotr Szotkowski) <shot@...> wrote:

>> I haven’t yet checked this, but I’ll check and report once/if I end
>> up going down this road. After experimenting a bit with all these
>> nice automagic approaches I think I’ll end up with either a good old
>> D extension or hand-coded inline C, as I’d really prefer something that
>> ‘just works’ in 1.9 MRI (and JRuby is not there yet with 1.9 support,
>> unfortunately – although I’ll give it one more chance). :)

> We've never said that 1.9 support is done, largely because it's hard
> to say what "done" actually means with 1.9.2 adding and changing many
> things. But if there's specific problems, please report them...we're
> actively trying to improve it.

Yes, of course – and I am reporting them as soon as I can put my finger
on the exact code that causes the problem and turn it into an example.
I’m currently bitten by JRUBY-4098, as the crux of my architecture is
based on nested, lazy, block-initialised Enumerators; I’m also finally
slowly grasping what’s the problem behind implementing them in JRuby.

(I also understand why waiting for a RubySpec-green 1.9.2 makes
sense before fully committing to support 1.9 features in JRuby.)

Thanks for your work on JRuby – and for your time at RuPy!

— Shot
--
Not every country in Central Europe is a poor, small place
with bad roads, corrupt officials, a rackety Russian-built
nuclear-power plant and a squabbling coalition government.
                                           [The Economist]