Details
-
Type:
Bug
-
Status:
Resolved
-
Priority:
Major
-
Resolution: Fixed
-
Affects Version/s: JRuby 1.6.1
-
Fix Version/s: JRuby 1.7.0.RC1
-
Component/s: Core Classes/Modules
-
Labels:None
-
Number of attachments :
Description
Initial invocation of 'Time.now' is slow. jodatime loading perhaps?
It's really slow especially on JRockit.
# With JRockit. See the 'total' of initial benchmark.
% JAVA_HOME=/home/nahi/java/jrockit-jdk1.6.0_24-R28.1.3-4.0.1 jruby -X-C -rbenchmark -e '3.times { Benchmark.bm { |x| x.report { sleep 1 }}}'
user system total real
1.768000 0.000000 1.768000 ( 1.039000)
^^^^^^^^ 1.768[sec] for 'sleep 1'.
user system total real
1.002000 0.000000 1.002000 ( 1.003000)
user system total real
1.002000 0.000000 1.002000 ( 1.002000)
# With JRockit + dummy Time.now call.
% JAVA_HOME=/home/nahi/java/jrockit-jdk1.6.0_24-R28.1.3-4.0.1 jruby -X-C -rbenchmark -e 'Time.now; 3.times { Benchmark.bm { |x| x.report { sleep 1 }}}'
user system total real
1.016000 0.000000 1.016000 ( 1.014000)
^^^^^^^^
user system total real
1.003000 0.000000 1.003000 ( 1.002000)
user system total real
1.001000 0.000000 1.001000 ( 1.001000)
# With Sun JDK.
% JAVA_HOME=/home/nahi/java/jdk1.6.0_25 jruby -X-C -rbenchmark -e '3.times { Benchmark.bm { |x| x.report { sleep 1 }}}'
user system total real
1.066000 0.000000 1.066000 ( 1.010000)
^^^^^^^^ a little slow on Sun JDK.
user system total real
1.001000 0.000000 1.001000 ( 1.001000)
user system total real
1.001000 0.000000 1.001000 ( 1.001000)
# With Sun JDK + dummy Time.now call.
% JAVA_HOME=/home/nahi/java/jdk1.6.0_25 jruby -X-C -rbenchmark -e 'Time.now; 3.times { Benchmark.bm { |x| x.report { sleep 1 }}}'
user system total real
1.001000 0.000000 1.001000 ( 1.002000)
^^^^^^^^
user system total real
1.001000 0.000000 1.001000 ( 1.001000)
user system total real
1.000000 0.000000 1.000000 ( 1.000000)
Here's 'measure' in benchmark.rb
def measure(label = "") # :yield:
t0, r0 = Benchmark.times, Time.now
yield
t1, r1 = Benchmark.times, Time.now
So measure calls Benchmark.times(calls Process.times) at first, then calls Time.now.
Initial 'Time.now' is considerably slow on JRockit so we see 0.7[sec] difference
between 'total' and 'real'. (0.05[sec] on Sun JDK.)
How do we fix this?
1. Load jodatime at startup. Startup time slows down.
2. Add dummy Time.now at benchmark.rb loading. Uglish...
I can't reproduce this at all on Hotspot, and JRockit is no more, so I think we will call this fixed for now.