Who is calling this method?

Have you ever stood in front of a piece of code and wondered why it behaves the way it does. And wished you had the information about the possible locations from which this method was invocated. Back in the old times it might have been easy – static code analysis could have given you the answer. But nowadays when we have reflection and bytecode modification tooling at hand the answer is often not so simple.

Well, we have lived with the same problem for a long time. In Plumbr we are making your lives easier by surfacing the sources of the problems. As a sample – when you happen to have a memory leak in your application, we tell you where the leaking objects are created. Down to the line in source code where the object was created. But we have not been able to hand over the whole call stack so far – it is just too expensive to gather this information during the application runtime.

But there is a very nice tool available just for the task at hand called BTrace. This is a dynamic tracing tool which you can attach to your Java process during runtime to acquire a call stack and then disconnect when you have acquired the information you needed. Btrace dynamically instruments the class bytecode in the target application in order to inject tracing code. You can use the same tool for other amazing purposes, but for the sake of clarity, lets just stick with this feature.

Lets go through a case study using the very same leak report acquired from Plumbr demo application. From the leak report below, we can see that something fishy is happening at the line 27 in the LeakingInterceptor class preHandle() method.

When exploring the source code, we can see that a new ImageEntry instance is created in the line 27:

lastUsedImages.add(new ImageEntry(image));

To get the full stack trace of this situation, we have to give a hint to BTrace about what to monitor in our source code. We do this in a form a small Java class, which will print out the entire stack trace every time a new instance of ImageEntry is created. Code for this is rather straightforward as you see:

import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
class LeakStack {
   @OnMethod(clazz="org.springframework.samples.petclinic.web.ImageEntry", method="<init>")
   public void printStack() {
      Threads.jstack();
      println("");
   }
}

The printStack() function is executed every time when a new ImageEntry instance is created. The mapping is in the annotations which specify the class and the method to monitor. And as you might recall from your bytecode classes, “<init>” denotes the constructor.

Now, hopefully you have managed to download the BTrace and it’s time to start the demo application (run “start.sh” to start the application and “create_usage.sh” script to generate usage). After that we can find out the PID of our demo application with the help of “jps” command.

In order to run btrace executable (found in $BTRACE_ROOT/bin/ folder), we have to specify the PID of our application and our desired script.

$ ./btrace <PID_OF_DEMO_APP> LeakStack.java

After that, we should get stack traces printed out to our console similar to the following:

org.springframework.samples.petclinic.web.LeakingInterceptor.preHandle(LeakingInterceptor.java:27)
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:891)
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:827)
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:547)
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1359)
org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:483)
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:941)
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:409)
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:186)
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:875)
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250)
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
org.eclipse.jetty.server.Server.handle(Server.java:345)
org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:441)
org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:919)
org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:582)
org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:218)
org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:51)
org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:586)
org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:44)
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:598)
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:533)
java.lang.Thread.run(Thread.java:722)

And we have successfully acquired the full call stack from the running application. Those of you who are now confused and worried that running Plumbr is complex – dont stress yourself. Out of the thousands of leaks we have discovered, less than ten were complex enough to hunt down without the full call stack. Plus – our RnD is working to improve our solution to the extent where you do not need to go through such tricky exercises. They just need a bit more time. And maybe a little bit of inspiration as well.

If you managed to read past this last call stack, you are definitely going to enjoy our future posts. So subsribe to our RSS feed or follow us in Twitter and stay tuned.