My First AspectJ Experience
At my job one of my tasks is to write a GUI to do the editing of some rather complex configurations. So naturally I had written up my own meta data to do this (more later). One of the problem I had was that on some of the screens the code I had written to do the layout were sucking up a lot of time just to do the layout of what should be some eimple pages (and even longer for some pages that were not so simple). While at the same time some of the larger pages were just fine.
So how does one go about debugging this? I suppose I could sync up
the model in UML and look at the collaboration diagrams, the problem is when
you get much past the high level operations UML begins to look like a first
gade scribble fest, and that is before you turn on the auto-formatting. (Perhaps
a subject for another future entry about how some things should be left out
of UML diagrams because they just clutter things up). I guess since
I wrote this code I should know what was wrong. But let's face it,
nobody outside of training exercises intentionally writes O(exp) code (which
is what it was behaving like).
As it turned out about two weeks earlier I had picked up a book Aspect
Oriented Programming with AspectJ while my wife and I were killing time
before a Friday Night Movie. So I decided to try applying the profiling
aspect to my layout code (but totally hacked up to get the stats I needed).
All I have to say is that it was incredably cool. To get the sort
of stats I was getting confirmed that it was exponential process: one method
was being called 2 million times on my CPU killer test, 16K, 33K and 66K
on my check it at each step test as well. Almost a perfect 2^n cost
of computing. But what schocked me was what was causing those huge
jumps... a property listener. I was re-calculating parts of the layout
in response to the addition of a layout element, which was causing other
items of the tree to be re-calulated for each addition. Being basically
a binary tree the size growth makes sence as I add one more item. Without
this knowledge I would in all likelyhood be re-writing that code today.
So anyway what I thought was the coolest was that all of this diagnostic
code was dropped at every method invocation in my select classes for the areas
I was worried about. It truly was a seperation of concern because I
usually do not care how often a method is called or how long it takes.
But when I care I really care. And applying a 30
line aspect to 15 some odd classes and loading it into MS Access so I can
do some SQL queries is a whole lot easier than insturmenting it by hand.