Don't let these ThreadLocals escape

A while ago I wrote about ThreadLocals and how useful and tricky they can be. In that blog post, I also wrote that it was a good practice to clean up your ThreadLocals so that, if the Thread was reused, it would not have access to the previous values. The recommended way to do this for a web application was to use a ServletFilter.

After running this setup for a while, I also have to add that you really have to know all the entry points into your application in order to achieve 100% cleanup coverage. Normally the ServletFilter is adding what is called a "Cleaner" into the ServletRequestCleanupService. That is required before you can cleanup callbacks for any of your ThreadLocals. In our log file I saw that we were not always adding a "Cleaner". This was an indication, that we were running code which had not been passed through the ServletFilter, so I reviewed our application.

It turned out that the first problem was a missing url-pattern element inside the filter-mapping block in the web.xml file. Unless you are mapping to /* make sure you are catching all the possible Url's. The good news is that since Servlet 2.5 you are allowed to have multiple url-pattern elements inside each filter-mapping element. So this was an easy fix.



Some people were writing that you could also separate multiple pattern with a comma. I haven't tried that myself.

Another problem area are application internal Thread pools. For instance do we use custom Events in the Spring framework which are passed between Spring beans. Per default this is done synchronously. You can change to asynchronous Event delivery by using a ApplicationEventMulticaster together with a proper TaskExecutor (i.e. org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor instead of default org.springframework.core.task.SyncTaskExecutor). However if you do this, you are creating yourself a thread pool. Listening to and handling of the Events will be done in separate Thread and not pass through the ServletFilter. So I was looking into ways to make sure, that each Event Listener adds a "Cleaner" and executes the cleaning logic afterwards. This was a good candidate to use an Aspect.



I have used the @AspectJ syntax for this Aspect and made it a Spring bean. This means I can compile the Aspect using a regular Java compiler. Instead of using load-time or compile-time weaving, we are using the Spring proxy-based AOP approach. In the code above, I am creating 2 Pointcuts, each one mapping to one of the Listeners where we actually have to do cleanup. This is probably not very future proof. Someone else might write another event listener in the future, which does then not have a Pointcut mapped to it. On the other hand using the proxy based AOP approach is probably slower than real weaving and some of the listeners which we have (5 currently) are really receiving a lot of events. So I sacrificed a future-proof implementation for maximum performance.

The 2 Pointcuts selecting listener execution are then combined in another Pointcut, which is then finally being used to create an Around advice which has a similar cleanup logic to the ServletFilter. Splitting Pointcuts into logical units with meaningful names is also a good AOP practice which I can recommend. I also took the liberty to rename a few classes. ServletRequestCleanupService became just CleanupService and ServletRequestCleanupCallback became CleanupCallback, which was more fitting now that not everything was passing the ServletRequestCleanupFilter anymore.

Time to wrap this up. If you need to clean up ThreadLocals from your Threads, investigate carefully make sure you have covered all entry points to your application. At least at some logging so you can find "holes" easily.

Mimicking a circular buffer

Today I needed a Java collection having some non-standard properties. I wanted to continuously iterate over the collection, pretty much like you would over a circular buffer. This alone would be simple enough to implement with any Java List I guess but I also wanted to be able to remove elements from the Collection while going through it. I could have written my own linked list and unlinked the elements that I wanted to remove while cycling through the list. However I wasn't really interested in adding a custom linked list to our project just for this specific purpose. Unfortunately the remove method of the LinkedList in Java takes an index which implies that you cannot iterate through the list using a for-each loop. If you use a for loop, the control variables have to be adapted after removing elements - so the code becomes more complex.

Google Guava to the rescue. They have this nice utility class Iterators. The cycle method in Iterators returns a indefinitely looping Iterator for any Iterable that is given as argument. This would give me the behavior of the ring buffer and, because it was an Iterator, I was able to remove elements from the underlying collection. The loop would stop if the Collection was exhausted. Pretty neat.


Testing just got better

This week I managed to work a bit with our test suite and make it run faster. When you work on a project, which has a codebase that grows and grows, it is natural that more and more tests are getting added. After some months you will be sitting with a test suite that runs a minute or even longer. This is the execution time for all our unit tests in the different Maven modules.


Last year I read an article in the German Java Magazin about a library called org.patterntesting. The library comes with TestRunner that can be used to run all test methods within a test class in parallel. Just change your test to look like this:


This will of course not work for all your tests immediately as not all tests can be run in parallel. Often this is due to bad test or software design. For instance tests requiring write access to the same physical File, tests altering shared fields within a test class, tests changing static field values - just to name a few. As you refactor your tests, so that they can run concurrently, you will automatically improve the design and testability of your application. We had a couple of these "smelling" unit tests that needed to be refactored. So this is what the execution time looked like after running the tests with patterntesting.


Saving 40 seconds does not seem a lot. But 40 seconds times 15 builds per day times 3 developers times 21 working days in a month brings you to 10,5 hours. Unfortunately, it isn't always as easy. Sometimes your test is already using the TestRunner, so you cannot just switch and use ParallelRunner. This is the case for all our Spring tests which were using the SpringJUnit4ClassRunner from Spring. I contacted one of the authors of the patterntesting library and got some help. In the latest version, patterntesting 1.2, there is a new TestRunner class ParallelProxyRunner, which can be used in connection with the DelegateTo annotation, to delegate to the original TestRunner while running the test in parallel. This works for the SpringJUnit4ClassRunner, but you have to be aware that the SpringJUnit4ClassRunner is not thread-safe (a problem that will be fixed in Spring 3.2). Though as a user of the patterntesting library you will never be affected by this - the ParallelProxyRunner will hide this problem for you.

This isn't everything patterntesting has to offer. My favorite thing is the @Broken annotation which replaces the @Ignore annotation in Junit.


One big anti-pattern in test driven development is developers adding @Ignore annotations and then never look at the test case again. When introduced the patterntesting library to other EA developers, I got a lot of responses like: "why do you have tests flagged as ignore or broken in the first place?" - it's bad practice. Yes, you are all right. But often reality is different. Game producers can get very pushy. Developers are forced to commit hot-fixes which can potentially break existing tests. Then the developer might not be able to fix the test for various reasons.

  • He or she is new in the team and doesn't have the big picture.
  • He or she is junior and doesn't know how stuff works.
  • The test is overly complicated so that only the author understands it.
  • It takes too long to fix it and something else has higher priority.

Just to name a few. Patterntesting comes adds other useful stuff for the testing toolbox. Here are some examples:




More examples can be found here.

Starting Dependency WAR Artifact using maven-jetty-plugin

I have worked in a lot of Maven projects, that used the maven-jetty-plugin. Normally the plugin is used to start a Jetty container with the WAR artifact produced by the current project. This works like a charm. Sometimes however, you want to host the WAR artifact of another project. This could be the case if you are developing the client for a service that can be reached via HTTP. The integration tests in the client project would require the service to be running and reachable, so that these tests can test and verify the client code. To start the Jetty container before and shut down after the integration test, you define two executions and bind them to the correct phase in Mavens lifecycle.



Also starting any external WAR artifact is straight forward with the maven-jetty-plugin and the deploy-war goal.



As you can see, the version is hard-coded in the path. This is somewhat ok as long as you are not violating the DRY principle. If you use the version somewhere else in your pom.xml, make sure to use a custom Maven property. Another way, which is a bit nicer perhaps, is to use the cargo-maven2-plugin which out of the box can start the WAR artifact of any Maven dependency from within the dependencies section. Here is a nice example from stackoverflow.com.

As you can see, either the cargo-maven2-plugin or the maven-jetty-plugin can be used for the simple use cases. It gets a bit trickier if you want to start the external WAR artifact and set some System properties during startup of the container. Both the maven-jetty-plugin and the cargo-maven2-plugin allow you to define individual system properties. However, only the maven-jetty-plugin can read a pre-existing properties file instead of individual System properties. This was required in one of the projects I am working on. Copying all the System properties out of the properties file to add them as individual System properties, is a lot of work and would again violate the DRY principle.

Also sometimes when you are developing both the service and the client project, and you are not using the SNAPSHOT mechanism, it can be tedious to update the version of the server WAR artifact that gets started during the integration tests of the client project. Maven knows two fixed keywords which you can use instead of specifying an exact version or a range. Use LATEST to download the latest snapshot or released version of a dependency from a repository. Use RELEASE to download the latest released version of a dependency from a dependency. Unfortunately you cannot use LATEST or RELEASE to start a WAR artifact of a dependency, if you are using the maven-jetty-plugin. This is because you specify the location of the WAR artifact as a full path inside the configuration - webApp element of the maven-jetty-plugin. The plugin does not use the syntax which is used to define the Maven dependencies.

There is however a little trick. You use the maven-dependency-plugin, which uses the default syntax for dependencies and can understand LATEST and RELEASE, to copy the WAR artifact to a fixed location. While copying you should also rename the war file. This makes your life easier as you never have to adapt the path in the webApp element of the maven-jetty-plugin if the version changes. Here is an example:

Test our new game

As some reader of this blog might know, I work for the EA studio of Playfish. Currently we are heading into the closed beta phase for a game which I helped to develop. This is a so called social game which is being played on Facebook. The backend of the game is developed by our team in Java. If you want to be one of the first ones to play the game and become a beta tester, fill in this application. I am not allowed to tell anything about the game at this point, just in response to this comment - yes the game is different from Adventure World and Cloudforest Expedition and much more fun to play.

Maybe I should have used a Lock here

Java 5 added some really nice classes in the java.util.concurrent package. For instance there is the ConcurrentMap interface which allows you to add items to a Map if they are not already contained. The code you would normally write if the ConcurrentMap didn't exist, needs to do this as a atomic check-then-act sequence, if the Map is shared between Threads. With the ConcurrentMap interface you get all of this for free using the putIfAbscent method.

I shoot myself in the foot today, with a small piece of code, which one of my unit tests was executing from a large number of Threads. The test was failing randomly, like 5% of the times. If you see tests randomly failing, it is often indicating a Date problem or a concurrency problem. Here is the class under test. Can you spot the problem?


In order to understand what the class does, you need to know what a DynamicProperty is. This is a class wrapping a value which comes from a remote source, i.e. over the Network. So instead of having fixed System properties, you would ask the remote source for the value. Then the value is cached for a couple of seconds and if expired you refresh the value. Now the ChangeAwareDynamicProperty is doing the same thing but additionally react to value changes. So every time the value is changed in the remote source, there is a costly operation that the ChangeAwareDynamicProperty needs to do. This code is not shown as it is not relevant.

What is the ConcurrentMap for? Obviously the costly operation should only be done once per value change right? So a simple approach is to use locking. Let only 1 Thread at a time go into a critical section where the current value is compared to the new value. If a change is detected, run the costly operation. This would totally work but the throughput would be horrible. Especially when a Thread detects a value change while holding the Lock, running the costly operation would block all other Threads for a while. So my idea was to use a ConcurrentMap instead of a Lock. If Threads detect a value change, they try to put the new value into a ConcurrentMap. By definition, only one Thread can put the new value into the Map. For this Thread the putIfAbscent call will return null. This Updater Thread will then run the costly operation, while other Threads will still return the previous value. Once the Updater Thread is finished, it will update the current value and remove the new current value from the ConcurrentMap. This is to prevent the Map from growing eternally. Sounds straightforward or?

Well obviously there was a problem, as the unit test was failing every now and then. Every time the test was failing, I could see that it was trying to run the costly operation twice for the same changed value, as indicated by the following log statement:


I started to believe, that the putIfAbsent method was buggy and returned null even if the value was already present in the Map. I asked another co-worker to check my code, to see if he could spot a problem. After a few minutes we realized that the problem was in my code - as to be expected. Like I said, I don't want the Map to grow forever. So the Updater Thread is removing the new changed value after the costly operation is finished. The problem is that another Thread could be waiting for the CPU in line 14. This is the line that invokes putIfAbscent. So once the Updater Thread is done, and the waiting Thread gets active, it will actually do exactly the same work again. Not good!

Our immediate solution was to not remove the Map entry after the Update Thread is finished. What we do instead is to remove the old value from the Map before reassigning the new changed value into currentVersion. As the Map will never contain more than 1 entry, it is always possible that a costly operation will be run again, even if a value has already been handled. This change only fixes the problem, that a single value change can trigger a consecutive execution of the costly operation.

git clone and remote end hung up unexpectedly

Yesterday morning before going to work, I created a git repository for a new hobby project of mine. I have done this a couple of time before and the git hosting provider of choice is Assembla. They are offering private git repositories and I never had any trouble in the past.

After creating the repository, I tried to clone it. I need to use sudo because I clone into a directory which is not owned by me. I am using the /web directory (or rather the directories under /web) directly as docroot for Apache.
sudo git clone git@git.assembla.com:my-new-repository.git
Initialized empty Git repository in /web/my-new-repository/.git/
Permission denied (publickey).
fatal: The remote end hung up unexpectedly

As you can see, something went wrong. I verified that my public ssh key was added to my Assembla account and it was. I decided it was a problem on the Assembla side and decided to try again this morning but the problem was still there. I created another git repository over at Bitbucket and tried again - same problem, wtf. Finally I had the great idea to try and clone the repository into my user directory and voila it worked. So it turned out that doing sudo and ssh public/private key authentication with git does not work. There is a good explanation about it on github.
If you are using sudo with git commands (e.g. using sudo git clone because you are deploying to a root-owned folder), ensure that you also generated the key using sudo. Otherwise, you will have generated a key for your current user, but when you are doing sudo git, you are actually the root user – thus, the keys will not match.

Using Reference Maps for Caches and Listeners

A while ago I wrote a blog post about the WeakHashMap. It then turned out that the WeakHashMap was not the optimal choice for that particular use case and I proposed a different solution. To make this a bit more seizable, I decided to implement a post a full code example. Let me again describe the use case.

Let's say you have a class wrapping some sort of event. Let's give the event class a name, write a Java interface and call it Auditable. Each Auditable subclass must implement two methods: validate and process. There is a invoker class called AuditableInvoker which receives a collection of Auditable's and invokes validate and process on each one of them. So far so good.



As an example, let's implement two Auditable subclasses which are pretty stupid. SleepingAuditable will just hold the current Thread for a few milliseconds. IteratingAuditable will run a small loop in it's validate and process methods.



In addition to that, there is a requirement that you need to know the execution time of the validate and process method in each Auditable subclass. Fortunately you can add listeners to AuditableInvoker. So all you have to do is to write a listener that measures the execution times. The listener need to start a stop watch before validate or process is invoked and stop this very stop watch after process and validate are finished. Once they are finished, the execution time can be computed and kept in a helper class that we call the StatsCollector. To keep things simple, our UnboundedStatsCollector will only increment a counter, completely ignoring the execution times.




The tricky part here is that you need to use the same stop watch before and after the invocations of an Auditable. A good use case for a map using weak referenced keys and object identity for comparison. Once an Auditable subclass has finished it's lifecycle and is no longer referenced somewhere else in the code, the garbage collection can collect the Auditable as well as the associated stop watch. This will prevent the Map from growing indefinitely. So here is a implementation using a ReferenceIdentityMap from the commons-collections project.


To verify that we really see the expected behavior, I have written a unit test that is stressing the ExecutionTimingAuditableLifecycleListener using multiple Threads. In this unit test I am re-using a class called MultithreadedStressTester which I stole from Nat Pryze's book "Growing Object Oriented Software guided by Tests".


The ExecutionTimingAuditableLifecycleListenerTest uses the MultithreadedStressTester to send a bunch of Threads over to the ExecutionTimingAuditableLifecycleListener, verifying that each invocation is properly timed using the ReferenceIdentityMap under the hood.

Finally, if you want to use google-guava instead of commons-collections, you can also use a LoadingCache with weak keys instead of the ReferenceIdentityMap. Here is a version of the ExecutionTimingAuditableLifecycleListener using google-guava.

The Static Final Inline Trap

Last week I was chasing a very interesting problem which we could only resolve with the help of a colleague. One of our testers found a bug in the current game that we are developing. If the user doesn't have Flashplayer installed, the No-Flash image is not shown properly. All code related to this, is pulled in from shared libraries which our project depends on. In the screen shot you will see something that looks like magic. There is a method which populates and returns a Map. Amongst others, one key called noflash_image_url is defining the location of the No-Flash image. In the debugger pane to the lower right, you can see the static final constant NOFLASH_IMAGE_URL evaluating to the correct value. This value is the correct location of the No-Flash image.

The strange thing however, is that the Map contains another (wrong) value, even though the Map value is also set using the same static final constant NOFLASH_IMAGE_URL. You can see that in the lower middle pane of the screen shot. So for some strange reason, the constant is evaluating to both the correct and the wrong value. I guess we could call it semi-constant in this particular case.

Anytime you see something weird like this, your first thought should be class loading problem. Based on my experience, the weirdest problems are often rooted in class loading. However this problem is of a different kind. For a better understanding, you have to know that the Class which initializes the Map is a dependency that ours project pulls in from a Maven dependency to library A. This library A then depends on another (transient) Maven library B which contains the NOFLASH_IMAGE_URL constant. Our project also defines a direct Maven dependency to library B. This is needed because library B changes quite often and we always want the latest version of B in our project. The latest version of B does contain the correct value the No-Flash image in the NOFLASH_IMAGE_URL constant. So one might think, that the Maven dependency resolution mechanism pulled in an old version of library B, but this wasn't the case.

A colleague then hinted me in the right direction. The Java compiler often does something called inlining for access to a static final variable. This is an optimization as the value of a final variable cannot change after it has been assigned. To verify this we ran the Java class file disassembler (javap) over the class file in library A.

   78: pop
   79: aload_2
   80: ldc #108; //String noflash_image_url
   82: ldc #109; //String http://static.playfish.com/shared/noflash.jpg
   84: invokeinterface #100,  3; //InterfaceMethod java/util/Map.put:(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;


As you can see, the compiler is really inlining the value in places where we, by running a debugger over the source code, expect an evaluation of the static final variable at runtime. This is definitely something you have to be aware of. We can fix this, by re-compiling library A against a newer version of library B, which will inline the correct No-Flash image. Another option to prevent inlining would be to declare the constant like this:

  public static final String NOFLASH_IMAGE_URL = new String ("...");


But then this might be really hard to understand for other developers and they might revert this change to a String literal if not properly documented. Update: I just realized that this problem is featured as Puzzle 93: Class Warfare in the Java Puzzlers book from Joshua Bloch. The compiler will inline all constant variables, such as Primitives and Strings which are initialized with a constant expression. Surprisingly, null is not inlined, neither are Java 5 enums.

Lost Virginity: WeakHashMap first timer

It was almost three years ago at OOPSLA in Nashville, where I heard about the WeakHashMap for the first time. The class is quite useful if you need a Map implementation, where the keys are compared using their memory references and not using equals. Another important property of the WeakHashMap is that the Map entries are removed "automagically" if no other object (than the WeakHashMap itself) holds a reference to the key object. The garbage collection will in that case remove Map entry and collect the key.

In the past 3 years I never used the WeakHashMap in any project. That changed yesterday. In the game that we are currently developing, we are using a mechanism where the game client is sending game events to the server. The server will then evaluate the game events and alter the users in memory before their state is made persistent in the database. Here is an example:

public interface GameEvent {



    /**

     * Subclasses may implement this to run validation logic, before the GameEvent is processed.

     *

     * @param user the {@link User} to apply this {@link GameEvent} on

     * @return {@link AuditResult} never <code>null</code>

     */

    AuditResult validate(User user);



    /**

     * Subclasses may implement this to run implementation specific logic, potentially altering the

     * given {@link User}. 

     *

     * @param user the {@link User} to apply this {@link GameEvent} on

     * @return {@link AuditResult} never <code>null</code>

     */

    AuditResult process(User user);

}





public class ConsumeFood implements GameEvent {



    private final int amount;



    public ConsumeFood(final int amount) {

        this.amount = amount;

    }



    @Override

    public AuditResult validate(final User user) {

        if (user.getFood() < this.amount) {

            return AuditResult("User doesn't have this amount of food.");

        }

        return AuditResult.SUCCESS;

    }



    @Override

    public AuditResult process(final User user) {

        user.addEnergy(this.amount);

        user.subtractFood(this.amount);

        return AuditResult.SUCCESS;

    }

}


Once the game client sends us the ConsumeFood game event, we subtract food from the player and add energy instead. We also have a wrapper class around a collection of game events and the execution logic looks like this:

public class GameEvents {

    

    .. other methods ...



    protected AuditResult process(final User user, final GameEvent change) {

        final AuditResult validateResult = change.validate(user);

        if (validateResult == AuditResult.SUCCESS) {

            return change.process(user);

        } else {

            return validateResult;

        }

    }

}


First we validate that we can apply the game event, then we process the event and alter the player. Since the number of different game events is continuously growing and growing, I thought it might be useful to measure the execution time of the validate and the process method in each game event. The way I implemented this a while ago, was through delegation. I added a wrapper class which was wrapping the real game event and timing the validate and process method:

import org.springframework.util.StopWatch;



public final class TimingGameEvent implements GameEvent {

    private final GameEvent gameEvent;



    public TimingGameEvent(final GameEvent gameEvent) {

        this.gameEvent = gameEvent;

    }



    /**

     * Delegates the processing to the encapsulated {@link GameEvent}. Uses a {@link StopWatch} to time the

     * execution time.

     */

    @Override

    public AuditResult process(final User user) {

        final StopWatch stopWatch = new StopWatch("process-stop-watch");

        stopWatch.start();

        try {

            return this.gameEvent.process(user);

        } finally {

            stopWatch.stop();

            this.processTimeInMs = stopWatch.getLastTaskTimeMillis();

        }

    }



    /**

     * Delegates the validation to the encapsulated {@link GameEvent}. Uses a {@link StopWatch} to time the

     * execution time.

     */

    @Override

    public AuditResult validate(final User user) {

        final StopWatch stopWatch = new StopWatch("validate-stop-watch");

        stopWatch.start();

        try {

            return this.gameEvent.validate(user);

        } finally {

            stopWatch.stop();

            this.validationTimeInMs = stopWatch.getLastTaskTimeMillis();

        }

    }

}


This worked well. However, this week we got another requirement from business. We needed to implement some sort of gameplay recorder. Each game event that the server receives must be recorded, so we can replay these events later. My first idea was to add another wrapper around the already existing TimingGameEvent wrapper class but this would have made it difficult to serialize the real game event to a File. Yes we decided to serialize to and deserialize from a String, which is stored in a plain textfile and each line represents one game event. I discarded the idea to add other wrappers around the game event and suggested a refactoring. Instead of using delegating wrappers, why not use a listener mechanism. Each listener would be notified before and after execution of the validate and the process method in each game event. Listeners could register themselves and it would be easier to extend in the future. On the negative side, of course measuring the execution times would not be as accurate anymore, as there could be other listeners which want to be notified before the game event is validated and processed. This however was not a big issue, since we were not interested in the exact time in milliseconds but rather in long running methods of a couple of seconds. I also added a mechanism to make sure the execution timing listener would get notified just before the game event method was executed and right after it was returning. More on that later.

Here is the listener interface I came up with:

public interface GameEventLifecycleListener {



    void onValidationStart(final User user, final GameEvent gameEvent);



    void onValidationFinish(final User user, final GameEvent gameEvent, 

             final AuditResult auditResult);



    void onProcessStart(final User user, final GameEvent gameEvent);



    void onProcessFinish(final User user, final GameEvent gameEvent, 

             final AuditResult auditResult);

}


Refactoring the TimingGameEvent class from above to a TimingGameEventLifecycleListener wasn't straight forward. Each invocation of the validate or the process method will now result in two listener notifications. So how do you know when to “press” stop on the StopWatch?

This is where the WeakHashMap comes in handy. Remember that each game event is going through the same chain? First onValidationStart is called, then onValidationFinish, onProcessStart and finally onProcessFinish. So the Listener could maintain a Map of all event implemented using a WeakHashMap. The first notification callback will add the game event to this Map. Subsequent notifications can assume that the game event will be present in the WeakHashMap. After the game event has passed through the chain and no object is referencing the game event anymore, it will automatically be removed from the WeakHashMap. Here is a part of the TimingGameEventLifecycleListener which will show you the concept.

import org.springframework.core.Ordered;



public class TimingGameEventLifecycleListener extends AbstractGameEventLifecycleListener {



    /**

     * By default the WeakHashMap is not thread-safe, so it needs to be wrapped in a synchronizedMap. This however

     * is quite slow, hence the ExecutionTimingGameEventLifecycleListener should not be running in production

     * all the time.

     */

    private final Map<GameEvent, TimedExecution> timedExecutions = Collections.synchronizedMap(

        new WeakHashMap<GameEvent, TimedExecution>()

    );



    @Override

    public void onValidationStart(final User user, final GameEvent gameEvent) {

        final TimedExecution timeValidation = 

          new TimedExecution(gameEvent.getClass());

        this.timedExecutions.put(gameEvent, timeValidation);

        // other stuff

    }



    @Override

    public void onValidationFinish(final User user, final GameEvent gameEvent, 

          final AuditResult auditResult) {

        final TimedExecution timeValidation = this.timedExecutions.get(gameEvent);

        if (timeValidation != null) {

     timeValidation.stopTimer();

        }

    }



    ... other notification methods ...



    @Override

    public int getOrder() {

        return Ordered.HIGHEST_PRECEDENCE;

    }

}


So the WeakHashMap can be nice in the role of a cache between different Listener methods. Another thing you may notice in the code above, is that the Listener is deriving from AbstractGameEventLifecycleListener instead of implementing GameEventLifecycleListener. I added a abstract base class for two reasons. First it is better to provide empty default implementations of all notification methods. Concrete Listeners like the TimingGameEventLifecycleListener can then only overwrite the methods they are interested in (okay in this case we are interested in all four notification methods, but other Listeners might not be). The second reason is that we want to force the Listeners to be in a specific order. Every Listener can for himself decide "how important" he is by implementing the getOrder() method defined in the org.springframework.core.Ordered interface which the AbstractGameEventLifecycleListener is implementing. Normally this interface is used by Spring to apply an order to Aspects. Though you might choose to keep your domain clean of Spring framework classes. Here is the AbstractGameEventLifecycleListener:

public class GameEvents {



    private final GameEvent[] events;

    private final NavigableSet<AbstractGameEventLifecycleListener> listeners;



    public void addListeners(final

          Collection<AbstractGameEventLifecycleListener> listeners) {

        this.listeners.addAll(listeners);

    }



    public GameEvents(final GameEvent[] events) {

        final int length = events == null ? 0 : events.length;

        this.listeners = new TreeSet<AbstractGameEventLifecycleListener>();

        this.events = new GameEvent[length];

        if (length > 0) {

            System.arraycopy(events, 0, this.events, 0, length);

        }

    }



    // other methods



    protected AuditResult process(final User user, final GameEvent gameEvent) {

        final AuditResult validateResult = gameEvent.validate(user);

        if (validateResult == AuditResult.SUCCESS) {

            return gameEvent.process(user);

        } else {

            return validateResult;

        }

    } 





    /**

     * Runs the {@link GameEvent#validate(User)} function of the given 

     * {@code gameEvent}, notifying all {@link AbstractGameEventLifecycleListener}s

     * before and after. The listener having the highest 

     * precidence is notified last before and first after the validation method.

     * @param user the {@link User} to validate the game event for

     * @param gameEvent the gameEvent to validate

     * @return the result of the validation

     */

    AuditResult runValidate(final User user, final GameEvent gameEvent) {

        for (Iterator<AbstractGameEventLifecycleListener> 

            iterator = this.listeners.descendingIterator(); 

  iterator.hasNext(); ) {

            final AbstractGameEventLifecycleListener listener = iterator.next();

            listener.onValidationStart(user, gameEvent);

        }



        final AuditResult validateResult = gameEvent.validate(user);



        for (final AbstractGameEventLifecycleListener listener : this.listeners) {

            listener.onValidationFinish(user, gameEvent, validateResult);

        }



        return validateResult;

    }



    /**

     * Runs the {@link GameEvent#process(User)} function of the given 

     * {@code gameEvent}, notifying all {@link AbstractGameEventLifecycleListener}s

     * before and after. The listener having the highest 

     * precedence is notified last before and first after the validation method.

     * @param user the {@link User} to process the gameEvent for

     * @param gameEvent the audit gameEvent to process

     * @return the result of processing the gameEvent

     */

    AuditResult runProcess(final User user, final GameEvent gameEvent) {

        for (Iterator<AbstractGameEventLifecycleListener> iterator =

             this.listeners.descendingIterator(); 

  iterator.hasNext(); ) {

            final AbstractGameEventLifecycleListener listener = iterator.next();

            listener.onProcessStart(user, gameEvent);

        }



        final AuditResult validateResult = gameEvent.process(user);



        for (final AbstractGameEventLifecycleListener listener : this.listeners) {

            listener.onProcessFinish(user, gameEvent, validateResult);

        }



        return validateResult;

    }

}


I said earlier, it is desirable to notify the TimingGameEventLifecycleListener last before validation starts and first after it finishes (to get more accurate timings). The GameEvents class, which is notifying the listeners, will honor the order using a NavigableSet that can be iterated in forward and backward order. Take a look at the updated version of the GameEvents class to see how it is implemented:

public abstract class AbstractGameEventLifecycleListener 

 implements GameEventLifecycleListener, Ordered, Comparable<GameEventLifecycleListener> {



    @Override

    public void onValidationStart(final User user, final GameEvent gameEvent) { }



    @Override

    public void onValidationFinish(final User user, final GameEvent gameEvent, 

       final AuditResult auditResult) { }



    @Override

    public void onProcessStart(final User user, final GameEvent gameEvent) { }





    @Override

    public void onProcessFinish(final User user, final GameEvent gameEvent, 

       final AuditResult auditResult) { }



    /**

     * Compares the order of the two {@link GameEventLifecycleListener}s 

     * using {@link Ordered}.

     * @param other another {@link GameEventLifecycleListener}

     * @return int

     */

    @Override

    public int compareTo(final GameEventLifecycleListener other) {

        return Integer.valueOf(this.getOrder()).compareTo(other.getOrder());

    }

}


One thing I wasn't able to come up with, was a good unit test to verify that the WeakHashMap is indeed not holding key references forever. This is extremely difficult to test as it involves testing for garbage collection and no, I am not suggesting running System.gc() from your test. I found something similar on this blog post. Apparently the Netbeans API offers something called assertGC(..) but it wasn't really fitting for my use case. So if you have a good suggestion how to test the behavior of a WeakHashMap, I am happy to hear it.

* UPDATE * UPDATE * After a few weeks running this the WeakHashMap and seeing some weird errors in the logs every now and then, I realized it's not the right Map implementation to use. The WeakHashMap is not what you want to use here, because the keys are not really compared using object identity. Initially I thought this was the case, when reading through the Javadoc of the WeakHashMap. What you really want is a hybrid Map, that combines the WeakHashMap with a IdentityHashMap. This hybrid Map will compare the keys based on objects identity and also use weak key references. The bad news is, there is no such map in the JDK (Java 6 at least). The good news is, there is a WeakIdentityHashMap in the Hibernate Search project and a ReferenceIdentityMap in the Commons Collections Project which can be used.