Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

Date#mon is slow #2838

Open
kwleland opened this Issue · 10 comments

4 participants

@kwleland

Date#mon is 20 times slower in rubinius 2.2.1 than mri 2.1.0

This seems to be the main reason that bm_cal.rb is 7 times slower in rubinius than mri.

test code: ( date is diddled to avoid apparent memoization)

require 'date'

fi = Date.new(1926,6,1)

800_000.times do |i|
  (fi + i%2).mon
end

Semi-Fancy ips style benchmark exercising mon and other accessors to follow in forthcoming PR.

@chuckremes
Collaborator

Here are my results using your new benchmark against rbx (master), jruby (latest release) and ruby 2.0 (latest release).

Charless-Mac-Pro:rubinius cremes$ bin/benchmark -trbx -t"jruby --server" -truby2 benchmark/core/date/bench_mon.rb 
=== bin/rbx ===
           Date#mon     82672.9 (±8.2%) i/s -     411336 in   5.017058s (cycle=3546)
           Date#year    82098.8 (±7.4%) i/s -     412224 in   5.056593s (cycle=7232)
=== jruby --server ===
           Date#mon    743979.4 (±32.7%) i/s -    2144233 in   4.998000s (cycle=23563)
           Date#year   837522.5 (±30.8%) i/s -    2528367 in   5.208000s (cycle=36643)
=== ruby2 ===
           Date#mon   1853716.1 (±9.0%) i/s -    9147264 in   4.999639s (cycle=54448)
           Date#year  1927674.4 (±4.1%) i/s -    9648995 in   5.014195s (cycle=53905)

Comparing benchmark/core/date/bench_mon.rb:Date#year:
         ruby2:    1927674 i/s
jruby --server:     837522 i/s - 2.30x slower
       bin/rbx:      82098 i/s - 23.48x slower
Comparing benchmark/core/date/bench_mon.rb:Date#mon :
         ruby2:    1853716 i/s
jruby --server:     743979 i/s - 2.49x slower
       bin/rbx:      82672 i/s - 22.42x slower

Definitely room for improvement! Thanks for contributing the benchmark.

@chuckremes
Collaborator

I did a little bit of digging on this issue. I don't think the benchmark is measuring what you think it is measuring. The #mon and #year methods are a bit slower in rbx than in the other runtimes, but not 20x slower.

I got a little suspicious that Date#+ might be slow. So, I created another bench to test it. That didn't yield the results I expected, so then I suspected that Math#% might be slow. I did another bench to try that out. Etc, etc.

Ultimately, I think the problem is that Date#new is slow. It is 16x slower in rbx than the other runtimes. Every time you take a Date obj and add 1 or 0 to it (via (i%2)) it is creating a new Date object. I believe that is where the difference is coming from.

Here's a gist that contains the other benches that I used to tease this out.

https://gist.github.com/chuckremes/8029858

I recommend being very careful about benchmarking. You need to be sure that you are actually testing the right behavior. In your case the benchmark is really about how fast each runtime can create a new Date object.

I suggest revising this benchmark so that it just tests #mon and/or #year. Create a separate benchmark to measure object creation. Do a third one that measures math operations on dates (+, -), etc.

@kwleland

If your theory is correct why does removing the .mon make things go 5 times faster?

Wouldn't you still have the object creation if you were incrementing? This is a tricky one.

I started with 125 lines of bm_cal.rb code and got it down to 5 lines where i had to keep the +changing i and the
.mon both in order to get the slowness without calling something different than the original problem code.

I'm also worried that just calling .mon over and over on the same date is being beat by memoization and not doing any work. I don't mind doing more work on related benchmarks but I don't want to lose the problem exposed by
bm_cal.rb when I do it.

@kwleland

Further data; I have code in b10.rb that has 2 timed blocks.
The first sets up an array of dates. The second mons them.
The array stuff is lightening fast and not material.
Of course .new's are slow but that wasn't the issue in cal.rb,
at least not by explicitly calling .new.
Note how slow the flippin mons are when the objects are already
made.

b10.rb:
require 'date'

fi = Date.new(1926,6,1)
a = []

t1 = Time.now
500_000.times do |i|
a[i] = Date.new(1926,6,1)
end
t2 = Time.now
puts (t2-t1).to_s

500_000.times do |i|
a[i].mon
end
t3 = Time.now
puts (t3-t2).to_s

admin2:ruby kwleland$ rvm use rubinius
Using /Users/kwleland/.rvm/gems/rbx-2.2.1
admin2:ruby kwleland$ ruby b10.rb

10.030382

9.128123 ouch!

admin2:ruby kwleland$ rvm use 2.1.0
Using /Users/kwleland/.rvm/gems/ruby-2.1.0-preview1
admin2:ruby kwleland$ ruby b10.rb

0.436378
0.068538 whee!

@chuckremes
Collaborator

The Date class is really screwed up. After more research, I think my theory holds up.

Note that Date.new is an alias to Date.civil (class method). Further, note that there is a class method #new!() that is used internally to create new Date objects. The Date.civil class method does some validation and transformation before then calling self.class.new! on the results.

Methods such as #+() end up calling the (faster) self.class.new! method internally which bypasses all of the checks and transformations that Date.new performs. Therefore, Date#+ will be faster at allocating a new Date object than calling Date.new(*args).

I really recommend taking a look at the guts of date.rb. It is scary.

It is not at all surprising that calling Date#mon is slower than just calling Date.new. It is doing a lot of work to transform a Julian date into the year/month/day that we expect. In my profiling, I have seen Rational show up as a potential bottleneck; it is doing a lot of floating point work in Ruby. I may be wrong about this, but I have a vague memory that says MRI does all of its Rational work in C which could explain some of that performance difference.

Anyway, this requires more digging. The benchmarks right now aren't quite right. The benchmark is creating a lot of new Date objects and then doing some complex floating point work on them. I wouldn't worry about memoization (rbx doesn't memoize) so the benchmark should be made simpler to eliminate unnecessary object allocations.

@dbussink
Owner

So the problem with Date is that it's a copy from Date I think from Ruby 1.9 (or perhaps 1.8). In MRI they didn't fix Date, but basically rewrote it as a C extension which is why the performance profile is so very different.

We would have to think about whether we'd want to import the MRI C extension version or put time into improving the Ruby one.

@chuckremes
Collaborator

We should probably improve the Ruby one. This is partly why @brixen split all of these things out to gems, right? We can clean up the Date classes or at least make the Ruby a little easier to understand.

@kwleland

Dumb question: If we need to go C shouldn't it be FFI rather than c-extension?

@chuckremes
Collaborator

FFI would be preferred versus C-ext API. However, better Ruby would be best of all.

@headius

FWIW, the JRuby numbers are considerably different when not run through bin/benchmark:

system ~/projects/jruby $ rvm ruby-2.1 do ruby ../rubinius/benchmark/core/date/bench_mon.rb 
Calculating -------------------------------------
           Date#mon      69545 i/100ms
           Date#year     70778 i/100ms
-------------------------------------------------
           Date#mon   2390364.9 (±5.4%) i/s -   11961740 in   5.021560s
           Date#year  2389114.5 (±4.9%) i/s -   11961482 in   5.021124s

system ~/projects/jruby $ jruby ../rubinius/benchmark/core/date/bench_mon.rb 
Calculating -------------------------------------
           Date#mon      54204 i/100ms
           Date#year     68645 i/100ms
-------------------------------------------------
           Date#mon   1720136.9 (±8.6%) i/s -    8510028 in   5.024000s
           Date#year  1778752.7 (±5.5%) i/s -    8855205 in   4.995000s

system ~/projects/jruby $ ../rubinius/bin/rbx ../rubinius/benchmark/core/date/bench_mon.rb 
Calculating -------------------------------------
           Date#mon       6085 i/100ms
           Date#year     10784 i/100ms
-------------------------------------------------
           Date#mon    125862.5 (±4.7%) i/s -     632840 in   5.040579s
           Date#year   128078.5 (±3.4%) i/s -     647040 in   5.058045s

JRuby's date logic as of 1.7.5 is a hybrid of Ruby code and a JVM-based date library.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.