Details

    • Number of attachments :
      0

      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...

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        I can't reproduce this at all on Hotspot, and JRockit is no more, so I think we will call this fixed for now.

        Show
        Charles Oliver Nutter added a comment - I can't reproduce this at all on Hotspot, and JRockit is no more, so I think we will call this fixed for now.

          People

          • Assignee:
            Charles Oliver Nutter
            Reporter:
            Hiroshi Nakamura
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: