Details

    • Type: Bug Bug
    • Status: Closed Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: JRuby 1.1.5
    • Fix Version/s: JRuby 1.2
    • Component/s: Core Classes/Modules
    • Labels:
      None
    • Number of attachments :
      1

      Description

      Process.times returns invalid values which makes it look like it is taking 100% of CPU time. Here's the best documentation I could find:

      http://www.ruby-doc.org/docs/ProgrammingRuby/html/ref_c_struct__tms.html

      Obviously at FiveRuns we collect metrics like CPU usage so this functionality is important for customers using JRuby with our software.

      1. times.rb
        1 kB
        Wayne Meissner

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        Marking for 1.1.6. Ideally we could present this in a way that does not require native calls; however, I'm not sure if that's possible. At the very least, wire up "times" and tms structure in jna-posix.

        Show
        Charles Oliver Nutter added a comment - Marking for 1.1.6. Ideally we could present this in a way that does not require native calls; however, I'm not sure if that's possible. At the very least, wire up "times" and tms structure in jna-posix.
        Hide
        Wayne Meissner added a comment -

        This file monkey patches Process.times to use FFI to call the real system times(3) function.

        It will need tweaking on non-MacOS to either find the _SC_CLK_TCK value, or hardcode hz to some sane value.

        Show
        Wayne Meissner added a comment - This file monkey patches Process.times to use FFI to call the real system times(3) function. It will need tweaking on non-MacOS to either find the _SC_CLK_TCK value, or hardcode hz to some sane value.
        Hide
        Charles Oliver Nutter added a comment -

        Ok, I'm pondering this one a bit. We can certainly use the native calls, but they'll only work where native is supported, which may not include some deployment scenarios. So a non-native option is needed as well.

        It turns out Java 5+ has such a feature in its management capabilities:

        http://java.sun.com/j2se/1.5.0/docs/api/java/lang/management/ThreadMXBean.html

        However, it's provided at thread granularity, so we can get the amount of CPU time any one thread has consumed, but not easily get a full process CPU time. Obviously we could just get a list of all threads and tally them up ourselves. Does that seem right?

        Anyone interested in this, please have a look at the javadocs and offer up an opinion...

        Show
        Charles Oliver Nutter added a comment - Ok, I'm pondering this one a bit. We can certainly use the native calls, but they'll only work where native is supported, which may not include some deployment scenarios. So a non-native option is needed as well. It turns out Java 5+ has such a feature in its management capabilities: http://java.sun.com/j2se/1.5.0/docs/api/java/lang/management/ThreadMXBean.html However, it's provided at thread granularity, so we can get the amount of CPU time any one thread has consumed, but not easily get a full process CPU time. Obviously we could just get a list of all threads and tally them up ourselves. Does that seem right? Anyone interested in this, please have a look at the javadocs and offer up an opinion...
        Hide
        Charles Oliver Nutter added a comment -

        I added in r8228 a bit of logic that will try to use the built-in ThreadMXBean to tally up all thread CPU times. It does appear to give better timings, as shown here:

        $ jruby -e "sleep 5; puts Process.times"
        #<struct Struct::Tms utime=0.30719799999999997, stime=0.065078, cutime=0.0, cstime=0.0>
        

        This would have shown over 5s of CPU time before, since it reported only real time.

        Show
        Charles Oliver Nutter added a comment - I added in r8228 a bit of logic that will try to use the built-in ThreadMXBean to tally up all thread CPU times. It does appear to give better timings, as shown here: $ jruby -e "sleep 5; puts Process.times" #<struct Struct::Tms utime=0.30719799999999997, stime=0.065078, cutime=0.0, cstime=0.0> This would have shown over 5s of CPU time before, since it reported only real time.
        Hide
        Charles Oliver Nutter added a comment -

        Waiting on input from people who needed this, so we'll leave the JMX-based version in place and address a native option for post 1.1.6.

        Show
        Charles Oliver Nutter added a comment - Waiting on input from people who needed this, so we'll leave the JMX-based version in place and address a native option for post 1.1.6.
        Hide
        Mike Perham added a comment -

        I'm happy with anything that gets us more realistic numbers. The JMX solution seems fine for now.

        Show
        Mike Perham added a comment - I'm happy with anything that gets us more realistic numbers. The JMX solution seems fine for now.
        Hide
        Charles Oliver Nutter added a comment -

        Mike: Can you confirm your use of 'times' is working more like you'd expect with this change?

        Show
        Charles Oliver Nutter added a comment - Mike: Can you confirm your use of 'times' is working more like you'd expect with this change?
        Hide
        Charles Oliver Nutter added a comment -

        I had to revert the JMX-based version of this because it appears to be introducing undue overhead into request timings on Rails. I may reinstate this code with a flag, Reinstate it but only check the current thread, or omit it entirely, but it appears we'll need to consider a native option for getting process timings.

        Show
        Charles Oliver Nutter added a comment - I had to revert the JMX-based version of this because it appears to be introducing undue overhead into request timings on Rails. I may reinstate this code with a flag, Reinstate it but only check the current thread, or omit it entirely, but it appears we'll need to consider a native option for getting process timings.
        Hide
        Charles Oliver Nutter added a comment -

        I've added Wayne's workaround with a modification to use platform-appropriate SC_CLK_TCK in r8349. We'll look at getting something more built-in for 1.1.7. For now, if you need accurate CPU timings, require 'ffi/times' somewhere before you start calling Process.times, and it should be accurate.

        Show
        Charles Oliver Nutter added a comment - I've added Wayne's workaround with a modification to use platform-appropriate SC_CLK_TCK in r8349. We'll look at getting something more built-in for 1.1.7. For now, if you need accurate CPU timings, require 'ffi/times' somewhere before you start calling Process.times, and it should be accurate.
        Hide
        Charles Oliver Nutter added a comment -

        I'm going to call this resolved. Since we don't have direct access to the normal "times" C function, if you want accurate timings on JRuby you should just require ffi/times. It will replace the Process.times method with an FFI version, and all is well.

        Show
        Charles Oliver Nutter added a comment - I'm going to call this resolved. Since we don't have direct access to the normal "times" C function, if you want accurate timings on JRuby you should just require ffi/times. It will replace the Process.times method with an FFI version, and all is well.
        Hide
        Evan Weaver added a comment -

        ffi/times.rb is gone in head. No alternative seems to have appeared.

        Show
        Evan Weaver added a comment - ffi/times.rb is gone in head. No alternative seems to have appeared.

          People

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

            Dates

            • Created:
              Updated:
              Resolved: