Why is Ruby irb iteration so slow?
I was playing around with the Ruby Benchmark class on irb and I noticed that Ruby slowed down noticeably when repeated.
I did a simple test without using the Benchmark class or Profiler__ (I thought it might have slowed it down).
def average_test
total_time = 0
time = 0
TESTS.times do |count|
time = test
total_time = total_time + time
yield count, time
end
average = total_time / TESTS
yield 'average', average
end
def test
x = 0
start_time = Time.now
for i in 1..ITERATIONS
x = x + 1
end
end_time = Time.now
time = end_time - start_time
end
ITERATIONS = 10_000_000
TESTS = 20
# create results file
results = File.new('results.txt', 'w')
# start test
average_test {|count, time| results.print "Test #{count}: #{time}"}
results.close
Here are the results after running in irb. (in seconds, sorry)
Test 0: 2.390647, Test 1: 2.343761, Test 2: 2.312554, Test 3: 2.566792, Test 4: 2.665193, Test 5: 2.537908, Test 6: 2.643086, Test 7: 2.534492, Test 8: 2.589034, Test 9: 2.390633, Test 10: 2.539533, Test 11: 2.385508, Test 12: 2.49659, Test 13: 2.498958, Test 14 : 2.527309, test 15: 2.464583, test 16: 2.504546, test 17: 2.570159, test 18: 2.371447, test 19: 2.330072,
Test average: 2.48306025 (s), 2483 (ms)
I also did the same test in JavaScript, just to compare speeds.
function test() {
var start = Date.now();
var x = 0;
for (var i = 0; i < ITERATIONS; i++) {
x = x + 1;
}
var end = Date.now();
var dt = end - start;
return dt;
}
function averageTest() {
var total = 0;
for (var i = 0; i < TESTS; i++) {
var time = test();
total = total + time;
console.log('Test ' + i + ': ', time);
}
var avg = total / TESTS;
console.log('Average: ', avg);
return avg;
}
var ITERATIONS = 10000000;
var TESTS = 20;
// start test
var avgTime = averageTest(); // results
Below are the results for JavaScript code running in Chrome. (in milliseconds)
Test 0: 41, Test 1: 44, Test 2: 41, Test 3: 48, Test 4: 46, Test 5: 48, Test 6: 49, Test 7: 47, Test 8: 46, Test 9: 50, Test 10: 41, Test 11: 41, Test 12: 47, Test 13: 54, Test 14: 55, Test 15: 57, Test 16: 35, Test 17: 50, Test 18: 47, Test 19: 49,
Average: 46.8 (ms), 0.0468 (s)
Ruby averaged 2,483ms compared to JavaScript 46.8ms.
Why is there such a huge difference? Is it because Ruby statements are method calls and method calls are slow or something?
I feel like I'm doing something really wrong. Thank.
source to share
I've tried your benchmark with several different Ruby implementations and have had different results. This seems to confirm my suspicion that your benchmark does not measure what you think it does. As I mentioned in my comment above: when writing tests, you should always read the generated native machine code to make sure it actually measures what you think it does.
For example, the YARV test case has a benchmark that should measure the performance of sending messages, however on Rubinius, sending a message is fully optimized, so the only thing that really gets done is incrementing the counter variable for the reference loop. Basically, it tells you the frequency of your CPU, nothing more.
ruby 2.3.0dev (2015-08-08 trunk 51510) [x86_64-darwin14]
Here's the current YARV snapshot:
Test 0: 0.720945 Test 1: 0.733733 Test 2: 0.722778 Test 3: 0.734074 Test 4: 0.774355 Test 5: 0.773379 Test 6: 0.751547 Test 7: 0.708566 Test 8: 0.724959 Test 9: 0.730899 Test 10: 0.725978 Test 11: 0.712902 Test 12: 0.747069 Test 13: 0.737792 Test 14: 0.736885 Test 15: 0.751422 Test 16: 0.718943 Test 17: 0.760094 Test 18: 0.746343 Test 19: 0.764731 Average: 0.738870
As you can see, the performance is very consistent across all runs, and it seems to be in line with other results posted in the comments.
rubinius 2.5.8 (2.1.0 bef51ae3 2015-08-09 3.5.1 JI) [x86_64-darwin14.4.0]
Here's the current Rubinius version:
Test 0: 1.159465 Test 1: 1.063721 Test 2: 0.516513 Test 3: 0.515016 Test 4: 0.553987 Test 5: 0.544286 Test 6: 0.567737 Test 7: 0.563350 Test 8: 0.517581 Test 9: 0.501865 Test 10: 0.503399 Test 11: 0.512046 Test 12: 0.487296 Test 13: 0.533193 Test 14: 0.533217 Test 15: 0.511648 Test 16: 0.535847 Test 17: 0.490049 Test 18: 0.539681 Test 19: 0.551324 Average: 0.585061
As you can see, the compiler is started sometime during the second run, after which it gets twice as fast, significantly faster than YARV, whereas during the first two runs, it is significantly slower than YARV.
jruby 9.0.0.0-SNAPSHOT (2.2.2) 2015-07-23 89c1348 64-bit Java HotSpot (TM) Server 25.5-b02 on 1.8.0_05-b13 + jit [darwin-x86_64]
This is the current snapshot of JRuby running on a somewhat older version (a couple of months) of HotSpot:
Test 0: 1.169000 Test 1: 0.805000 Test 2: 0.772000 Test 3: 0.755000 Test 4: 0.777000 Test 5: 0.749000 Test 6: 0.751000 Test 7: 0.694000 Test 8: 0.696000 Test 9: 0.708000 Test 10: 0.691000 Test 11: 0.745000 Test 12: 0.752000 Test 13: 0.755000 Test 14: 0.707000 Test 15: 0.744000 Test 16: 0.674000 Test 17: 0.710000 Test 18: 0.733000 Test 19: 0.706000 Average: 0.754650
Again, the compiler seems to be removed somewhere between runs 1 and 2, after which it is compared against YARV.
jruby 9.0.1.0-SNAPSHOT (2.2.2) 2015-08-09 2939c73 64-bit OpenJDK VM server 25.40-b25-internal-graal-0.7 on 1.8.0-internal-b128 + jit [darwin -x86_64]
This is a slightly new snapshot of JRuby working on a future version of HotSpot:
Test 0: 0.815000 Test 1: 0.693000 Test 2: 0.634000 Test 3: 0.615000 Test 4: 0.599000 Test 5: 0.616000 Test 6: 0.623000 Test 7: 0.611000 Test 8: 0.604000 Test 9: 0.598000 Test 10: 0.628000 Test 11: 0.627000 Test 12: 0.601000 Test 13: 0.646000 Test 14: 0.675000 Test 15: 0.611000 Test 16: 0.684000 Test 17: 0.689000 Test 18: 0.626000 Test 19: 0.639000 Average: 0.641700
Again, we see its speed getting faster during the first two runs, after which it sits somewhere between a little faster than the YARV, and the other JRuby and a little slower than the Rubinius.
jruby 9.0.1.0-SNAPSHOT (2.2.2) 2015-08-09 2939c73 64-bit OpenJDK VM server 25.40-b25-internal-graal-0.7 on 1.8.0-internal-b128 + jit [darwin -x86_64]
This is my favorite: JRuby + Truffle Truffle enabled and running on a Graal-enabled JVM:
Test 0: 6.226000 Test 1: 5.696000 Test 2: 1.836000 Test 3: 0.057000 Test 4: 0.111000 Test 5: 0.103000 Test 6: 0.082000 Test 7: 0.146000 Test 8: 0.089000 Test 9: 0.077000 Test 10: 0.076000 Test 11: 0.082000 Test 12: 0.072000 Test 13: 0.104000 Test 14: 0.124000 Test 15: 0.084000 Test 16: 0.080000 Test 17: 0.118000 Test 18: 0.087000 Test 19: 0.070000 Average: 0.766000
The truffle seems to need a significant increase in time as the first three runs were terribly slow, but then it picks up speed sharply, leaving everything else 5-10 times dusty.
Note: This is not 100% true as JRuby + Truffle does not yet support the full Ruby language.
Also note, this shows that simply averaging over all runs is highly misleading, as JRuby + Truffle comes out in the same average state as YARV and JRuby, but actually has 7x more consistent performance. The difference between the slowest run (run 1 JRuby + Truffle) and the fastest run (run 20 also JRuby + Truffle) is 10,000 times.
Note # 3: Notice how all JRuby numbers end with 000
? This is because JRuby does not easily access the OS microsecond timer via the JVM and therefore should be happy with milliseconds. It doesn't really matter in this particular test, but for faster benchmarks, it can skew the results significantly. This is another thing that you should consider when designing your tests.
Why is there such a huge difference? Is it because Ruby statements - method calls and method calls are slow or something?
I do not think so. In YARV Fixnum#+
it is not even a method call, it is optimized for a static inline operator. It essentially performs the built-in operation of adding integers to a register in the CPU. As fast as it goes.
YARV comes back to be seen as a method call when you patch monkey Fixnum
.
Rubinius can probably optimize method biases, although I haven't tested.
I feel like I'm doing something really wrong.
Perhaps your test doesn't measure what you think. In particular, I believe that when implemented with complex optimizing compilers, the iteration portion of your iteration test can be optimized.
Actually, I noticed a significant difference between your JavaScript and Ruby criteria: in JavaScript you use a primitive loop for
, in Ruby you use Range#each
( for β¦ in
just translates to each
). If I switch both Ruby and JavaScript tests to an identical loop while
, I get the Ruby version: 223ms for YARV, 56ms for Rubinius, 28ms for JRuby, and 33ms for JRuby + Truffle. For JS version: 30ms for Squirrelfish Extreme / Nitro (Safari) and 16ms for V8 / Crankshaft (Chrome).
Or, in other words: if you measure the same thing, they end up equally fast ;-) (Well, except for YARV, which is known to be slow anyway.)
So, as it turns out, the difference between Ruby and JavaScript was that in JS you weren't repeating anything, you were just incrementing the number, whereas in Ruby you were actually repeating a data structure (namely a Range
). Remove iteration from Ruby and it runs as fast as JavaScript.
I created two test scripts that hopefully roughly measure the same thing:
#!/usr/bin/env ruby
ITERATIONS = 10_000_000
TESTS = 20
WARMUP = 3
TOTALRUNS = TESTS + WARMUP
RESULTS = []
run = -1
while (run += 1) < TOTALRUNS
i = -1
starttime = Time.now
while (i += 1) < ITERATIONS do end
endtime = Time.now
RESULTS[run] = (endtime - starttime) * 1000
end
puts RESULTS.drop(WARMUP).reduce(:+) / TESTS
"use strict";
const ITERATIONS = 10000000;
const TESTS = 20;
const WARMUP = 3;
const TOTALRUNS = TESTS + WARMUP;
const RESULTS = [];
let run = -1;
while (++run < TOTALRUNS) {
let i = -1;
const STARTTIME = Date.now();
while (++i < ITERATIONS);
const ENDTIME = Date.now();
RESULTS[run] = ENDTIME - STARTTIME;
}
alert(RESULTS.slice(WARMUP).reduce((acc, el) => acc + el) / TESTS);
You will notice that I have increased the number of iterations, I have doubled the number of test runs, and I have introduced a number of warm-up runs that are not included in the calculation of the result. I have also tried to make both snippets as similar as possible. (Note: you may need to remove some of the ES6isms in order to get it to run in your browser. For example, my version of Safari doesn't like thick arrow function literals.)
Results:
- Ruby
- YARV: 223.2498ms
- JRuby: 358.45ms
- Ruby: 477.49485ms
- JRuby + Truffle + Graal: 26.4ms
- JavaScript
- Nitro: 3827.3ms
- V8: 6839ms
I'm a little confused to be honest. Now Nitro is ahead of V8, all Ruby implementations are 10 times faster than JavaScript, JRuby + Truffle + Graal is again 10 times faster than the rest of Ruby, making it 100 times faster than JavaScript.
I guess it really tells us that the reference meaning is pointless: -D
source to share