Unexpected POJO Cache events
joneian Feb 15, 2009 6:38 PMHi,
I'm very impressed with the POJO cache, it does exactly what I'm looking for. I'm interested in performing updates to the cache, and getting the events in a client. I've written an app to test this out, and I'm getting more events than I expect.
Here is the POJO:
@Replicable public class Order { private Long id; private String counterparty; private BigDecimal amount; // getters and setters ....
Here is the server which is:
1) adding a POJO to the Cache,
2) modifying it,
3) then detaching it.
public class JBCacheTestServer { public static void main(String[] args) { PojoCache cache = PojoCacheFactory.createCache("replSync-service.xml"); long id=0; while (true) { Order order = createOrder(); // creates an Order object with random data log.info("Created order: " + order); order.setId(++id); cache.attach(order.getId().toString(), order); sleep(); // sleeps for a while order.setCounterparty("rachel"); log.info("Updating order: " + order); sleep(); log.info("Deleting order: " + order); cache.detach(order.getId().toString()); sleep(); } } ...
And here's the client listening to the cache:
public class JBCacheTestClient { public static void main(String[] args) { PojoCache cache = PojoCacheFactory.createCache("replSync-service.xml"); cache.addListener(new ClientCacheListener()); } @PojoCacheListener public static class ClientCacheListener { @Attached public void onAttachEvent(AttachedEvent event) { log.info("attached: " + event); } @FieldModified public void onFieldModifiedEvent(FieldModifiedEvent event) { log.info("modified:" + event); } @Detached public void onDetachedEvent(DetachedEvent event) { log.info("detached:" + event); } ...
Here's the log output of the server once it gets into the loop:
36035 [main] INFO com.iandjones.jbcachetest.server.JBCacheTestServer - Created order: id:null, cpty: ian, amount:1528.1274530155354 36070 [Incoming-1,192.168.2.2:57917] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 39268 [Timer-1,192.168.2.2:57917] DEBUG org.jgroups.protocols.FD - sending are-you-alive msg to 192.168.2.2:57918 (own address=192.168.2.2:57917) 46080 [Incoming-1,192.168.2.2:57917] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 46082 [main] INFO com.iandjones.jbcachetest.server.JBCacheTestServer - Updating order: id:2, cpty: rachel, amount:1528.1274530155354 49269 [Timer-3,192.168.2.2:57917] DEBUG org.jgroups.protocols.FD - sending are-you-alive msg to 192.168.2.2:57918 (own address=192.168.2.2:57917) 56082 [main] INFO com.iandjones.jbcachetest.server.JBCacheTestServer - Deleting order: id:2, cpty: rachel, amount:1528.1274530155354 56089 [Incoming-1,192.168.2.2:57917] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 56778 [Timer-4,192.168.2.2:57917] DEBUG org.jgroups.protocols.MERGE2 - 192.168.2.2:57917 is looking for merge candidates, found initial_mbrs=[[own_addr=192.168.2.2:57918, coord_addr=192.168.2.2:57917, is_server=true], [own_addr=192.168.2.2:57917, coord_addr=192.168.2.2:57917, is_server=true]]
And here's the log for the client:
29629 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 29651 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - attached: org.jboss.cache.pojo.notification.event.AttachedEvent[source=1528.1274530155354] 29654 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - attached: org.jboss.cache.pojo.notification.event.AttachedEvent[source=id:2, cpty: ian, amount:1528.1274530155354] 29662 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 29662 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.transaction.TransactionTable - Found local TX=org.jboss.cache.transaction.DummyTransaction@91f0de, global TX=GlobalTransaction:<192.168.2.2:57917>:3 32884 [Timer-2,192.168.2.2:57918] DEBUG org.jgroups.protocols.FD - sending are-you-alive msg to 192.168.2.2:57917 (own address=192.168.2.2:57918) 39664 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 39665 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - modified:org.jboss.cache.pojo.notification.event.FieldModifiedEvent[source=id:2, cpty: ian, amount:1528.1274530155354] 42884 [Timer-2,192.168.2.2:57918] DEBUG org.jgroups.protocols.FD - sending are-you-alive msg to 192.168.2.2:57917 (own address=192.168.2.2:57918) 49671 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 49673 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - detached:org.jboss.cache.pojo.notification.event.DetachedEvent[source=id:2, cpty: rachel, amount:1528.1274530155354] 49673 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - detached:org.jboss.cache.pojo.notification.event.DetachedEvent[source=1528.1274530155354] 49674 [Incoming-1,192.168.2.2:57918] INFO com.iandjones.jbcachetest.client.JBCacheTestClient - modified:org.jboss.cache.pojo.notification.event.FieldModifiedEvent[source=id:2, cpty: rachel, amount:null] 49677 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.marshall.CacheMarshaller300 - Region does not exist for Fqn null - not using a context classloader. 49677 [Incoming-1,192.168.2.2:57918] DEBUG org.jboss.cache.transaction.TransactionTable - Found local TX=org.jboss.cache.transaction.DummyTransaction@5585dc, global TX=GlobalTransaction:<192.168.2.2:57917>:4
I'm expecting the 3 events previously mentioned, but I'm getting more:
1) For the attach, I'm getting an attach for the amount attribute, and the one I expect for the object
2) I get one event for the modify as expected, but the value in the object is the old value. I was expecting the new value. I know I can get it from event.getValue, but I just want the update object.
3) For the detach, I get the expected detach for the object, then a detach for the amount attribute, and then a modify for the detached object.
Given the object cache mapping model, I'm not all that surprised that I'm getting these events. However, I don't think I should get these events. I can filter out the attribute events by checking the type of the event source object, but I still get that odd final modification event for the object thats been detached.
POJO Cache events don't seem to be exhaustively documented, is this how it should work? Am I listening to the correct events?
Thanks for your help,
Ian
JBoss Cache core: 3.0.2 GA
JBoss POJO Cache: 3.0.0 GA