I recently went about creating my own “interceptor” solution, outside of the normal AspectJ, AspectWerkz, or Spring AOP solution. I realize that it sounds like maybe I am suffering from the “Not written here” complex, but I did not want to have to introduce a whole new package/technology into our codebase. We are not using Spring, and probably won’t any time soon. Also, I really did not feel that I needed to bring in AspectJ, etc. just to solve a simple problem. Besides, I just wanted to go about designing something.
It started because recently I have been tackling a few issues with queries in our application. It started with some queries taking a long time, close to 30 (yes, thirty) seconds to complete. The code that I am looking through uses Hibernate, but basically as a way to not use JDBC. Nearly every query is written as a prepared statement in the code, and there are hundreds of queries. Each query typically has its own method, which handles all of the transaction management and caching.
Quickly, let me point out that I realize this is foolish at best, with terrible being a more realistic adjective. Firstly, all that transaction code is repeated throughout the entire service level, it’s not even refactored out into a method. Secondly, the caching/retrieving is done manually in some methods rather than use Hibernate’s caching. Even more interesting, EHCache is used as the cache. So to be clear, the code basically uses Hibernate to avoid ResultSet manipulation.
Initially, my task was to find the slow queries. However, the poor response times could only be reproduce in the production environment; not an ideal place for debugging. I figured that slow queries would still be slow in dev or in QA, just on a much smaller magnitude. If I could time every query in dev and QA, I could identify the relatively slow queries. These would be the queries that I would optimize first, most likely with some caching. Furthermore, this would provide an audit of every query call in the system.
Ideally, I would just wrap up every service-level object with a performance tracking interceptor in my Spring configuration, but Spring was not an option. So, I could go through the code and add timestamps before and after each query call, adding to the transaction and caching code. Or, I could figure out a way to intercept each method invocation and perform the timestamp logic. As you can imagine, intercepting made the most sense to me.
It is interesting to note here that this seems to me the only solution, but I realize that others may not see it this way. They may see this as overkill and a waste of time. Why not simply add the necessary code through copy/paste, throw it into QA and roll it back when the results are obtained. And I have to admit, this probably would save time and be just as effective. However, it also seems sloppy and error-prone. Also, I was thinking bigger-picture; adding the transaction management and cache management into the interceptor.
Back to aspects. Java 1.3 included the Proxy class in the reflection package. This class provides a way to dynamically create proxies of interfaces with an InvocationHandler. At runtime, rather than call the actual method of the proxied class, the “invoke” method of the handler is called. In essence, this allows the developer to “intercept” the method invocation and do as they please. The only condition is that the class to be proxied must implement at least one interface, and only the methods defined in the interface can be “intercepted”. Fortunately for me, the code I was working with had the service level properly defined through interfaces.
So the solution was beginning to take shape. I simply need to create a proxy for each service level object with a handler for tracking the elapsed time between the method invocation and the method return. So, the handler would look something like this:
public class MyInvocationHandler implements InvocationHandler {
private Object target;
public MyInvocationHandler(Object target) {
this.target = target;
}
public Object invoke(Object proxy, Method method, Object[] parameters) throws Throwable {
Object o = null;
try {
long start = System.currentTimeMillis();
o = method.invoke(target, parameters);
System.out.println(method.getName() + " - " + (System.currentTimeMillis() - start));
} catch (InvocationTargetException ite) {
throw ite.getCause();
}
return o;
}
}
This is obviously a very simple example (and I apologize for the lack of formatting). The invoke method is called in place of the method on the proxied object; "target". In reality, we would not want to write out to the System, but this is just a simple example.
To set this up, the following code is needed when the “target” is instantiated.
Foo target = new FooImpl();
MyInvocationHandler handler = new MyInvocationHandler(target);
Foo proxy = (Foo) Proxy.newProxyInstance(target.getClass().getClassLoader(), new Class[] { Foo.class }, handler);
Simple enough, isn’t it? Now, the target is actually an instance of “FooImpl” and the proxy is actually an instance of “Proxy”. However, the proxy instance will actually be treated by the runtime environment as an instance of “Foo”. Any instanceof, casts and other type comparisons will properly evaluate just as if a non-proxied instance of “Foo” was used. However, it is important to note that the proxy is not viewed as an instance of “FooImpl”.
The handler code can be improved significantly; for instance rather than writing to System.out, the handler could write to a file or database. The results could be filtered to ignore results that fall under a specified threshold. I actually did both of these and found the problem queries.
Another thing to keep in mind is that the entire call stack can be examined and reported. Not only do you have the immediate method call and target, but the class and method (and line number) of the caller can be determined with:
new Throwable().fillInStackTrace().getStackTrace();
I am going to end things here for now. As you can see, with very little code we have provided ourselves with some pretty useful information without incorporating any new technologies or cutting and pasting. However, we can still do more. We can link multiple interceptors and specify which methods we wish to intercept. That will be part 2.
Also, please feel free to comment or ask questions.
