MethodCallSpy – building own method tracing Java Agent with AspectJ

I have just released – MethodCallSpy – a simple JVM method tracing agent. This article and the released source code is to help anyone in how to modify existing Java program behaviour in runtime. Let's use method tracing as a good example of practical application.

Its not only a good demonstration of what AOP can do for you, but this tool was really used in production. We used tool similar to MethodCallSpy to trace classes that are still in practical use in a legacy applications, to detect and eventually remove unused code to slash maintenance costs.

There are better tools do exist. Professional, commercial ones, notably YourKit. But it is an overkill for a once off usage, for task I described above. I could not quickly find any suitable free tool so I wrote my own.

MethodCallSpy goes in two flavours. The first is mainly for demonstration purposes, an intermediate step in the development of more realistically usable tool. The second instalment is such tool. The MethodCallSpy0 may serve as a good base for your experiments with Aspect programming. It simply prints every traced method to console. The MethodCallSpy is sophisticated, multi threaded application with simple socket base IPC, listening to remote commands, gathering and aggregating tracing data.

Links to source codes:
https://bitbucket.org/espinosa/methodcallspy
https://bitbucket.org/espinosa/methodcallspy0

You can trace not only Java programs, but practically any JVM application, originally written in Groovy, Scala or JRuby. It does not guarantees the result will be usable in all scenarios. We have tested it on Groovy server based application, running on Tomcat, and it captured what we wanted.

MethodCallSpy0

Let's first look at the simpler variant. When MathodCallSpy0 runs with application as a Java agent it simply prints all methods and classes used to standard output. It is a Maven project, it takes care of all dependencies transparently. Run time modification of target application is done with AspectJ framework and its Load Time Weaver.

How to run and what is supposed to do is clear from the integration test – TraceAllAgentTest – but let's describe it also here.

How to run with your application:
java -cp <classpath> -javaagent:<full path to AspectJ library> targetAppClass

The classpath must include target application JAR and its libraries indeed, besides that AspectJ libraries, agent classes like TraceAllAgent.class, and AOP configuration file – aop.xml. The configuration file must be inside META-INF directory, top level directory. Ideally agent classes, like TraceAllAgent.class, should be ideally packed with the aop.xml in one jar.

But first of all, specify in aop.xml what packages to trace. What packages from the target application should be intercepted, or advised in AOP terminology. Change the <include within="my.home.sampleapplication..*" /> to something meaningful for you application. The double dot. This is crucial, it recursively include also all sub packages. Or use all inclusive <include within="*" /> but use it with care.

The intended output is trace print of all public methods and may look like:
>>> called class: my.home.sampleapplication.SampleApp method: main(..)
>>> called class: my.home.sampleapplication.SampleApp constructor
>>> called class: my.home.sampleapplication.SampleApp method: somePublicMethod(..)

All messages generated by the trace agent are simply prefixed with >>> just to distinguish agent output from general application output. There is a stream filtering utility in the test intended to capture just the agent output. See Utils.filterLinesStartingWith() method.

And that is all what MethodCallSpy0 can do for you. It starts with application, it ends with application. It traces all packages classes and methods from packages listed in aop.xml.

Tests

The behaviour of MethodCallSpy0 is well demonstrated in the integration tests. It is a proper end to end test with a sample application being advised in runtime, using a forked JVM process and LTW (Load Time Weaving). Modified behaviour tested is on redirected output from application, filtered and searched for tracing agent messages. For simplicity all trace agent output is prefixed with >>>.

Relevant parts:

ProcessBuilder pb = new ProcessBuilder(

  "java",

  "-cp", classpath,

  "-javaagent:"+aspectjWeaverJarFullPath,

SampleApp.class.getName());

pb.redirectErrorStream(true);

Process p = pb.start();

String result = Utils.dumpProcessOutputToString(p.getInputStream());

int exitValue = p.waitFor();

Assert.assertEquals(0, exitValue);

Assert.assertEquals("" +

  ">>> called class: my.home.sampleapplication.SampleApp method: main(..)\n" +

  ">>> called class: my.home.sampleapplication.SampleApp constructor",
  Utils.filterLinesStartingWith(">>>", result));

There should be no output from the test itself. The whole captured output however is reprinted at the end of the test to a logger. To see this run the test with system parameter -Djava.util.logging.ConsoleHandler.level=FINE. There may be some logging messages from AspectJ weaving process of interest.

The output is logged using plain Java logging framework – java.util.logging. It is very limited in its abilities compared to Log4j or Slf4j. But it perfectly matches needs for this test and does not require any external library.

What is Java Agent?

The runtime modification of target application is no hacking. Java from version 1.4 provides instrumentation service, package java.lang.instrument. It officially enables agents to modify any program running on JVM. Java Agents are (usually) small programs written (usually) in Java itself (or any JVM based language) to modify behaviour of another Java (Scala, Groovy) program.

Java Agent does not necessary has to do anything with AOP, Java Agent enables AOP's load time weaving to happen. Also, not all AOP systems use or even supports run time modification of target code.

MethodSpyCall, or TraceAllAgent class, is not, technically speaking, the Java Agent. AspectJ framework is the agent. It does all the byte code manipulation. MethodCallSpy is just a hosted.

Configuration file – aop.xml

The real Java Agent is the AspectJ library. The aop.xml configuration file is the connecting link between them. MethodCallSpy's TraceAllAgent class is defined here as Aspect. This class will be scanned for aspect defining annotations. Aspect class TraceAllAgent must be annotated with @Aspect.

The configuration file also restricts what packages to be changed in runtime to what aspect defines internally with its @Pointcut annotated methods. Only those packages defined here will be affected.

The aop.xml must be in the top level META-INF directory on the classpath. You have to explicitly specify what packages to trace. Or you can make it all inclusive, but use it with care, all core Java classes will be traced too, all eventual libraries.

Agent class (package) has to be part of the included classes! otherwise you get Stack Overflow in an infinite loop. It has to be excluded by cross-cutting definition in the code.

Inclusions are not recursive by default. To include sub packages use double dot and star notation. It is same with pointcut defining rules in Java code too.

What is AspectJ? Why AOP?

The runtime code modification is done through instrumentation and class byte code manipulation. Using it directly is tedious, challenging business, it requires great insight into most intimate parts of class structure. AspectJ shields users from this complexities, enabling developer to define modifications in more friendly AOP instruments – aspects, pointcuts and advices – defining what to do before, after or instead of a specified methods, or similar blocks of code. This is limiting, but usually fully satisfy common needs for runtime program modification like tracing, monitoring, debugging, performance measurement or test code coverage.

To be continued..

In the next article we look at the more advanced variant – MethodCallSpy – and some technical details.