How to analyze Thread Dump – Part 5: Thread Stack Trace

This article is part 5 of our Thread Dump analysis series. So far you have learned the basic principles of threads and their interactions with your Java EE container & JVM. You have also learned different Thread Dump formats for HotSpot and IBM Java VM’s. It is now time for you to deep dive into the analysis process.

** UPDATE: Thread Dump analysis tutorial videos now available here.

In order for you to quickly identify a problem pattern from a Thread Dump, you first need to understand how to read a Thread Stack Trace and how to get the “story” right. This means that if I ask you to tell me what the Thread #38 is doing; you should be able to precisely answer; including if Thread Stack Trace is showing a healthy (normal) vs. hang condition.

Java Stack Trace revisited

Most of you are familiar with Java stack traces. This is typical data that we find from server and application log files when a Java Exception is thrown. In this context, a Java stack trace is giving us the code execution path of the Thread that triggered the Java Exception such as a java.lang.NoClassDefFoundError, java.lang.NullPpointerException etc. Such code execution path allows us to see the different layers of code that ultimately lead to the Java Exception.

Java stack traces must always be read from bottom-up:

-        The line at the bottom will expose the originator of the request such as a Java / Java EE container Thread.

-        The first line at the top of the stack trace will show you the Java class where that last Exception got triggered.

Let’s go through this process via a simple example. We created a sample Java program simply executing some Class methods calls and throwing an Exception. The program output generated is as per below:

JavaStrackTraceSimulator

Author: Pierre-Hugues Charbonneau

http://javaeesupportpatterns.blogspot.com

Exception in thread "main" java.lang.IllegalArgumentException:

        at org.ph.javaee.training.td.Class2.call(Class2.java:12)

        at org.ph.javaee.training.td.Class1.call(Class1.java:14)

        at org.ph.javaee.training.td.JavaSTSimulator.main(JavaSTSimulator.java:20)

-        Java program JavaSTSimulator is invoked (via the “main” Thread)

-        The simulator then invokes method call() from Class1

-        Class1 method call() then invokes Class2 method call()

-        Class2 method call()throws a Java Exception: java.lang.IllegalArgumentException

-        The Java Exception is then displayed in the log / standard output

As you can see, the code execution path that lead to this Exception is always displayed from bottom-up.

The above analysis process should be well known for any Java programmer. What you will see next is that the Thread Dump Thread stack trace analysis process is very similar to above Java stack trace analysis.

Thread Dump: Thread Stack Trace analysis

Thread Dump generated from the JVM provides you with a code level execution snapshot of all the “created” Threads of the entire JVM process. Created Threads does not mean that all these Threads are actually doing something. In a typical Thread Dump snapshot generated from a Java EE container JVM:

-        Some Threads could be performing raw computing tasks such as XML parsing, IO / disk access etc.

-        Some Threads could be waiting for some blocking IO calls such as a remote Web Service call, a DB / JDBC query etc.

-        Some Threads could be involved in garbage collection at that time e.g. GC Threads

-        Some Threads will be waiting for some work to do (Threads not doing any work typically go in wait() state)

-        Some Threads could be waiting for some other Threads work to complete e.g. Threads waiting to acquire a monitor lock (synchronized block{}) on some objects

I will get back to the above with more diagrams in my next article but for now let’s focus on the stack trace analysis process. Your next task is to be able to read a Thread stack trace and understand what it is doing, on the best of your knowledge.

A Thread stack trace provides you with a snapshot of its current execution. The first line typically includes native information of the Thread such as its name, state, address etc. The current execution stack trace has to be read from bottom-up. Please follow the analysis process below. The more experience you get with Thread Dump analysis, the faster you will able to read and identify very quickly the work performed by each Thread:

-        Start to read the Thread stack trace from the bottom

-        First, identify the originator (Java EE container Thread, custom Thread ,GC Thread, JVM internal Thread, standalone Java program “main” Thread etc.)

-        The next step is to identify the type of request the Thread is executing (WebApp, Web Service, JMS, Remote EJB (RMI), internal Java EE container etc.)

-        The next step is to identify form the execution stack trace your application module(s) involved e.g. the actual core work the Thread is trying to perform. The complexity of analysis will depend of the layers of abstraction of your middleware environment and application

-        The next step is to look at the last ~10-20 lines prior to the first line. Identify the protocol or work the Thread is involved with e.g. HTTP call, Socket communication, JDBC or raw computing tasks such as disk access, class loading etc.

-        The next step is to look at the first line. The first line usually tells a LOT on the Thread state since it is the current piece of code executed at the time you took the snapshot

-        The combination of the last 2 steps is what will give you the core of information to conclude of what work and / or hanging condition the Thread is involved with

Now find below a visual breakdown of the above steps using a real example of a Thread Dump Thread stack trace captured from a JBoss 5 production environment. In this example, many Threads were showing a similar problem pattern of excessive IO when creating new instances of JAX-WS Service instances.

As you can see, the last 10 lines along with the first line will tell us what hanging or slow condition the Thread is involved with, if any. The lines from the bottom will give us detail of the originator and type of request.

I hope this article has helped you understand the importance of proper Thread stack trace analysis. I will get back with much more Thread stack trace examples when we cover the most common Thread Dump problem patterns in future articles. The next article will now teach you how to breakdown the Thread Dump threads in logical silos and come up with a potential list of root cause “suspects”.

Please feel free to post any comment and question.

Posted in: Java,Thread Dump