When you come to debug a JVM in production(or in a performance lab) one of the available techinques is to grab a thread dump using either a JMX or the jstack command line tool. Sometimes it is all you have, thats why it is called the 'poor man's profiler'. JDK (1.6 and up) includes the jstack command line tool. In order to use it you need to discover the relevant process id by using either ps (UNIX) / task manager (Windows) or by using jps which is another command line tool found in the jdk. Usually you will execute the following command:
jstack -l {your process i} > stacktrace.txt
This will create a file with stack traces for all the thread in the process. If you run your JVM in UNIX you need to make sure that you are using the same user (or root). In Windows you will need to make sure you are running on the same session as well.
The stacktrace.txt contains a short header and a per thread section. For each thread we will have some information: Thread name, priority, thread id, native thread id, status, state, stacktrace and "locked ownable synchronizers" (java.util.concurrent ReentrantLocks which the thread is locking)
Following an example for a thread which is named ISCREAM3 and is currently sleeping.
"ISCREAM3" prio=5 tid=0x00007fd48a9b2800 nid=0x9203 waiting on condition [0x000000010ddec000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.rest(Sleeper.java:44)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.singleCycle(Sleeper.java:23)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.ExceptionThrower.singleCycle(ExceptionThrower.java:19)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:30)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.loopForever(Sleeper.java:37)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.run(Sleeper.java:51)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Recurse.doRecursion(Recurse.java:25)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Recurse.doRecursion(Recurse.java:25)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Recurse.singleCycle(Recurse.java:16)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.longerStackTrace(Sleeper.java:32)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.loopForever(Sleeper.java:37)
at com.performizeit.jpo.ex.cpuprofile.threadClasses.Sleeper.run(Sleeper.java:51)
at java.lang.Thread.run(Thread.java:744)
Locked ownable synchronizers:
- None
This is really cool, you take a quick glance and you are able to see what the thread is doing. The problem starts when you come to analyze real applications. These application are huge and may have hundreds of such threads (and from time to time even thousands) with long stacktraces so you will probably need to read through a file with tens of thousands of lines.
Thats where mjstack gets into the picture. It enables you to transform the thread dump into something that may be useful to you. It does not have a fancy UI, as a matter of fact it has no user interface at all. The way to work with it, is to compose several small steps that let you focus on what you really want. With this tool you are able to filter out threads, sort them, eliminate some of the data in them and group them by certain attribute.
Each such step will be called a monad and there three kind of such monads:
- Filters - filters out certain threads
- Mappers - Change thread info
- Terminals - performs final transformation and subsequent monads can't be applied after it.
The argument passed to mjstack are a list of monads seperated by period(.) each one of them contains a list of arguments inside two slashes (//) seperated by a comma (,).
For example the monad contains/name,mythread/ will filter out any thread which its name does not contain the string "mythread". The terminal group/state/ will create a histogram of different states. We can also combine them together contains/name,mythread/.group/state/ this will histogram by state only the threads with name that contains mythread
Lets see some examples:
1. Focus on runnable threads:
cat stacktrace.txt | ./mjs.sh contains/state,RUNNABLE/
2. Show only the names of the runnable threads
cat stacktrace.txt | ./mjs.sh contains/state,RUNNABLE/.group/name/
3. Focus on the threads which belong to your ISCREAM thread pool and group them by state:
cat stacktrace.txt | ./mjs.sh contains/name,ISCREAM/.group/state/
4. Look for threads that actually run your application code
cat stacktrace.txt | ./mjs.sh contains/stack,myconpany/
4. Look for threads that actually run your application code and take only the 5 topmost stack-frames:
cat stacktrace.txt | ./mjs.sh contains/stack,myconpany/.keeptop/5/
And so much more ! You have great power in your hands since you can compose monads as you like.
If you reached to this point and still interested, don't hesitate the project is open source and you can download it from :
Disclaimer: This is an initial version so it may contain bugs and it was not optimized yet. I would love to get feedback.
Enjoy !
No comments:
Post a Comment