Metrics Everywhere

Performance metrics of a system are rarely useful without looking at trends. Trends are generally unavailable unless you already knew what to look for before you needed it. I like to try to shotgun performance counters all over the system in the hopes that enough information will be gathered to at least let us know when things may not be going as well as we'd like.

Historically, I've done this by creating counter objects, fetching them by name, and feeding them new data as things happen. This works pretty well, but you have to do it all over the place. It's messy and redundant.

In our new project, we're using aspectj, so I thought I'd so something a little more simple.

It started with an annotation: @TimedMethod. I can stick that on top of any method I want to time. For example:

  @TimedMethod("junk.slowmethod")
  public int someSlowMethod(Object arg1, String arg2)
      throws Exception {
    [...]
  }

Now, all I had to do was write an aspect that would intercept any call to a method that has that annotation and time it. The basic recipe looks like this:

  pointcut timedMethod(): execution(@TimedMethod * *(..));

  Object around(): timedMethod() {
    MethodSignature ms=thisJoinPointStaticPart.getSignature();
    Method m=ms.getMethod();
    TimedMethod tm=m.getAnnotation(TimedMethod.class);

    boolean success=false;
    long start=System.currentTimeMillis();
    try {
      Object rv=proceed();
      success=true;
      return rv;
    } finally {
      long end=System.currentTimeMillis();
      ComputingStat stat=Stats.getComputingStat(
        tm.value() + (success?".success":"fail"));
      stat.add(end-start);
    }
  } 

That covers almost all cases. There were still the times when the stat name needs to be computed based on additional information. For that, I created a sort of StatNameFormatter whose implementations could be referenced in the annotation to allow specific stat producers to provide further informaton. For example, the bulk of our DAO stuff is implemented in a base class, however, I want to track stats for these things separately. All I need is a formatter implementation that knows how to get this additional information.

Note that I'm using the joinpoint to get to the method to get to the annotation in the advice above. I should be able have the pointcut include it with @annotation(TimedMethod). While that works in eclipse, it blows up the aspectj compiler. The difference is minor, so I can move on.

For reading them back, I just have a simple servlet that finds all stats and prints them out. Now I just need to revitalize visualstatwatch.