Showing posts with label Deadlock. Show all posts
Showing posts with label Deadlock. Show all posts

Monday, September 29, 2008

Analysing Thread dump

Once you get the thread dump, the actual story begins. Any body can get thread dump with one time learning but analyzing this dump is key skill to any performance engineer. Lets us go step by step on this.
Few things we need to know about the thread dump structure. Let us take a below example dump and start learning the structure.

NOTE: This structure and namings will differ from OS to OS and application vendor to vendor. But below description gives a clear idea about any dump.

1. Always the thread dump start by line "Full thread dump"

2. Dump contains current state of all the thread in the system. I have pasted just a part of thread dump below for explaining the structure.

First line contains:

Thread name - Thread name always starts with thread group it belong to and the number assigned to this thread. This name is very important. There will different thread groups in the system and each has its own usage. For a typical j2ee applications some of thread groups you can observe are HTTPThreadGroup, CacheCleaner, Worker,TaskManager,SystemThreadGroup, WorkExecutorWorkerThread,etc etc. Always find which thread group is actually executing your code. Basically find the group of your interest rather than wasting time in looking in to threads belonging to unwanted thread groups such as SystemThreadGroup, GC group, TaskManager etc etc. In the below example I have pasted the dump of 2 threads "10' and "11" which belongs to thread group HTTPThreadGroup.

Current priority of the thread - For below threads the priority is 1. Not much to learn here for now.

Thread ID - As name indicates, this is an unique ID given to the thread. Not much to learn here for now.

State of the thread - Currently it is runnable. Different states are runnable, waiting, blocked, idle, Object.wait(). This is very important for finding contention.You can clearly find that Thread 10 is in running state and Thread 11 is in waiting state.

From second line:

Tells in which method currently the thread is ( when the dump was took). The complete call stack to the current method is given.We can Observe that Thread 10 is currently executing ASN1Header.readBody() method and Thread 11 is waiting under method EBMSExchangePlugin.decodeIncomingMessage() method. So we have 2 thread where one is waiting and one is running.

The locks that thread has acquired if any, with complete details such as where it has acquired and the lock ID. In the below example you can observe that Thread 10 acquired a lock under EBMSExchangePlugin.decodeIncomingMessage() method. There will be a unique number for each lock. Now the lock number is 0x6dce17e0. If the thread is in waiting state then dump contains for which lock it is waiting and under which method it is waiting.You can see that Thread-11 is waiting for a lock under EBMSExchangePlugin.decodeIncomingMessage() method for lock number 0x6dce17e0.

"HTTPThreadGroup-10" prio=1 tid=0x5664d700 nid=0x218a runnable [55458000..5545919c] at com.phaos.ASN1.ASN1Header.readBody(Unknown Source) at com.phaos.ASN1.ASN1String.inputChunk(Unknown Source) at com.phaos.ASN1.ASN1String.input(Unknown Source) at com.phaos.ASN1.ASN1String.(Unknown Source) at com.phaos.ASN1.ASN1Utils.inputASN1Object(Unknown Source) at com.phaos.ASN1.ASN1Sequence.input(Unknown Source) at com.phaos.ASN1.ASN1Sequence.(Unknown Source) at com.phaos.ASN1.ASN1Utils.inputASN1Object(Unknown Source) at com.phaos.ASN1.ASN1Set.input(Unknown Source) at com.phaos.ASN1.ASN1Set.(Unknown Source) at com.phaos.ASN1.ASN1Utils.inputASN1Object(Unknown Source) at com.phaos.ASN1.ASN1Sequence.input(Unknown Source) at com.phaos.ASN1.ASN1Sequence.(Unknown Source) at com.phaos.ASN1.ASN1Utils.inputASN1Object(Unknown Source) at com.phaos.ASN1.ASN1Sequence.input(Unknown Source) at com.phaos.ASN1.ASN1Sequence.(Unknown Source) at com.phaos.cert.X509.input(Unknown Source) at com.phaos.cert.X509.(Unknown Source) at com.phaos.cert.X509.(Unknown Source) at com.phaos.xml.keys.X509Data.getCertificates(Unknown Source) at com.phaos.xml.keys.retrieval.KeyInfoTool.getCertFromX509Data(Unknown Source) at com.phaos.xml.keys.retrieval.KeyInfoTool.retrievePublicKey(Unknown Source) at com.phaos.xml.keys.retrieval.KeyRetriever.retrievePublicKey(Unknown Source) at com.phaos.xml.keys.retrieval.KeyRetriever.getPublicKey(Unknown Source) at com.phaos.xml.dsig.XSSignature.verify(Unknown Source) at com.phaos.xml.dsig.XSSignature.verify(Unknown Source) at oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin.verifySig(EBMSExchangePlugin.java:6714) at oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin.verifyAck(EBMSExchangePlugin.java:5446) at oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin.decryptAndVerify(EBMSExchangePlugin.java:6209) at oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin.decodeIncomingMessage(EBMSExchangePlugin.java:586) - locked <0x6dce17e0> (a oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin) at oracle.tip.adapter.b2b.engine.Engine.processIncomingMessage(Engine.java:1374) at oracle.tip.adapter.b2b.engine.Engine.incomingContinueProcess(Engine.java:2415) at oracle.tip.adapter.b2b.engine.Engine.handleMessageEvent(Engine.java:2314) at oracle.tip.adapter.b2b.engine.Engine.processEvents(Engine.java:2269) at oracle.tip.adapter.b2b.data.MsgListener.onMessage(MsgListener.java:524) at oracle.tip.adapter.b2b.data.MsgListener.run(MsgListener.java:369) at java.lang.Thread.run(Thread.java:534) "HTTPThreadGroup-11" prio=1 tid=0x5664f808 nid=0x218a waiting for monitor entry [553d7000..553d819c] at oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin.decodeIncomingMessage(EBMSExchangePlugin.java:506) - waiting to lock <0x6dce17e0> (a oracle.tip.adapter.b2b.exchange.ebms.EBMSExchangePlugin) at oracle.tip.adapter.b2b.engine.Engine.processIncomingMessage(Engine.java:1374) at oracle.tip.adapter.b2b.engine.Engine.incomingContinueProcess(Engine.java:2415) at oracle.tip.adapter.b2b.engine.Engine.handleMessageEvent(Engine.java:2314) at oracle.tip.adapter.b2b.engine.Engine.processEvents(Engine.java:2269) at oracle.tip.adapter.b2b.data.MsgListener.onMessage(MsgListener.java:524) at oracle.tip.adapter.b2b.data.MsgListener.run(MsgListener.java:369) at java.lang.Thread.run(Thread.java:534)

Final Thumb rule For thread dump analysis:

NOTE: Always take 5 dumps with the delay of 1 sec. This is what I follow, you can get any number of dumps.

Step-1: Find all Threads (which belongs only to the group of your interest) which are in waiting state. Get the lock numbers on which they waiting.

Step-2: Find all threads which hold this lock. Just by doing a search for that lock number.

When to declare the lock contention....

1. If you observe more than one thread waiting for a lock and if that lock is held by some thread.

2. If you observe more than one thread waiting for a lock and even if you don't find the thread which is holding it.

3. If a thread is waiting for lock for too long (means, if you see the same thread is waiting for that lock in more than 2 dumps)

When you declare the Deadlock....

If you observe a chain lock. Read the above definition of deadlock in "Getting Thread dump Article" . You will understand it...

Final Note:

Every lock contention you find may not be solved. Some times the functionality itself may required to use these locks. So your analysis is key to refine the code. You can use this analysis and try to find the alternative ways to implement the same functionality with out using locks.
You can use so many third party free tools in analyzing these thread dumps. I have posted a blog for some of the best used tools. Have a look.

Tuesday, August 5, 2008

How to Get Thread dump?

Our Agenda will be like this...

  • Some Basic Jargons.

  • What is Thread dump and use of it?

  • How can I get Thread dump?

  • How to Analyse it?

Jargons:
Some of the Jorgan's before going to the details..

Thread: It is very important to know what thread means before going to this topic. According to text book, thread can be loosely defined as a separate stream of execution that takes place simultaneously with and independently of everything else that might be happening. Just leave it if you don't understand :)

Multi threaded application/process: An process may run as single thread or with multiple threads. For example Oracle DB runs as different processes. Each process can contain single or many threads. If a process run with many threads then we call it as multi threaded process. Generally using multi threads will help us to use the processor resource effectively. For example if your system has 4 processors and if your app is single threaded then at any point of time only one CPU(processor) will be used, rest all 3 will be in idle. So we are wasting the resources. If we redesign the app to make work with 4 threads then you will be using all the CPUs effectively.
Many of the applications that we are using will give an option to the user itself to tell how many threads that the process can use. The best example will be the application servers. For almost all the application servers, we can decide how many threads should it run with.


What is Thread dump?

Thread dump contains the complete list of threads details. These details includes...


  • The Thread number or name.

  • Thread state - running,waiting,blocked,idle etc

  • Locks that it is holding and method under which this lock is holding.

  • Method name which the thread is currently executing.

The structure of this thread dump differs from OS to OS and also application to application. As said above this dump is used to find mainly the lock contention and dead locks.

Lock Contention: In Simple words, if a thread is holding a lock for long time and another thread is waiting for this lock to get released then we call it as lock contention.

Deadlock: This is some thing father of Lock contention :) For example consider t1 is holding a lock for which t2 is waiting. And t2 is holding a lock for which t3 is waiting, and t3 is holding a lock for which t1 is waiting. Can you observe a chain over there. Now all 3 threads are waiting for a lock which is held by other thread and hence this state remains as it is for ever. Once the system comes to this state, everything will get stuck and application comes to an deadend. This is deadlock.

How can I get Thread dump?

I always work for Java/j2ee applications and hence let us see how thread dump is captured for JRocket JVM and Sun JVM.

NOTE: Important thing to be noted is, if you want to take a thread dump for a java process then make sure you don't use "-Xrs" in your JVM options.

BEA JRocket JVM:

JRocket JVM comes with an inbuild management console where an option is provided to get a thread dump. Even it gives all the thread locks and deadlocks in that dump at the end of display. Below is the exact process...

For detailed explaination of BEA Jrocket management console goto:

http://edocs.bea.com/jrockit/tools/usingjmc/start.html

Steps:
  • Start your JVM with -Xmanagement -Djrockit.managementserver.port=un-used port
Example: java -Xmanagement -Djrockit.managementserver.port=8989 testApplication
  • Start the JRocket Console using below command. This will open a console as displayed below
java -jar /console/ManagementConsole.jar


  • Click on connect and give necessary details and get connected to the JVM first.
  • Now you get the thread dump by clicking View --> "View Thread stack dump".
Now you will get the complete thread dump in a separate window which you can copy paste to a notepad.

As said earlier the beauty of this tools is, it will analyze the thread dump and gives the current lock contentions and deadlocks automatically with out breaking your head. The contention details that it gives is the max you can analyze even if you analyze manually.

Sun JVM:

If you are using jdk1.6 and above, then you are lucky enough to get dumps in faster way as below

  • Set the jdk's bin path to PATH variable.
  • Get the PID using command "jps".
  • And run " jstack -l PID"
  • Evan you can forward the dump to a file as "jstack -l PID > FileName"
If you are using Sun JVM ( less than jdk 1.6) then you need to send Signal QUIT to the jvm process so that it will print the thread dump.

  • Windows OS and process is running in console mode in command prompt.
In this case, just press "Ctrl+Break" in the process console. Then the complete thread dump is printed in the console log itself.
  • Windows OS and process is running as service
If the OS is windows and process is running as service we don't have the console where we can press Ctrl+Break. Follow below steps....
sendSignal pid

This will print the thread dump in your application related logs. For example if you are using Oracle application server then the log will be printed in opmn.log. Just check all the logs where all the general errors are printed.

  • Unix Operating system.

If you are using Unix or Linux then the process is very simple. Just find the process id by using "ps -ef" command and execute below command

kill -3 pid

In this case also the thread dump is printed under the standard logging files.

Analysing thread dump is a simple yet power full in fidning many performance bottlenecks. Please find my another posting on thread dump anlaysis...