Tracing Java execution using a Dynamic Proxy

In my previous post, I discussed five ways for tracing Java programs execution. Tracing execution can be done from a number of reasons. I focused on understanding the code. While it may be easy to read and understand a single method, understanding the whole flow may be a tough challenge. Since most design time tools fail to show a full end-to-end flow, tracing the program execution is the next best option.

I summarized my post with a conclusion that working with Aspects is the best option. I'm going to touch that in one of the next posts. In this post, I will introduce another approach: Dynamic Proxies. Although this method has its' limitations (see below), it is very easy to set-up and use.

What is a DynamicProxy?

DynamicProxy is a cool feature in Java. Most novice Java developers are not familiar with it. You can find the official tutorial here. I'll give a shorter one, focusing on tracing. The following diagram illustrates how it works:

• Step 1: Client invokes Method A, which is part of an interface.
• Step 2: The Dynamic Proxy intercepts the call, receives a call to a generic invoke method. This is the magic sauce.
• Step 3: The dynamic proxy invokes the original method using reflection, along with more logic, e.g. logging the call.
  

There are two supernatural phenomena here:

• You have a class which can take any shape - each instance of the class can decide, at runtime, which interfaces it will implement.
• When the instance receives a call through any of these interfaces, it will actually receive a call to one invoke method with all the relevant details: the method which was invoked and the arguments.

Other than the above, it's all plain Java code which you control.

There are some limitations to dynamic proxies, derived directly from the way they work:

• The invocations you're tracing must be part of an interface. If not, you'll need to extract the interface. Still, even if you do, it will only work for public methods invoked by outside callers.
• You should control the instantiation of the target class' instances. It should be intercepted and replaced with your own instances.

The Debug Proxy

Sun provides an example of tracing using dynamic proxy. I made some modifications to the code and I'm attaching my own version of a DebugProxy. The main limitation in the original code is that it proxies only the immediate interfaces implemented by the original class. If the class extends a super-class which implements an interface, this interface will not be "proxied" (is that a word?). I also made some more modifications:

• Used Apache commons logging to do the actual logging. The logging is done "on behalf" of the original class in trace level only.
• Logging all the method arguments using toString.
• Correctly throwing exceptions: will throw the original exception that occurred.
• Using Java 5 features (Generics, for each loops, etc.).

You can download the file here: DebugProxy.java.

Using the Debug Proxy

First, download the DebugProxy and install it in your project. You may need to fix the package definition. If you're not using Commons Logging, you may want to change that as well.

Next, change the instantiation on your class. Here's the example:

• Original code: MyInterface obj = new MyClass(...)
• New code: MyInterface obj = (MyInterface)DebugProxy.newInstance(new MyClass(...))

That's it. You're all set. Just execute the program and check the results in the log. After the first time, you will have your proxy in place and the whole process becomes even simpler.

Conclusion

Using a DynamicProxy to trace runtime execution has several advantages:

• It's very simple to set up. It's laser-targeted at the class which is interesting at the moment, ignoring the rest of the system.
• You control the code, hence, you have the ultimate control on the way the events are logged. You have all the information and you can log it in any way you see fit. You can even set up a breakpoint inside your debug proxy and intercept all the calls.
• Not much overhead on the system at runtime.

Of course, there are the limitations:

• The intercepted calls must be made through an interface.
• You need to control the instantiation of the original class.

Overall, it's great for specific cases, like understanding which events were received by an Event Handler and when. In the general case, you'll need to find another solution.

Comments

[WarpedJavaGuy]

I think this approach can be very useful for "once off" tracing and debugging purposes. But for cases where you really want to trace existing code "as is" (without controlling instantiation), then aspects will work better.

[Stas Ostapenko]

AOP is perfect for tracing. One can even trace some library with the help of load-time weaving. Here is my story :
http://ostas.blogspot.com/2007/12/tracing-myfaces-with-aspectj-tomcat-and.html

[Raj]

Can the proxy also log return values just like arguments, that can be useful.

Also I was wondering how we can hook up a proxy through a IOC container like GUICE or Spring

[Zviki Cohen]

Since the debug proxy is responsible for invoking the original method, there's no limitation on what you can do there. It's very simple to print the result of the method. Download and check out my code.

As for Spring or Guice. I'm using Spring. If you're using Spring correctly, this means you're using Interfaces as members and work with dependency injection. This is classic for a dynamic proxy. For a quick and temporary trace, you can specify a "factory bean/method" for your bean which will create a dynamic proxy around the original class. For a more complete solution, you can customize the global factory. I'm guessing Guice has something you can customize as well.