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.
Subscribe to:
Post Comments (Atom)
No comments:
Post a Comment