Work at SourceForge, help us to make it a better place! We have an immediate need for a Support Technician in our San Francisco or Denver office.

Close

#278 JVM hung when writing heap dump

v3.3.5
open
5
2010-04-16
2010-04-16
Sumax
No

I am using Java service wrapper version -3.3.5 on JRE1.6 JVM. My JVM heap size is 1GB. Of late there have been OutofMemory occurences on the JVM, and hence I have configured the JVM to print heap-dump to disk on OOM. But I see that the wrapper terminates the JVM while it is printing the heap-dump, and hence I never get the complete heap-dump to analyze. I am using the default ping-timeout configuration of the wrapper (I assume it is 30secs).

I have attached the log snippet below. Please help me figure out what config I should be tweaking in the wrapper to identify the heap-dump event and hold off on terminating the JVM until the heap dump is complete.

-------------------------
INFO | jvm 3 | 2010/04/15 18:39:54 | [Full GC
INFO | jvm 3 | 2010/04/15 18:39:57 | 971007K->971007K(1009792K), 3.0115220 secs]
INFO | jvm 3 | 2010/04/15 18:39:57 | [Full GC
INFO | jvm 3 | 2010/04/15 18:40:02 | 971007K->970260K(1009792K), 4.0798794 secs]
INFO | jvm 3 | 2010/04/15 18:40:02 | [Full GC
INFO | jvm 3 | 2010/04/15 18:40:05 | 971008K->971008K(1009792K), 2.9432915 secs]
INFO | jvm 3 | 2010/04/15 18:40:05 | java.lang.OutOfMemoryError: Java heap space
INFO | jvm 3 | 2010/04/15 18:40:05 | Dumping heap to java_pid3424.hprof ...
INFO | jvm 3 | 2010/04/15 18:40:05 | [Full GC
INFO | jvm 3 | 2010/04/15 18:40:08 | 971008K->971008K(1009792K), 2.8907112 secs]
INFO | jvm 3 | 2010/04/15 18:40:08 | [Full GC
INFO | jvm 3 | 2010/04/15 18:40:11 | 971008K->970520K(1009792K), 3.7910460 secs]
INFO | jvm 3 | 2010/04/15 18:40:11 | [Full GC
INFO | jvm 3 | 2010/04/15 18:40:15 | 971008K->970390K(1009792K), 3.7844757 secs]
ERROR | wrapper | 2010/04/15 18:40:52 | JVM appears hung: Timed out waiting for signal from JVM.
ERROR | wrapper | 2010/04/15 18:40:53 | JVM did not exit on request, terminated
-------------------------

Thanks
Sumax

Discussion

  • Sumax
    Sumax
    2010-04-16

    I have been using this wrapper config for more than 4 years now, and I see it is happening in our Production env, hence I would greatly appreciate as quick a response as possible.

     
  • Sumax
    Sumax
    2010-04-16

    • priority: 5 --> 9
     
  • Leif Mortenson
    Leif Mortenson
    2010-04-16

    • priority: 9 --> 5
    • assigned_to: nobody --> mortenson
     
  • Leif Mortenson
    Leif Mortenson
    2010-04-16

    Sumax,
    The problem is that the JVM takes a couple minutes or more to write the dump file. When this is being done, the JVM is 100% unresponsive and the Wrapper is thinking it is frozen. This is not normal operation for a server app.

    To work around this, you need to extend the shutdown timeouts so the Wrapper always gives your JVM time to dump its output.
    wrapper.shutdown.timeout=300
    wrapper.jvm_exit.timeout=300

    We recommend that you remove these settings when you disable the profiling.

    Please let me know how this works for you.

    Cheers,
    Leif

     
  • Sumax
    Sumax
    2010-04-16

    Shuld'nt it be the 'wrapper.ping.timeout' that I have to increase?, instead of wrapper.shutdown.timeout=300
    wrapper.jvm_exit.timeout=300

    Thanks,

     
  • Leif Mortenson
    Leif Mortenson
    2010-04-16

    Sumax,
    It depends when the dump is taking place. Usually when I use it, I have it set up to dump on shutdown. If you are doing dumps while the JVM is running then yes, you should set the following:

    wrapper.ping.timeout=300

    Cheers,
    Leif

     
  • Sumax
    Sumax
    2010-04-16

    I have configured the JVM itself to dump contents to heap only when it goes OutOfMemory (using the JVM option -XX:+HeapDumpOnOutOfMemoryError).
    I am not sure if the JVM is in running state or Shutdown when it is dumping the heap. My guess is that the JVM is still in running state when this happens. From the log snippet I have posted, it looks like there was no attempt to shutdown from the JVM while or before it started dumping the heap contents.

    Please let me know your thoughts.