Monday, September 29, 2008
Analysing Thread dump
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?
- 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
- Start the JRocket Console using below command. This will open a console as displayed below
/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".
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"
- Windows OS and process is running in console mode in command prompt.
- Windows OS and process is running as service
- Download Sendsignal.exe from http://www.latenighthacking.com/projects/2003/sendSignal
- Find the process ID of your process. You can get this from task manager.
- Goto command prompt and execute below command...
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
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...
