Wednesday, April 25, 2012

Using HotSpot Attach API for fun and profit

JConsole and its successor JVisualVM are awesome tools, but most of information used by these tools is available via JMX for any JMX capable tool (though JVisualVM extensively use other APIs too). JMX and especially set of standard JVM MBeans are awesome too. You can get a lot diagnostic from stock JVM for free.

Damn, would JMX have standard restful HTTP protocol it would be best thing since sliced bread! :)

But despite their awesomeness, there  are few things which regularly frustrate me. Here they are


  • I often have SSH only access to server box (other ports are blocked). JMX is using java RMI and RMI is very unfriendly to constrained networks. While it is possible to setup RMI tunneling via SSH it is a real pain (and for chained SSH environment it is hardly possible at all).

  • I want to see portion of CPU consumed by threads. You know like top but for threads in JVM. Why this simple thing is not in JConsole?

  • I still have to parse GC logs. Heap usage diagrams are nice, but I need numbers. Visual GC is cool at diagramming, though.


  • What I would really like is a command line tool which could get me that information from running JVM.

    With Java 1.6 and above it is actually fairly simple to achieve, thank to attach API (which allows you to execute agent on other JVM by process ID). Some digging into JConsole code and woala … my wish come true.

    jtop

    jtop connects to JVM by PID and periodically dumps thread CPU utilization to a console. Just type
    java -jar jtop.jar <PID>
    and you get thread list with CPU details
    2012-04-25T00:38:07.799+0400 CPU usage 
      process cpu=2.96%
      application: cpu=2.02% (user=1.24% sys=0.78%)
      other: cpu=0.93% 
    [000001] user=0.00% sys=0.00% - main
    [000002] user=0.00% sys=0.00% - Reference Handler
    [000003] user=0.00% sys=0.00% - Finalizer
    [000004] user=0.00% sys=0.00% - Signal Dispatcher
    [000005] user=0.00% sys=0.00% - Attach Listener
    [000018] user=0.00% sys=0.00% - CLI Requests Server
    [000021] user=0.00% sys=0.00% - AWT-EventQueue-0
    [000022] user=0.00% sys=0.00% - AWT-Shutdown
    [000023] user=0.00% sys=0.00% - Inactive RequestProcessor thread [Was:Explorer Builder Processor/com.sun.tools.visualvm.core.explorer.ExplorerModelBuilder$1]
    [000026] user=0.00% sys=0.00% - TimerQueue
    [000028] user=0.00% sys=0.00% - Inactive RequestProcessor thread [Was:TimedSoftReference/org.openide.util.TimedSoftReference]
    [000032] user=0.31% sys=0.78% - Timer-1
    [000036] user=0.00% sys=0.00% - RMI TCP Accept-0
    [000037] user=0.93% sys=0.00% - RMI TCP Connection(2)-192.168.0.105
    [000038] user=0.00% sys=0.00% - RMI Scheduler(0)
    [000039] user=0.00% sys=0.00% - JMX server connection timeout 39
    [000040] user=0.00% sys=0.00% - JMX server connection timeout 40
    

    gcrep

    Like jtop, gcrep connects to running JVM, but instead of thread usage, it collects GC information and mimic GC log.
    java -jar  gcrep.jar <PID>
    [GC: G1 Young Generation#30 time: 54ms mem: G1 Survivor: 2048k+0k->2048k G1 Eden: 93184k-93184k->0k G1 Old Gen: 72253k+134k->72387k]
    [GC: G1 Young Generation#31 time: 51ms interval: 9648ms mem: G1 Survivor: 2048k+0k->2048k[rate:0.00kb/s] G1 Eden: 93184k-93184k->0k[rate:-9658.37kb/s] G1 Old Gen: 72387k+0k->72387k[rate:0.00kb/s]]
    
    Unlike normal GC logs, here I have detailed information for each space, deltas and approximate allocation rate. Of cause, you can get same thing for GC log with just few hundreds of awk script lines, provided GC log output is not screwed by race condition between concurrent phases (which is happen sometime).

    You can grab jars from code.goole.com/p/gridkit
    Sources are available at GitHub https://github.com/aragozin/jvm-tools

    Both of my tools are very rough at the moment. They just fit my personal needs, but you can easily modify code and may be send a patch back to me.

    14 comments:

    1. Alexey - I'm guessing one needs to specify the PID at the end, e.g. java -jar jtop.jar 123?

      ReplyDelete
    2. Alexey, question:

      How do you figure out which CPU usage belongs to Process and what to Application?

      Also, check this:

      process cpu=0.70%
      application: cpu=0.80% (user=0.80% sys=0.00%)
      other: cpu=-0.10%

      Process CPU is < Application CPU ==> Other is < 0%

      ReplyDelete
      Replies
      1. Hi,

        Process CPU time is reported by JMX.
        Application CPU time is accumulated CPU time of all java threads reported by JMX.

        Some threads (e.g. concurrent GC thread) is not reported. So I added accumulated "application" time to measure gap between application java threads and "other" (JVM/native) threads.

        Calculation may not be very accurate, so artifacts with negative values are possible.

        Any ideas how to improve it are welcome :)

        Delete
    3. I think you should host your code on github. You will have many people who will be willing to fork/update your code.

      BTW, nice work!

      ReplyDelete
    4. There's also this plugin for jconsole (and jvisualvm with the jconsole plugin):
      http://lsd.luminis.nl/top-threads-plugin-for-jconsole/

      ReplyDelete
    5. Not really a 'standard' but Jolokia is a JMX to HTTP bridge. I haven't seen a plugin for visualvm or the sorts though.

      http://www.jolokia.org/

      ReplyDelete
      Replies
      1. Yes, Jolokia is nice. Though installing monitoring tools as instrumentation agent is not always feasible.

        Delete
    6. What are you using to get detailed gc information? GarbageCollectorMXBean doesn't expose eden/survivor space details.

      ReplyDelete
    7. GarbageCollectorMXBean has LastGCInfo attribute which contains details for all memory spaces.

      ReplyDelete
    8. Thank you for these tools.
      Over here I have this error showing up :

      Exception in thread "main" com.sun.tools.attach.AttachNotSupportedException: The VM does not support the attach mechanism

      I have it running in 1.5 and 1.6. Already it seems only to run with version6.

      ReplyDelete