Understanding Java and native thread details

Java thread

A Java thread runs on a native thread, which means that two stack traces exist for each Java thread. The first stack trace shows the Java methods and the second stack trace shows the native functions. This example is an internal Java thread:

3XMTHREADINFO "Attach API wait loop" J9VMThread:0x23783D00, j9thread_t:0x026958F8, 
java/lang/Thread:0x027F0640, state:R, prio=10
3XMJAVALTHREAD (java/lang/Thread getId:0xB, isDaemon:true)
3XMTHREADINFO1 (native thread ID:0x15C, native priority:0xA, native policy:UNKNOWN)
3XMCPUTIME CPU usage total: 0.562500000 secs, user: 0.218750000 secs, system: 0.343750000 secs
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at com/ibm/tools/attach/javaSE/IPC.waitSemaphore(Native Method)
4XESTACKTRACE at com/ibm/tools/attach/javaSE/CommonDirectory.waitSemaphore(CommonDirectory.java:193)
4XESTACKTRACE at com/ibm/tools/attach/javaSE/AttachHandler$WaitLoop.waitForNotification(AttachHandler.java:337)
4XESTACKTRACE at com/ibm/tools/attach/javaSE/AttachHandler$WaitLoop.run(AttachHandler.java:415)
3XMTHREADINFO3 Native callstack:
4XENATIVESTACK ZwWaitForSingleObject+0x15 (0x7787F8B1 [ntdll+0x1f8b1])
4XENATIVESTACK WaitForSingleObjectEx+0x43 (0x75E11194 [kernel32+0x11194])
4XENATIVESTACK WaitForSingleObject+0x12 (0x75E11148 [kernel32+0x11148])
4XENATIVESTACK j9shsem_wait+0x94 (j9shsem.c:233, 0x7460C394 [J9PRT26+0xc394])
4XENATIVESTACK Java_com_ibm_tools_attach_javaSE_IPC_waitSemaphore+0x48 (attach.c:480, 0x6FA61E58 [jclse7b_26+0x1e58])
4XENATIVESTACK VMprJavaSendNative+0x504 (jnisend.asm:521, 0x709746D4 [j9vm26+0x246d4])
4XENATIVESTACK javaProtectedThreadProc+0x9d (vmthread.c:1868, 0x709A05BD [j9vm26+0x505bd])
4XENATIVESTACK j9sig_protect+0x44 (j9signal.c:150, 0x7460F0A4 [J9PRT26+0xf0a4])
4XENATIVESTACK javaThreadProc+0x39 (vmthread.c:298, 0x709A0F39 [j9vm26+0x50f39])
4XENATIVESTACK thread_wrapper+0xda (j9thread.c:1234, 0x7497464A [J9THR26+0x464a])
4XENATIVESTACK _endthread+0x48 (0x7454C55C [msvcr100+0x5c55c])
4XENATIVESTACK _endthread+0xe8 (0x7454C5FC [msvcr100+0x5c5fc])
4XENATIVESTACK BaseThreadInitThunk+0x12 (0x75E1339A [kernel32+0x1339a])
4XENATIVESTACK RtlInitializeExceptionChain+0x63 (0x77899EF2 [ntdll+0x39ef2])
4XENATIVESTACK RtlInitializeExceptionChain+0x36 (0x77899EC5 [ntdll+0x39ec5])

The Java stack trace includes information about locks that were taken within that stack by calls to synchronized methods or the use of the synchronized keyword.

After each stack frame in which one or more locks were taken, the Java stack trace might include extra lines that start with 5XESTACKTRACE. These lines show the locks that were taken in the method on the previous line in the trace. The lines also show a cumulative total of how many times the locks were taken within that stack at that point. This information is useful for determining the locks that are held by a thread, and when those locks will be released.

Java locks are reentrant; they can be entered more than once. Multiple occurrences of the synchronized keyword in a method might result in the same lock being entered more than once in that method. Because of this behavior, the entry counts might increase by more than one, between two method calls in the Java stack, and a lock might be entered at multiple positions in the stack. The lock is not released until the first entry, the one furthest down the stack, is released.

Java locks are released when the Object.wait() method is called. Therefore a record of a thread entering a lock in its stack does not guarantee that the thread still holds the lock. The thread might be waiting to be notified about the lock, or it might be blocked while attempting to reenter the lock after being notified. In particular, if another thread calls the Object.notifyAll() method, all threads that are waiting for that monitor must compete to reenter it, and some threads will become blocked. You can determine whether a thread is blocked or waiting on a lock by looking at the 3XMTHREADBLOCK line for that thread. For more information, see Blocked thread information. A thread that calls the Object.wait() method releases the lock only for the object that it called the Object.wait() method on. All other locks that the thread entered is still held by that thread.

4XESTACKTRACE at java/io/PrintStream.write(PrintStream.java:504(Compiled Code))
5XESTACKTRACE    (entered lock: java/io/PrintStream@0xA1960698, entry count: 3)
4XESTACKTRACE at sun/nio/cs/StreamEncoder.writeBytes(StreamEncoder.java:233(Compiled Code))
4XESTACKTRACE at sun/nio/cs/StreamEncoder.implFlushBuffer(StreamEncoder.java:303(Compiled Code))
4XESTACKTRACE at sun/nio/cs/StreamEncoder.flushBuffer(StreamEncoder.java:116(Compiled Code))
5XESTACKTRACE    (entered lock: java/io/OutputStreamWriter@0xA19612D8, entry count: 1)
4XESTACKTRACE at java/io/OutputStreamWriter.flushBuffer(OutputStreamWriter.java:203(Compiled Code))
4XESTACKTRACE at java/io/PrintStream.write(PrintStream.java:551(Compiled Code))
5XESTACKTRACE    (entered lock: java/io/PrintStream@0xA1960698, entry count: 2)
4XESTACKTRACE at java/io/PrintStream.print(PrintStream.java:693(Compiled Code))
4XESTACKTRACE at java/io/PrintStream.println(PrintStream.java:830(Compiled Code))
5XESTACKTRACE    (entered lock: java/io/PrintStream@0xA1960698, entry count: 1) 

Attached native thread

The attached native threads provide the same set of information as a Java and native thread pair, but do not have a Java stack trace. For example:

"JIT Compilation Thread" TID:0x01E92300, j9thread_t:0x00295780, state:CW, prio=10
            (native thread ID:0x3030, native priority:0xB, native policy:UNKNOWN)
           No Java callstack associated with this thread
           Native callstack:
               KiFastSystemCallRet+0x0 (0x7C82860C [ntdll+0x2860c])
               WaitForSingleObject+0x12 (0x77E61C8D [kernel32+0x21c8d])
               monitor_wait_original+0x5a0 (j9thread.c:3593, 0x7FFA49F0 [J9THR26+0x49f0])
               monitor_wait+0x5f (j9thread.c:3439, 0x7FFA443F [J9THR26+0x443f])
               j9thread_monitor_wait+0x14 (j9thread.c:3309, 0x7FFA4354 [J9THR26+0x4354])
               TR_J9Monitor::wait+0x13 (monitor.cpp:61, 0x009B5403 [j9jit26+0x585403])
               protectedCompilationThreadProc+0x2a4 (compilationthread.cpp:2063, 0x0043A284 
[j9jit26+0xa284])
               j9sig_protect+0x42 (j9signal.c:144, 0x7FE117B2 [J9PRT26+0x117b2])
               compilationThreadProc+0x123 (compilationthread.cpp:1996, 0x00439F93 [j9jit26+0x9f93])
               thread_wrapper+0x133 (j9thread.c:975, 0x7FFA1FE3 [J9THR26+0x1fe3])
               _threadstart+0x6c (thread.c:196, 0x7C34940F [msvcr71+0x940f])
               GetModuleHandleA+0xdf (0x77E6482F [kernel32+0x2482f])

Unattached native thread

The unattached native threads do not have meaningful names and provide only minimal information in addition to the stack trace, for example:

  Anonymous native thread
            (native thread ID:0x229C, native priority: 0x0, native policy:UNKNOWN)
           Native callstack:
               KiFastSystemCallRet+0x0 (0x7C82860C [ntdll+0x2860c])
               WaitForSingleObject+0x12 (0x77E61C8D [kernel32+0x21c8d])
               j9thread_sleep_interruptable+0x1a7 (j9thread.c:1475, 0x7FFA24C7 [J9THR26+0x24c7])
               samplerThreadProc+0x261 (hookedbythejit.cpp:3227, 0x00449C21 [j9jit26+0x19c21])
               thread_wrapper+0x133 (j9thread.c:975, 0x7FFA1FE3 [J9THR26+0x1fe3])
               _threadstart+0x6c (thread.c:196, 0x7C34940F [msvcr71+0x940f])
               GetModuleHandleA+0xdf (0x77E6482F [kernel32+0x2482f])