The Support Authority: JVM enhancements that help you see how your WebSphere Application Server is behaving

Recently, a number of new enhancements have been made to the serviceability features within the IBM® Java™ Virtual Machine. These improvements have been delivered as part of Java 6 R2.6, the latest release from the IBM Java Technology Centre, which underpins IBM WebSphere® Application Server V8. Some of the improvements have also been delivered in Service Refreshes of Java 6. 1.This article discusses each category of improvements that have been made, and how they can help you better understand the behavior of your application running on WebSphere Application Server V8. This content is part of the IBM WebSphere Developer Technical Journal.

Share:

Ian Partridge ( i.partridge@uk.ibm.com ), J9CORE Java Service Team , IBM

Ian Partridge joined IBM in 2003 as a member of the JVM development team. He initially worked in the garbage collection development team, before taking roles in the shared classes and RAS components. In 2009 he moved to the Java service organisation to pass on his knowledge of JVM debugging and troubleshooting to customers.



Adam Pilkington, Advisory Software Engineer, J9 RAS, IBM

Before joining IBM in 2006, Adam Pilkington was a J2EE technical architect for a large financial services organisation in the UK. He is now part of the Java Technology Centre team based in the Hursley Park Development Lab and has worked in both the Java performance and Diagnostic Tooling Framework for Java (DTFJ) teams. He is currently working in the RAS team where he is the lead for IBM's strategic technology for enabling JVM post mortem diagnostics. He is currently focussing on ways to leverage this technology beyond its initial scope, whilst working with both the development and service organisations across IBM labs to ensure it's adoption and ways that it can be enhanced to deliver greater business value. Adam is a developerWorks Contributing Author and was appointed an IBM Senior Inventor in 2008.


developerWorks Contributing author
        level

Dr. Mahesh Rathi, WebSphere Application Server SWAT Team, IBM

Dr. Mahesh Rathi has been involved with WebSphere Application Server product since its inception. He led the security development team before joining the L2 Support team, and joined the SWAT team in 2005. He thoroughly enjoys working with demanding customers, on hot issues, and thrives in pressure situations. He received his PhD in Computer Sciences from Purdue University and taught Software Engineering at Wichita State University before joining IBM.



21 September 2011

Also available in Chinese Russian

In each column, The Support Authority discusses resources, tools, and other elements of IBM® Technical Support that are available for WebSphere® products, plus techniques and new ideas that can further enhance your IBM support experience.

This just in...

As always, we begin with some new items of interest for the WebSphere community at large:

Continue to monitor the various support-related Web sites, as well as this column, for news about other tools as we encounter them.

And now, on to our main topic...


JVM serviceability enhancements

Several enhancements have been made to the serviceability features within the IBM Java Virtual Machine, delivered as part of Java 6 R2.6, which underpins IBM WebSphere Application Server V8. These improvements can be categorized into five main areas:

Details on each of these areas are described in the sections that follow.


JVM dump support (-Xdump)

The -Xdump option in the JVM configures the behaviour of the dump engine. You've probably used some of the features of the dump engine before without realizing you were doing so. For example, if you've ever seen a PHD heapdump file generated when a java/lang/OutOfMemoryError was thrown, that process was controlled by the dump engine.

The dump engine works by using the concept of agents. Each dump agent represents an instruction to the JVM of what type of dump to generate under which condition. There are default dump agents, such as the one which writes a PHD heapdump when an OutOfMemoryError is thrown, but you can also specify your own on the command line.

When a dump event occurs, the JVM reviews the list of active dump agents and executes any that are applicable to the event in question. The resulting action could be to write a javacore file, a heapdump file, a system dump file, or to execute an external tool, for example.

There are a variety of different dump events you can use. Table 1 shows some of the most useful ones.

Table 1
EventTriggered when
gpfA general protection fault (GPF) occurs.
userThe JVM receives the SIGQUIT (Linux®, AIX®, z/OS®, and i5/OS®) or SIGBREAK (Windows®) signal.
vmstartThe JVM is started.
vmstopThe JVM stops (for example, System.exit() is called).
loadA class is loaded.
systhrowAn exception is about to be thrown by the JVM.
fullgcA garbage collection cycle is started.
allocationAn object is allocated with a size matching the given “filter” expression.

If you want to write a heapdump when a certain exception is thrown, try this command:

-Xdump:heap:events=systhrow,filter=com/acme/MyException

If you want to write a javacore file when the JVM starts up (for example, to check that custom options you have specified are being picked up), then try adding:

-Xdump:java:events=vmstart

Most of the improvements made to -Xdump support relate to javacore files. Javacore files are human-readable text files that summarise the state of the JVM. By default, they are generated when SIGQUIT is sent to the JVM. Here are the improvements which have been made to these files:

  • Native stack traces

    Although javacore files contained a list of the threads currently running, they previously only listed each thread's Java stack. This is only half the story. As well as a Java stack, each thread also has a native stack. Being able to see the native stack can be really useful, especially in applications that make use of the Java Native Interface (JNI) to transition between Java and native code. Listing1 shows an extract of the output you now see in a javacore file.

    Listing 1
    THREADS subcomponent dump routine
    =================================
    Current thread
    ----------------------
    "main" J9VMThread:0x41481300, j9thread_t:0x002A5284, java/lang/Thread:0x00431CB0,
    state:R, prio=5
    (native thread ID:0xB7C, native priority:0x5, native policy:UNKNOWN)
    Java callstack:
    at gpf.action(Native Method)
    at gpf.main(gpf.java:8)
    Native callstack:
    _Java_gpf_action@8+0xe (gpf.c:14, 0x42181025 [gpf+0x1025])
    VMprJavaSendNative+0x421 (jnisend.asm:432, 0x7FF0B321 [j9vm24+0x1b321])
    gpProtectedRunCallInMethod+0x1c (jnicsup.c:313, 0x7FF0748C [j9vm24+0x1748c])
    signalProtectAndRunGlue+0xa (jnicsup.c:1840, 0x7FF07F2A [j9vm24+0x17f2a])
    j9sig_protect+0x41 (j9signal.c:144, 0x7FECC161 [J9PRT24+0xc161])
    gpProtectAndRun+0x38 (jnicsup.c:410, 0x7FF08788 [j9vm24+0x18788])
    gpCheckCallin+0x3a (jnicsup.c:558, 0x7FF0883A [j9vm24+0x1883a])
    callStaticVoidMethod+0x44 (jnicgen.c:303, 0x7FF06E84 [j9vm24+0x16e84])
    getString646_USChars+0x5b (jni_util.c:488, 0x00403750 [java+0x3750])
    canonicalize+0x61 (canonicalize_md.c:249, 0x00409A7E [java+0x9a7e])
    GetModuleFileNameA+0x1ba (0x7C80B729 [kernel32+0xb729])

    You can see that by also having the native callstack, you can glean useful information about the state of the JVM. For example, you can see the filename and line number of the native method currently being executed. This can really help to track down why crashes in native code are occurring.

    As a bonus, anonymous native threads are also listed in javacore files. Previously, only Java threads were listed. Now, if your application is using native threads as well (for example, you are creating threads directly from native code using operating system APIs, such as pthreads) these will be listed in javacore files. Listing 2 is an example from a javacore, showing the JIT sampler thread. The JIT sampler thread is a background thread started by the JVM. It monitors what Java code is being executed so that the JIT compiler can make good decisions about which Java methods to select for compilation to native code.

    Listing 2
    Anonymous native thread
    (native thread ID:0x9A8, native priority: 0x0, native policy:UNKNOWN)
    Native callstack:
    KiFastSystemCallRet+0x0 (0x7C90E514 [ntdll+0xe514])
    WaitForSingleObject+0x12 (0x7C802542 [kernel32+0x2542])
    j9thread_sleep_interruptable+0x101 (j9thread.c:1458, 0x7FFA1311 [J9THR24+0x1311
    samplerThreadProc+0x5f6 (hookedbythejit.cpp:3301, 0x7F82E826 [j9jit24+0xe826])
    thread_wrapper+0xbf (j9thread.c:971, 0x7FFA3F4F [J9THR24+0x3f4f])
    _threadstart+0x6c (thread.c:196, 0x7C34940F [msvcr71+0x940f])
    GetModuleFileNameA+0x1ba (0x7C80B729 [kernel32+0xb729])

    At the time of this writing, there are a few limitations with native stack trace support. It is not currently available on z/OS or 64-bit Windows. Also, the ability to see filenames and line numbers depends on the compiler options that were used, whether your binaries are stripped, and whether appropriate side-files (for example, PDB files on Windows) are available.

  • Environment variables

    Javacore files now include details of the environment variables that are set (Listing 3).

    Listing 3
    Environment Variables
    ------------------------------------------------------------------------
    _CXX_WORK_SPACE=(32000,(150,150))
    _CXX_PMSGS=EDCPMSGE
    MAIL=/usr/mail/CHAMBER
    _CC_CNAME=CCNDRVR
    PATH=/u/sovbld/bldsys:/usr/local/perl/bin:/u/java/bin:/bin:/usr/sbin:/u/chamb....
    _C89_WORK_SPACE=(32000,(150,150))
    _CXX_WORK_UNIT=SYSDA
    _CXX_INCDIRS=/usr/include //DD:SYSLIB //'PP.ADLE370.ZOS180.SCEEH.NET.H'....
    _C89_PNAME=EDCPRLK
    TMPDIR=/tmp

    Since there are certain legacy environment variables which can affect the behaviour of the JVM, it's useful to have this information included. Users also sometimes have problems relating to the setting of the LIBPATH environment variable. It's now easy to see what that's been set to.

  • ulimits

    Javacore files also now include details of the operating system ulimit settings (Listing 4).

    Listing 4
    User Limits (in bytes except for NOFILE and NPROC)
    -----------------------------------------------------------------
    type				soft limit		hard limit
    RLIMIT_AS			unlimited		unlimited
    RLIMIT_CORE			0			unlimited
    RLIMIT_CPU			unlimited		unlimited
    RLIMIT_DATA			unlimited		unlimited
    RLIMIT_FSIZE		unlimited		unlimited
    RLIMIT_LOCKS		unlimited		unlimited
    RLIMIT_MEMLOCK		32768			32768
    RLIMIT_NOFILE		1024			1024
    RLIMIT_NPROC		16382			16382
    RLIMIT_RSS			unlimited		unlimited
    RLIMIT_STACK		10485760		unlimited
    RLIMIT_MSGQUEUE		819200		819200	
    RLIMIT_NICE			0			0
    RLIMIT_RTPRIO		0			0
    RLIMIT_SIGPENDING		16382			16382

    One of the most common reasons why users are unable to collect a full valid core file is because their ulimit settings are too restrictive. By having this information easily at hand in javacores you might be able to diagnose that problem more quickly.

  • Native memory usage counters

    A major new feature in javacore files is a summary of the native memory usage of the JVM, organized by component in a tree. Listing 5 shows how it looks.

    Listing 5
    NATIVEMEMINFO subcomponent dump routine
    =======================================
    JRE: 555,698,264 bytes / 1208 allocations
    |
    +--VM: 552,977,664 bytes / 856 allocations
    | |
    | +--Classes: 1,949,664 bytes / 92 allocations
    | |
    | +--Memory Manager (GC): 547,705,848 bytes / 146 allocations
    | | |
    | | +--Java Heap: 536,875,008 bytes / 1 allocation
    | | |
    | | +--Other: 10,830,840 bytes / 145 allocations
    | |
    | +--Threads: 2,660,804 bytes / 104 allocations
    | | |
    | | +--Java Stack: 64,944 bytes / 9 allocations
    | | |
    | | +--Native Stack: 2,523,136 bytes / 11 allocations
    | | |
    | | +--Other: 72,724 bytes / 84 allocations
    | |
    | +--Trace: 92,464 bytes / 208 allocations
    | |
    | +--Trace: 92,464 bytes / 208 allocations
    | |
    | +--JVMTI: 17,328 bytes / 13 allocations
    | |
    | +--JNI: 15,944 bytes / 32 allocations
    | |
    | +--Port Library: 6,824 bytes / 56 allocations
    | |
    | +--Other: 528,788 bytes / 205 allocations
    |
    +--JIT: 1,748,808 bytes / 82 allocations
    | |
    | +--JIT Code Cache: 524,320 bytes / 1 allocation
    | |
    | +--JIT Data Cache: 524,336 bytes / 1 allocation
    | |
    | +--Other: 700,152 bytes / 80 allocations
    |
    +--Class Libraries: 971,792 bytes / 270 allocations

    You can easily see how much memory is being used by threads, for example. This new feature will be really useful when memory leaks are being diagnosed. The feature has been designed so that it will be easy to improve the granularity of the data in future. By the way, the huge size of the Memory Manager (GC) section reflects the Java heap size you've set using the -Xmx option.


JVM Trace Support (-Xtrace)

The JVM trace engine is a flexible component that you can use to trace the execution flow of your application. You could use it to generate a javacore file when a certain Java method is entered or exited, or you could use it to calculate exactly how much time each JDBC transaction is taking, for example.

The JVM itself also has internal tracepoints built-in, which are invaluable to the IBM support team. In Java 6 R2.6 the number of internal tracepoints has been increased, providing greater granularity to the JVM's internal data logging. Of course, work has been done to minimise the performance impact of tracepoints, so they remain with extremely low overhead.

An important user-facing feature added to the trace engine is the ability to trigger printouts of Java stacktraces when a certain Java method is executed (Listing 6).

Listing 6
java -Xtrace:methods={myHello.*},trigger=method{myHello.*,jstacktrace} myHello,print=mt

09:58:56.546*0x123700 mt.3 > myHello.<clinit>()V Bytecode static method
09:58:56.562 0x123700 j9trc_aux.0 - jstacktrace:
09:58:56.562 0x123700 j9trc_aux.1 - [1] myHello.<clinit> (myHello.java:21)
09:58:56.578 0x123700 j9trc_aux.1 - [2] java.lang.J9VMInternals.initializeImpl 
	(Native Method)
09:58:56.578 0x123700 j9trc_aux.1 - [3] java.lang.J9VMInternals.initialize 
	(J9VMInternals.java
09:58:56.593 0x123700 mt.9 < myHello.<clinit>()V Bytecode static method
09:58:56.593 0x123700 mt.3 > myHello.main([Ljava/lang/String;)V Bytecode static method
09:58:56.609 0x123700 j9trc_aux.0 - jstacktrace:
09:58:56.609 0x123700 j9trc_aux.1 - [1] myHello.main (myHello.java:26)
Hello World
09:58:56.625 0x123700 mt.9 > myHello.main([Ljava/lang/String;)V Bytecode static method

The -Xtrace option here is split into three different components:

  • methods={myHello.*}

    This enables method trace for all methods in the myHello class.

  • trigger=method{myHello.*,jstacktrace}

    This sets the JVM to emit a Java stacktrace when any method in the myHello class is entered.

  • print=mt

    This tells the JVM that all the method trace output should be printed to the console.

In the example output shown in Listing 6, you can see that the jstacktrace trigger occurred twice: once when a myHello object was constructed (myHello.<clinit>) and once when myHello.main() was entered.

You can also be more specific; for example, only start to print stacktraces after a given method is entered for the fifth time:

java -Xtrace:methods={myHello.main},trigger=method{myHello.main,jstacktrace,,5} myHello,print=mt


JVM Logging (-Xlog)

The -Xlog parameter is used to control the logging of JVM messages. These are the messages prefixed with a unique identifier, for example:

JVMDUMP032I JVM requested Java dump using 'C:\javacore.20110526.152519.2636.0001.txt' in response to an event

All these messages are sent to stderr by default, but selected messages are also sent to the system log as well. Table 2 shows how this is implemented on different platforms.

Table 2
PlatformSystem log
WindowsEvent log (Event Viewer)
Linuxsyslog
AIXerrlog or syslog
z/OSMVS console

You can control which messages are sent to the system log via the -Xlog command. By default, the JVM logs all messages in the Error and Vital category to the system log. To log every message, specify -Xlog:all. To log only error and warning messages, specify -Xlog:error,warn. To disable all logging to the system log, specify -Xlog:none. Be aware that if you specify -Xlog:none, logging to stderr is unaffected.


RAS extension APIs in JVMTI

The JVM Tool Interface (JVMTI) is a programming interface that can be used by external tools to query the state of the JVM and the application it is running. There is a comprehensive set of APIs provided for inspecting the behaviour of threads, objects, classes, and the JVM's memory management.

The JVMTI specification also provides a way for JVMs to implement their own custom interfaces via the Extension Mechanism. JVMTI agent can discover the list of custom APIs exposed by a JVM via the GetExtensionFunctions() function. This returns an array of jvmtiExtensionFunctionInfo structures, one for each extension function the JVM defines.

The IBM JVM defines a number of extension functions, and these have been expanded in Java 6 R2.6 to include functions for controlling the behaviour of the dump engine at run time. These are defined in the ibmjvmti.h header file which ships in the Java SDK. The functions include:

  • QueryVmDump()

    Query the VM dump options that are currently defined and enabled. The function returns a list of dump option specifications as ASCII strings.

  • SetVmDump()

    Modify the current settings of the dump engine at run time using the same syntax as the -Xdump option (with the initial -Xdump: omitted).

  • TriggerVmDump()

    Trigger a VM dump. The type of dump required is specified as a char* string (for example, java or heap).

  • ResetVmDump()

    Resets the VM's list of dump agents back to the settings which were in force when the JVM started.

There are also two JVMTI Event functions defined in ibmjvmti.h. One is VMDumpStart(), which is triggered whenever a JVM dump starts, and the other is VMDumpEnd(), which is triggered whenever a JVM dump ends. The parameters to these callback functions enable the receiver to determine the dump event in question, the extension event name, and the dump filename that is being written to by the dump agent. These event functions can be useful if you want to write complex custom native code to be executed in a failure scenario.


Simplification of the postprocessing requirements for system dumps

Previous versions of the JDK required you to run the jextract postprocessing tool on IBM system dumps before tools such as Memory Analyzer would be able to load and process the dump. This requirement has now been removed and these tools will be able to work immediately on the system dump. Although this is a new feature, there is built-in support for other versions of the JDK , specifically Java 6 Service Refresh (SR) 9 and later, and Java 5 SR 12 and later. System dumps generated from these JDKs can be loaded into a post mortem analysis tool without processing by jextract.

Native code analysis

In order to analyze native code, for example a JNI invoked function, a tool might also require the presence of the native libraries that were loaded by the VM at that time. Typically, the most common use of these libraries is to resolve any native symbols contained within a stack trace. Some platforms such as Windows and z/OS produce system dumps that already contain the native libraries and so no further collection steps are required. If they are not included in the system dump and the analysis is being carried out on the machine which generated the dump, then the locally found libraries will be used. However, if the core file is moved to another machine, then the native libraries will also need to be transferred. The are currently two mechanisms provided for doing this. The first is to use IBM Diagnostics Collector, which can either be enabled when the VM starts or can be used following the generation of a system dump. The alternative method is to run jextract as before. Both of these tools generate a compressed archive which will contain the dump and any other required artifacts, such as the native libraries.


Conclusion

There are a number of new features available in the Java 6 R2.6 release which underpin WebSphere Application Server V8. For more information, consult the IBM SDK Java Technology Edition Version 6 Supplement Information Center, which documents the differences between Java 6 and the new Java 6 R2.6 release. This document should be read in conjunction with the Java 6 Diagnostics Guide.

Resources

Learn

Get products and technologies

Discuss

Comments

developerWorks: Sign in

Required fields are indicated with an asterisk (*).


Need an IBM ID?
Forgot your IBM ID?


Forgot your password?
Change your password

By clicking Submit, you agree to the developerWorks terms of use.

 


The first time you sign into developerWorks, a profile is created for you. Information in your profile (your name, country/region, and company name) is displayed to the public and will accompany any content you post, unless you opt to hide your company name. You may update your IBM account at any time.

All information submitted is secure.

Choose your display name



The first time you sign in to developerWorks, a profile is created for you, so you need to choose a display name. Your display name accompanies the content you post on developerWorks.

Please choose a display name between 3-31 characters. Your display name must be unique in the developerWorks community and should not be your email address for privacy reasons.

Required fields are indicated with an asterisk (*).

(Must be between 3 – 31 characters.)

By clicking Submit, you agree to the developerWorks terms of use.

 


All information submitted is secure.

Dig deeper into WebSphere on developerWorks


static.content.url=http://www.ibm.com/developerworks/js/artrating/
SITE_ID=1
Zone=WebSphere
ArticleID=758483
ArticleTitle=The Support Authority: JVM enhancements that help you see how your WebSphere Application Server is behaving
publish-date=09212011