Friday, May 23, 2014

MJStack -> MJProf

Two months ago I have started the MJStack project (see previous blog post). This project continues to evolve (I am getting help from anatmaor@github). As time passes   I have  realised  at some point that this is turning into a sampling profiler so I have decided to rename the project into mjprof.

So what is new ?

First of all data source concept. MJStack collected its data from standard input only. MJProf can   collect stack dumps via invocation of JStack, via JMX (including remote JMX), from standard input and directly from a file. Since mjprof is extensible via plugins you can add additional data sources.

In addition merging of stack traces (into profiles) can be done over time based on thread id.

This is a great leap forward. I will appreciate your feedback and contribution.
Stay tuned and
      fork me on github  https://github.com/lifey/mjprof


Saturday, March 1, 2014

MJStack- The Monadic JStack Analyzer

   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.
   Sounds like project lambda ? Well that is not a coincidence. I was inspired by the concept of functional programming streams closures and lambda expressions. You can take those monads and compose them as you wish.

   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 !