Buck's Blog

  • April 23, 2014

JRockit's New Shutdown Verbose Logging Option

David Buck
Principal Member of Technical Staff
Have you ever had to troubleshoot an issue where the JVM seems to shutdown (in other words, disappear, but not crash), but you have no idea what triggered the shutdown? Perhaps some other process sent a SIGTERM? Or maybe some 3rd-party library you don't even have the source code for decided to call System.exit()? Another common scenario is that the last of your application's non-daemon threads have exited (normally, or as the result of an uncaught exception).

For R28.3.2, I created a new verbose logging module that instruments the JVM shutdown code and tries to log details regarding each possible event that can trigger a shutdown. In JRockit, a logging module is enabled with the "-Xverbose" command-line option, so the new module "shutdown" would be enabled  with "-Xverbose:shutdown" (*). Lets see some examples of this in action.

Here is what a shutdown initiated by a call to System.exit() would look like. (Please note the truncated module name.):

[INFO ][shutdow] JVM_Halt() called in response to:
[INFO ][shutdow] System.exit() or direct call from JNI code

Here is an example from using the "kill <pid>" command to shutdown the JVM:

[INFO ][shutdow] JVM_Halt() called in response to:
[INFO ][shutdow] Signal 15 received from PID:21152 UID:142

Here is one last example from a process where the main method has returned (and there where no other application threads still running).

[INFO ][shutdow] No remaining non-daemon Java threads.

All you need to do to get log output like the above is to run your application with a JRockit >= R28.3.2 and add "-Xverbose:shutdown" to the java command line. The logging itself is absolutely minimal and is only output during JVM shutdown. In fact, it would not be unreasonable to enable this new logging module as a proactive measure, even if you were not currently facing an unexplained shutdown issue.

While there is already a wide array of tools and techniques available for dealing with this kind of scenario (SystemTap on Linux and DTrace on Solaris being two of my favorites), I thought it would be useful to have something built into the JVM itself. The main advantage is in having a simple, platform-independent way to troubleshoot these kind of issues across all of JRockit's supported platforms.

It is important to understand that this new module can only output the reason for graceful shutdowns. If the JVM crashes, or is forcibly killed (for example via SIGKILL on a Posix system), the JVM will not have an opportunity to output information about the root cause of it's unfortunate demise. Outside of a JVM crash (which will hopefully leave behind other artifacts like a crash log or core file), another common cause of sudden process disappearances is forced termination by the OS. On Linux, in response to a system-wide lack of resources, a component called OOM killer will pick a specific process and forcibly kill it. As another example, on recent versions of Windows, closing the GUI window of the command line shell also seems to suddenly force any child processes to die without warning. In circumstances like these, the new verbose module will not be able to log the cause of the shutdown (although the lack of output itself would indicate either a forced shutdown or a crash, hopefully helping you to troubleshoot the issue further).

Obviously, there are scenarios where you will need to use other tools or techniques to further narrow down your issue even after trying the new shutdown logging module. But hopefully having this cross-platform and easy-to-use tool built right into the JVM will come in handy for resolving simple issues and at least point you in the right direction when starting a more complicated investigation.

(*) For details on using the Xverbose option, please have a look at the command line reference:

Be the first to comment

Comments ( 0 )
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.