Multiple events on the local node with Infinispan 5.3.0-final
Hi,
After upgrading to Infinispan 5.3.0-final I found a strange "intermittent" problem in my application. Digging a bit deeper, I found out it is due to CacheEntry events raised twice for some keys on the local node (the node where the cache operation is invoked).
I was able to reproduce the problem and I wrote the following test case:
import static org.hamcrest.Matchers.instanceOf;
import static org.hamcrest.Matchers.is;
import static org.junit.Assert.assertThat;
import java.util.LinkedList;
import java.util.List;
import org.infinispan.Cache;
import org.infinispan.configuration.cache.CacheMode;
import org.infinispan.configuration.cache.ConfigurationBuilder;
import org.infinispan.configuration.global.GlobalConfigurationBuilder;
import org.infinispan.manager.DefaultCacheManager;
import org.infinispan.notifications.Listener;
import org.infinispan.notifications.cachelistener.annotation.CacheEntryCreated;
import org.infinispan.notifications.cachelistener.annotation.CacheEntryModified;
import org.infinispan.notifications.cachelistener.annotation.CacheEntryRemoved;
import org.infinispan.notifications.cachelistener.event.CacheEntryCreatedEvent;
import org.infinispan.notifications.cachelistener.event.CacheEntryEvent;
import org.infinispan.notifications.cachelistener.event.CacheEntryModifiedEvent;
import org.infinispan.notifications.cachelistener.event.CacheEntryRemovedEvent;
import org.junit.Test;
public class TestInfinispanDuplicatedEvents {
static {
System.setProperty("java.net.preferIPv4Stack", "true");
}
@Listener
public class MyCacheListener {
private List<CacheEntryEvent<String, String>> events = new LinkedList<CacheEntryEvent<String,String>>();
@CacheEntryCreated
public void created(CacheEntryCreatedEvent<String, String> event) {
events.add(event);
}
@CacheEntryModified
public void modified(CacheEntryModifiedEvent<String, String> event) {
events.add(event);
}
@CacheEntryRemoved
public void removed(CacheEntryRemovedEvent<String, String> event) {
events.add(event);
}
}
@Test
public void must_raise_create_event_once() {
DefaultCacheManager nodeA = configureNode();
Cache<String, String> cacheA = nodeA.getCache();
MyCacheListener listenerA = new MyCacheListener();
cacheA.addListener(listenerA);
DefaultCacheManager nodeB = configureNode();
Cache<String, String> cacheB = nodeB.getCache();
MyCacheListener listenerB = new MyCacheListener();
cacheB.addListener(listenerB);
cacheA.put("a", "a");
/*
* We expect 4 events on both nodes: pre-create, pre-modified, post-modified, post-create
*/
assertThat(listenerA.events.size(), is(4));
assertThat(listenerB.events.size(), is(4));
checkEvents(listenerA, "a");
checkEvents(listenerB, "a");
/*
* So far so good, let's try another key, say "b"
*/
listenerA.events.clear();
listenerB.events.clear();
cacheA.put("b", "b");
/*
* We expect 4 events again
*/
assertThat(listenerA.events.size(), is(4));
assertThat(listenerB.events.size(), is(4));
checkEvents(listenerA, "b");
checkEvents(listenerB, "b");
/*
* Let's try another one, say "a0"
*/
listenerA.events.clear();
listenerB.events.clear();
cacheA.put("a0", "a0");
/*
* We expect another 4 events, but on the local node (A in this case) we get 8
*/
assertThat(listenerA.events.size(), is(4));
assertThat(listenerB.events.size(), is(4));
checkEvents(listenerA, "a0");
checkEvents(listenerB, "a0");
}
private DefaultCacheManager configureNode() {
return new DefaultCacheManager(GlobalConfigurationBuilder.defaultClusteredBuilder().transport().globalJmxStatistics().allowDuplicateDomains(true)
.build(), new ConfigurationBuilder().clustering().cacheMode(CacheMode.REPL_SYNC).build());
}
private void checkEvents(MyCacheListener listenerA, String expectedKey) {
assertThat(listenerA.events.get(0), is(instanceOf(CacheEntryCreatedEvent.class)));
assertThat(listenerA.events.get(0).getKey(), is(expectedKey));
assertThat(listenerA.events.get(0).isPre(), is(true));
assertThat(listenerA.events.get(1), is(instanceOf(CacheEntryModifiedEvent.class)));
assertThat(listenerA.events.get(1).getKey(), is(expectedKey));
assertThat(listenerA.events.get(1).isPre(), is(true));
assertThat(listenerA.events.get(2), is(instanceOf(CacheEntryModifiedEvent.class)));
assertThat(listenerA.events.get(2).getKey(), is(expectedKey));
assertThat(listenerA.events.get(2).isPre(), is(false));
assertThat(listenerA.events.get(3), is(instanceOf(CacheEntryCreatedEvent.class)));
assertThat(listenerA.events.get(3).getKey(), is(expectedKey));
assertThat(listenerA.events.get(3).isPre(), is(false));
}
}
The problem happens regardless of the cluster mode, but only with non-transactional caches. I think this is due to the fact that with transactional caches the events are raised on commit.
Also, my application used to work with an interceptor rather than an event listener, this is because prior to 5.3.0 I wasn't able to ignore the modification event that comes with an entry creation operation (CacheEntryModifiedEvent.isCreated() method has been added, thanks a lot for that!). So I actually found the problem when I saw my interceptor being occasionally executed 3 times with 2 nodes.
I'm not sure whether the command and the chain of interceptor is really meant to be executed twice on the local node, but the consequent behaviour on the events sounds like a bug.
Thanks!
