Interpreting a Javadump

 

+

Search Tips   |   Advanced Search

 

In general, the information in a Javadump file is platform independent. However, certain platforms might provide more information about fatal exceptions.

The content and range of information in a Javadump is not guaranteed across releases. In some cases, information might be missing because of the nature of a crash.

 

Javadump tags

The Javadump file contains sections separated by eyecatcher title areas to aid readability of the Javadump. The first such eyecatcher is shown below:

--------------------------------------------------------------
0SECTION TITLE subcomponent dump routine
===============================

Different sections contain different tags. An example tag (1CIJAVAVERSION) is shown below:

1CIJAVAVERSION J2RE 5.0 IBM J9 2.3 Windows XP x86-32 build 20051012_03606_lHdSMR
        (JIT enabled - 20051012_1800_r8)

Normal tags have these characteristics:

Special tags have these characteristics:

Here is an example of some tags taken from the start of a Windows dump.

NULL           --------------------------------------------------------------
0SECTION       TITLE subcomponent dump routine
NULL           ===============================
1TISIGINFO     Dump Event "user" (00004000) received 
1TIDATETIME    Date:                 2006/08/22 at 17:23:50
1TIFILENAME    Javacore filename:    C:\\javacore.20060822.172350.1196.txt
NULL           --------------------------------------------------------------
0SECTION       GPINFO subcomponent dump routine
NULL           ================================
2XHOSLEVEL     OS Level         : Windows XP 5.1 build 2600 Service Pack 1
2XHCPUS        Processors -
3XHCPUARCH       Architecture   : x86
3XHNUMCPUS       How Many       : 1

For the rest of the chapter, the tags are removed to aid readability.

 

TITLE, GPINFO, and ENVINFO sections

At the start of a Javadump, the first three sections are the TITLE, GPINFO, and ENVINFO sections.

The example below shows some output taken from a test program, using JNI, that executes a strcpy into a protected location.

strcpy produces an access violation that has an exception code (on Windows) of 0xC0000005.

This is commonly referred to as a "general protection fault" or gpf.

In this case failure was caused by MSVCR71D.dll.

TITLE subcomponent dump routine
===============================
Dump Event "gpf" (00002000) received 
Javacore filename:    C:\Program Files\IBM\Java50\jre\bin\javacore.20051024.110853.2920.txt

GPINFO subcomponent dump routine
================================
OS Level: Windows XP 5.1 build 2600 Service Pack 1
Processors -
        Architecture: x86
        How Many:       1


J9Generic_Signal_Number: 00000004
ExceptionCode: C0000005
ExceptionAddress: 423155F1
ContextFlags: 0001003F
Handler1: 70C2FE60
Handler2: 70B86AB0
InaccessibleAddress: 000004D2

Module: C:\WINDOWS\System32\MSVCR71D.dll
Module_base_address: 42300000
Offset_in_DLL: 000155F1

Registers:
        EDI:000004D2
        ESI:00000020
        EAX:000004D2
        EBX:00000000
        ECX:000004D2
        EDX:00000000
        EIP:423155F1
        ESP:0007FBF4
        EBP:0007FCDC

VM flags:00040000

------------------------------------------------------------------------
ENVINFO subcomponent dump routine
=================================
J2RE 5.0 IBM J9 2.3 Windows XP x86-32 build 20051015_03657_lHdSMR (JIT enabled - 20051015_1812_r8)
Running as a standalone JVM java Test GPF
Java Home Dir:   C:\Program Files\IBM\Java50\jre
Java DLL Dir:    C:\Program Files\IBM\Java50\jre\bin
Sys Classpath:   C:\Program Files\IBM\Java50\jre\lib\vm.jar;C:\Program Files\....... 
UserArgs:
        -Xjcl:jclscar_23
        -Dcom.ibm.oti.vm.bootstrap.library.path=C:\Program Files\IBM\Java50\jre\bin
        -Dsun.boot.library.path=C:\Program Files\IBM\Java50\jre\bin
                << lines removed .........>>
        -Xdump

 

Storage Management (MEMINFO)

After the previous sections is the MEMINFO section, giving information about the Memory Manager.

This part of the file gives various storage management values (in hexadecimal), including the free space in heap, the size of current heap, and details on other internal memory that the JVM is using. It also contains garbage collection history data.

The example below shows some typical output. All the values are output as hexadecimal values.

------------------------------------------------------------------------
MEMINFO subcomponent dump routine
=================================
Bytes of Heap Space Free: 365df8
Bytes of Heap Space Allocated: 400000

Internal Memory
        segment         start           alloc           end             type            bytes
        00172FB8	       41D79078        41D7DBC4        41D89078        01000040        10000
                << lines removed for clarity >>
        00172ED4        4148C368        4149C360        4149C368        01000040        10000
Object Memory
        segment         start           alloc           end             type            bytes
        00173EDC        00420000        00820000        00820000        00000009        400000
Class Memory
        segment         start           alloc           end             type            bytes
        001754C8        41E36250        41E36660        41E3E250        00010040        8004
                << lines removed for clarity >>
        00174F24        41531C70        415517C8        41551C70        00020040        20000
JIT Code Cache
        segment         start           alloc           end             type            bytes
        4148836C        002F0000        00370000        00370000        00000068        80000
JIT Data Cache
        segment         start           alloc           end             type            bytes
        41489374        416A0020        416A259C        41720020        00000048        80000

GC History
10:11:18:562797000 GMT j9mm.53 -   GlobalGC end: workstackoverflow=0 overflowcount=0 weakrefs=81 
   soft=1 phantom=0 finalizers=21 newspace=0/0 oldspace=64535568/101534208 loa=6582784/9938432 
10:11:18:562756000 GMT j9mm.57 -   Sweep end 
10:11:18:561695000 GMT j9mm.56 -   Sweep start 
10:11:18:561692000 GMT j9mm.55 -   Mark end 
10:11:18:558022000 GMT j9mm.54 -   Mark start 
10:11:18:558003000 GMT j9mm.52 -   GlobalGC start: weakrefs=81 soft=1 phantom=0 finalizers=21
  globalcount=41 scavengecount=0 
10:11:18:465931000 GMT j9mm.53 -   GlobalGC end: workstackoverflow=0 overflowcount=0 weakrefs=81
  soft=1 phantom=0 finalizers=21 newspace=0/0 oldspace=52177296/103607808 loa=4944968/9105408 
10:11:18:465892000 GMT j9mm.57 -   Sweep end 
10:11:18:464689000 GMT j9mm.56 -   Sweep start 
10:11:18:464687000 GMT j9mm.55 -   Mark end 
10:11:18:460946000 GMT j9mm.54 -   Mark start 
10:11:18:460927000 GMT j9mm.52 -   GlobalGC start: weakrefs=83 soft=1 phantom=0 finalizers=21
  globalcount=40 scavengecount=0 
10:11:18:350282000 GMT j9mm.53 -   GlobalGC end: workstackoverflow=0 overflowcount=0 weakrefs=83
  soft=1 phantom=0 finalizers=21 newspace=0/0 oldspace=53218040/104210432 loa=1838432/8116224 
10:11:18:350263000 GMT j9mm.57 -   Sweep end 
10:11:18:349051000 GMT j9mm.56 -   Sweep start 
10:11:18:349048000 GMT j9mm.55 -   Mark end 
10:11:18:345270000 GMT j9mm.54 -   Mark start 

 

Locks, monitors, and deadlocks (LOCKS)

Here is an example of the LOCKS component part of a Windows 32-bit Javadump taken during a deadlock. A lock (also referred to as a monitor) prevents more than one entity from accessing a shared resource. Each object in Java has an associated lock (obtained by using a synchronized block or method). In the case of the JVM, threads compete for various resources in the JVM and locks on Java objects.

This example was taken from a deadlock test program where two threads "DeadLockThread 0" and "DeadLockThread 1" were unsuccessfully attempting to synchronize (Java keyword) on two java/lang/Integers.

You can see in the example (highlighted) that "DeadLockThread 1" has locked the object instance...

The monitor has been created as a result of a Java code fragment looking like "synchronize(count0)", and this monitor has "DeadLockThread 1" waiting to get a lock on this same object instance (count0 from the code fragment). Below is another monitor locked by "DeadLockThread 0" that has "DeadLockThread 1" waiting.

This classic deadlock situation is caused by an error in application design; Javadump is a major tool in the detection of such events.

LOCKS subcomponent dump routine
===============================
Monitor pool info: Current total number of monitors: 2
Monitor Pool Dump (flat & inflated object-monitors):
 sys_mon_t:0x00039B40 infl_mon_t: 0x00039B80:

   java/lang/Integer@004B22A0/004B22AC: Flat locked by "DeadLockThread 1" (0x41DAB100), entry count 1

   Waiting to enter: "DeadLockThread 0" (0x41DAAD00)
 sys_mon_t:0x00039B98 infl_mon_t: 0x00039BD8: 

   java/lang/Integer@004B2290/004B229C: Flat locked by "DeadLockThread 0"  (0x41DAAD00), entry count 1

   Waiting to enter: "DeadLockThread 1" (0x41DAB100)

JVM System Monitor Dump (registered monitors):

          Thread global lock (0x00034878): <unowned>
          Windows native HEAP lock lock (0x000348D0): <unowned>
          NLS hash table lock (0x00034928): <unowned>
          portLibrary_j9sig_async_monitor lock (0x00034980): <unowned>
          Hook Interface lock (0x000349D8): <unowned>
            < lines removed for brevity >

=======================
Deadlock detected !!!
---------------------
           
  Thread "DeadLockThread 1" (0x41DAB100)
    is waiting for:
      sys_mon_t:0x00039B98 infl_mon_t: 0x00039BD8:
      java/lang/Integer@004B2290/004B229C: 
    which is owned by:
  Thread "DeadLockThread 0" (0x41DAAD00)
    which is waiting for:
      sys_mon_t:0x00039B40 infl_mon_t: 0x00039B80:
      java/lang/Integer@004B22A0/004B22AC: 
    which is owned by:
  Thread "DeadLockThread 1" (0x41DAB100)


 

Threads and stack trace (THREADS)

This section shows a complete list of Java threads that are alive.

A thread is alive if it has been started but not yet stopped. A Java thread is implemented by a native thread of the operating system. Each thread is represented by a line such as:

"Signal Dispatcher" (TID:0x41509200, sys_thread_t:0x0003659C, state:R, native ID:0x00000C78) prio=5
  	 at com/ibm/misc/SignalDispatcher.waitForSignal(Native Method)
  	 at com/ibm/misc/SignalDispatcher.run(SignalDispatcher.java:84)

The properties of a thread are...

The Java thread priority is mapped to an operating system priority value in a platform-dependent manner. A large value for the Java thread priority means that the thread has a high priority (that is, the thread should run more frequently than lower priority threads).

The values of state can be:

R - Runnable Thread is able to run when given the chance.
CW - Condition Wait Thread is waiting. For example, because:

  • A sleep() call is made
  • The thread has been blocked for I/O
  • A synchronized method of an object locked by another thread has been called
  • The thread is synchronizing with another thread with a join() call
S - Suspended Thread has been suspended by another thread.
Z - Zombie Thread has been killed.
P - Parked The thread has been parked by the new concurrency API (java.util.concurrent).
B - Blocked Thread is waiting to obtain a lock that something else currently owns.

There is a stack trace below each Java thread. A stack trace is a representation of the hierarchy of Java method calls made by the thread. The example below is taken from the same Javadump as used in the LOCKS example and two threads ("DeadLockThread 0" and "DeadLockThread 1") are both in Blocked state. The application code path that resulted in the deadlock between "DeadLockThread 0" and "DeadLockThread 1" can clearly be seen.

There is no current thread because all the threads in the application are blocked. The Javadump generation was triggered by a user signal.


------------------------------------------------------------------------
THREADS subcomponent dump routine
=================================

Current Thread Details
----------------------

All Thread Details
------------------

Full thread dump J9SE VM (J2RE 5.0 IBM J9 2.3 Windows XP x86-32 build 20051012_03606_lHdSMR,
                                                  native threads):
  "DestroyJavaVM helper thread" (TID:0x41508A00, sys_thread_t:0x00035EAC, state:CW,
          native ID:0x00000F54) prio=5
  "JIT Compilation Thread" (TID:0x41508E00, sys_thread_t:0x000360FC, state:CW, native ID:0x000000BC)
          prio=11
  "Signal Dispatcher" (TID:0x41509200, sys_thread_t:0x0003659C, state:R, native ID:0x00000C78) prio=5
          at com/ibm/misc/SignalDispatcher.waitForSignal(Native Method)
 	       at com/ibm/misc/SignalDispatcher.run(SignalDispatcher.java:84)
  "DeadLockThread 0" (TID:0x41DAAD00, sys_thread_t:0x42238A1C, state:B, native ID:0x0000073C) prio=5
          at Test$DeadlockThread0.SyncMethod(Test.java:112)
          at Test$DeadlockThread0.run(Test.java:131)
  "DeadLockThread 1" (TID:0x41DAB100, sys_thread_t:0x42238C6C, state:B, native ID:0x00000738) prio=5
          at Test$DeadlockThread1.SyncMethod(Test.java:160)
          at Test$DeadlockThread1.run(Test.java:141) 

 

Classloaders and Classes (CLASSES)

See Understanding class loading for information about the parent-delegation model.

The classloader (CLASSES) section includes:

In this example, there are the standard three classloaders:

The example below shows this relationship. Take the application classloader with the full name sun/misc/Launcher$AppClassLoader. Under Classloader summaries, it has flags -----ta-, which show that the class loader is 6=trusted and 7=application (See the example for information on class loader flags). It gives the number of loaded classes (1) and the parent classloader as sun/misc/Launcher$ExtClassLoader.

Under the ClassLoader loaded classes heading, you can see that the application classloader has loaded three classes, one called Test at address 0x41E6CFE0.

In this example, the System class loader has loaded a large number of classes, which provide the basic set from which all applications derive.


------------------------------------------------------------------------
CLASSES subcomponent dump routine
=================================
Classloader summaries
        12345678: 1=primordial,2=extension,3=shareable,4=middleware,
                  5=system,6=trusted,7=application,8=delegating
        p---st--        Loader *System*(0x00439130)
                        Number of loaded classes 306
        -x--st--        Loader sun/misc/Launcher$ExtClassLoader(0x004799E8),
                        Parent *none*(0x00000000)
                        Number of loaded classes 0
        -----ta-        Loader sun/misc/Launcher$AppClassLoader(0x00484AD8),
                        Parent sun/misc/Launcher$ExtClassLoader(0x004799E8)
                        Number of loaded classes 1
ClassLoader loaded classes
Loader *System*(0x00439130)
  java/security/CodeSource(0x41DA00A8)
  java/security/PermissionCollection(0x41DA0690)
    << 301 classes removed for clarity >>
  java/util/AbstractMap(0x4155A8C0)
  java/io/OutputStream(0x4155ACB8)
  java/io/FilterOutputStream(0x4155AE70)
Loader sun/misc/Launcher$ExtClassLoader(0x004799E8)
Loader sun/misc/Launcher$AppClassLoader(0x00484AD8)
  Test(0x41E6CFE0)
  Test$DeadlockThread0(0x41E6D410)
  Test$DeadlockThread1(0x41E6D6E0)