Eviction Policy problem cache clear

[gorshkov]

Hi,

I try tune JbossCache
Object stored in JBoss cache successfully. But I can't remove Object from cache use EvictionPolicy.

(JBoss 4.0.4.GA + JbossCache 1.4.0.GA + EJB 3.0 RC8)

ejb3-entity-cache-service.xml:

 ...
 <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">
 ...
 <attribute name="CacheMode">LOCAL</attribute>
 ...
 <!-- Name of the eviction policy class. -->
 <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.LRUPolicy</attribute>

 <!-- Specific eviction policy configurations. This is LRU -->
 <attribute name="EvictionPolicyConfig">
 <config>
 <attribute name="wakeUpIntervalSeconds">5</attribute>
 <!-- Cache wide default -->
 <region name="/_default_">
 <attribute name="maxNodes">5</attribute>
 <attribute name="timeToLiveSeconds">10</attribute>
 <attribute name="maxAgeSeconds">15</attribute>
 </region>
 </config>
 </attribute>
 ...

persistence.properties :

hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManager# Clustered cache with TreeCache
hibernate.cache.provider_class=org.jboss.ejb3.entity.TreeCacheProviderHook
hibernate.treecache.mbean.object_name=jboss.cache:service=TreeCache
hibernate.dialect=org.hibernate.dialect.SQLServerDialect
hibernate.jndi.java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory
hibernate.jndi.java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces
hibernate.bytecode.use_reflection_optimizer=false
# I don't think this is honored, but EJB3Deployer uses it
hibernate.bytecode.provider=javassist

console log:

2006-08-02 14:17:15,807 DEBUG [org.jboss.cache.eviction.LRUConfiguration] parseConfig: name -- /_default_ maxNodes -- 5
timeToLiveSeconds -- 10 maxAgeSeconds -- 15

I'm start project. JBoss cache successfully, but NumberOfNodes more then 5 and after 10 second cache not clear. Why? Where I'm wrong?

Thanks in advance.

[ben.wang]

you can turn on the org.jboss.cache to trace to see the eviction log.

[gorshkov]

That`s my log:

2006-08-03 09:44:06,736 DEBUG [org.jboss.system.ServiceCreator] About to create bean: jboss.cache:service=TreeCache with code: org.jboss.cache.TreeCache
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceCreator] Created bean: jboss.cache:service=TreeCache
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceController] recording that jboss.cache:service=TreeCache depends on jboss:service=Naming
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] considering <anonymous> with object name jboss:service=Naming
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceController] recording that jboss.cache:service=TreeCache depends on jboss:service=TransactionManager
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] considering <anonymous> with object name jboss:service=TransactionManager
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] TransactionManagerLookupClass set to org.jboss.cache.JBossTransactionManagerLookup in jboss.cache:service=TreeCache
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] IsolationLevel set to REPEATABLE_READ in jboss.cache:service=TreeCache
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] CacheMode set to LOCAL in jboss.cache:service=TreeCache
2006-08-03 09:44:06,767 DEBUG [org.jboss.system.ServiceConfigurator] ClusterName set to EJB3-entity-cache in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] ClusterConfig set to [config: null] in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 INFO [org.jboss.cache.TreeCache] setting cluster properties from xml to: UDP(ip_mcast=true;ip_ttl=2;loopback=false;mcast_addr=228.1.2.3;mcast_port=43333;mcast_recv_buf_size=80000;mcast_send_buf_size=150000;ucast_recv_buf_size=80000;ucast_send_buf_size=150000):PING(down_thread=false;num_initial_members=3;timeout=2000;up_thread=false):MERGE2(max_interval=20000;min_interval=10000):FD(down_thread=true;shun=true;up_thread=true):VERIFY_SUSPECT(down_thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(down_thread=false;gc_lag=50;max_xmit_size=8192;retransmit_timeout=600,1200,2400,4800;up_thread=false):UNICAST(down_thread=false;min_threshold=10;timeout=600,1200,2400;window_size=100):pbcast.STABLE(desired_avg_gossip=20000;down_thread=false;up_thread=false):FRAG(down_thread=false;frag_size=8192;up_thread=false):pbcast.GMS(join_retry_timeout=2000;join_timeout=5000;print_local_addr=true;shun=true):pbcast.STATE_TRANSFER(down_thread=false;up_thread=false)
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] InitialStateRetrievalTimeout set to 5000 in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] SyncReplTimeout set to 10000 in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] LockAcquisitionTimeout set to 15000 in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] EvictionPolicyClass set to org.jboss.cache.eviction.LRUPolicy in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceConfigurator] EvictionPolicyConfig set to [config: null] in jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 INFO [org.jboss.cache.TreeCache] setEvictionPolicyConfig(): [config: null]
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceController] Creating service jboss.cache:service=TreeCache
2006-08-03 09:44:06,783 DEBUG [org.jboss.system.ServiceController] waiting in create of jboss.cache:service=TreeCache waiting on jboss:service=Naming
2006-08-03 09:44:06,783 DEBUG [org.jboss.deployment.MainDeployer] Done with create step of deploying ejb3-entity-cache-service.xml

2006-08-03 09:44:08,406 DEBUG [org.jboss.cache.TreeCache] Creating jboss.cache:service=TreeCache
2006-08-03 09:44:08,406 DEBUG [org.jboss.cache.TreeCache] failed looking up TransactionManager, will not use transactions
javax.naming.NameNotFoundException: TransactionManager not bound
 at org.jnp.server.NamingServer.getBinding(NamingServer.java:529)
 at org.jnp.server.NamingServer.getBinding(NamingServer.java:537)
 at org.jnp.server.NamingServer.getObject(NamingServer.java:543)
 at org.jnp.server.NamingServer.lookup(NamingServer.java:296)
 at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:625)
 at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:587)
 at javax.naming.InitialContext.lookup(InitialContext.java:351)
 at org.jboss.cache.JBossTransactionManagerLookup.getTransactionManager(JBossTransactionManagerLookup.java:18)
 at org.jboss.cache.TreeCache._createService(TreeCache.java:1311)
 at org.jboss.cache.TreeCache.createService(TreeCache.java:1297)
 at org.jboss.system.ServiceMBeanSupport.jbossInternalCreate(ServiceMBeanSupport.java:260)
 at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:243)
 at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
 at $Proxy0.create(Unknown Source)
 at org.jboss.system.ServiceController.create(ServiceController.java:330)
 at org.jboss.system.ServiceController.create(ServiceController.java:273)
 at org.jboss.system.ServiceController.create(ServiceController.java:349)
 at org.jboss.system.ServiceController.create(ServiceController.java:273)
 at org.jboss.system.ServiceController.create(ServiceController.java:349)
 at org.jboss.system.ServiceController.create(ServiceController.java:273)
 at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
 at $Proxy4.create(Unknown Source)
 at org.jboss.deployment.SARDeployer.create(SARDeployer.java:258)
 at org.jboss.deployment.MainDeployer.create(MainDeployer.java:953)
 at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:807)
 at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:771)
 at sun.reflect.GeneratedMethodAccessor14.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
 at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
 at $Proxy6.deploy(Unknown Source)
 at org.jboss.deployment.scanner.URLDeploymentScanner.deploy(URLDeploymentScanner.java:421)
 at org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:634)
 at org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
 at org.jboss.deployment.scanner.AbstractDeploymentScanner.startService(AbstractDeploymentScanner.java:336)
 at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
 at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
 at $Proxy0.start(Unknown Source)
 at org.jboss.system.ServiceController.start(ServiceController.java:417)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
 at $Proxy4.start(Unknown Source)
 at org.jboss.deployment.SARDeployer.start(SARDeployer.java:302)
 at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1007)
 at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:808)
 at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:771)
 at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:755)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
 at java.lang.reflect.Method.invoke(Method.java:585)
 at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
 at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
 at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
 at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
 at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
 at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
 at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
 at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
 at $Proxy5.deploy(Unknown Source)
 at org.jboss.system.server.ServerImpl.doStart(ServerImpl.java:482)
 at org.jboss.system.server.ServerImpl.start(ServerImpl.java:362)
 at org.jboss.Main.boot(Main.java:200)
 at org.jboss.Main$1.run(Main.java:464)
 at java.lang.Thread.run(Thread.java:595)
2006-08-03 09:44:08,406 WARN [org.jboss.cache.TreeCache] Using deprecated configuration element 'EvictionPolicyProvider'. This is only provided for 1.2.x backward compatibility and may disappear in future releases.
2006-08-03 09:44:08,421 DEBUG [org.jboss.cache.eviction.LRUConfiguration] parseConfig: name -- /_default_ maxNodes -- 5 timeToLiveSeconds -- 10 maxAgeSeconds -- 15
2006-08-03 09:44:08,421 DEBUG [org.jboss.cache.eviction.RegionManager] createRegion(): creating region for fqn- /_default_

2006-08-03 09:44:08,608 DEBUG [org.jboss.cache.TreeCache] Starting jboss.cache:service=TreeCache
2006-08-03 09:44:08,608 INFO [org.jboss.cache.eviction.RegionManager] Starting eviction timer
2006-08-03 09:44:08,608 DEBUG [org.jboss.cache.TreeCache] Started jboss.cache:service=TreeCache

2006-08-03 09:44:33,650 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /imhotep/cmp/PubBean/imhotep.cmp.PubBean#49020 for a node that doesn't exist yet. Process as an add.
2006-08-03 09:44:33,650 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /imhotep/cmp/DocBean/imhotep.cmp.DocBean#5141322 for a node that doesn't exist yet. Process as an add.

2006-08-03 09:44:43,667 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Visiting node that was not added to eviction queues. Assuming that it has 1 element.
2006-08-03 09:44:43,667 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Visiting node that was not added to eviction queues. Assuming that it has 1 element.

[confuz]

Had you applied a cache loader?
and maybe the cached object will be cleaned after 15 seconds as your configuration.

[gorshkov]

I'm not use cache loader.
And object not cleaned after 15 seconds :(

[ben.wang]

From you log tracing, eviction timer thread is supposed to wake up every 5 seconds. But I don't see that (you have between 08, 33, and 43). Is that all you have?

[gorshkov]

No my log is more long. This is fragment only. But I can't find in log EvictionThreadWakeupIntervalSeconds or other world
reminiscent of this parameter

In ejb3-entity-cache-service.xml:
5

In the jmx-console I can see EvictionThreadWakeupIntervalSeconds = 5

(I can send you all my log)

[alximik]

I have the same problem.

When the last node in FQN is a String everything is fine. But when the last node in FQN is an Integer the cache is not cleared.

treeCache.put(new Fqn(new Object[]{"a", "b", Integer.valueOf(1).toString()}), "key2", "value2");//The data will be cleared

treeCache.put(new Fqn(new Object[]{"a", "b", Integer.valueOf(1)}), "key2", "value2");//The data will not be cleared

The logs are the same in both cases

2006-08-21 10:52:02,692 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /a/b/1 should be evicted because of max age
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Attempting to evict cache node with fqn of /a/b/1
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_evict(/a/b/1)]
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _evict(/a/b/1)
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /a/b/1 for owner Thread[Timer-5,5,jboss]
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/a, caller=Thread[Timer-5,5,jboss], lock=<unlocked>
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquired RL: fqn=/a, caller=Thread[Timer-5,5,jboss], lock=read owners=[Thread[Timer-5,5,jboss]]
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/a/b, caller=Thread[Timer-5,5,jboss], lock=<unlocked>
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquired RL: fqn=/a/b, caller=Thread[Timer-5,5,jboss], lock=read owners=[Thread[Timer-5,5,jboss]]
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/a/b/1, caller=Thread[Timer-5,5,jboss], lock=<unlocked>
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.Node] acquired WL: fqn=/a/b/1, caller=Thread[Timer-5,5,jboss], lock=write owner=Thread[Timer-5,5,jboss]
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _evict(/a/b/1) on cache.
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.TreeCache] _evict(/a/b/1)
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.TreeCache] _remove(null, "/a/b/1")
2006-08-21 10:52:02,692 TRACE [org.jboss.cache.AbstractNode] removed child 1

[zzzz8]

Hi,

I've seen the same problem, too! In this case, my last node is a Long object... Hope this gets fixed soon. Thanks!

[gorshkov]

(JBoss 4.0.4.GA + JbossCache 1.4.0.GA + EJB 3.0 RC8) cache not clear
(JBoss 4.0.4.GA + JbossCache 1.4.0.GA + EJB 3.0 RC7) cache clear !!!
For the time being we use EJB 3.0 RC7...

[ben.wang]

OK, eviction policy has this restriction that if you specify the region name from the xml, it needs to be String-based (since there is no way to express Object from xml configuration).

So if you need to evict non-String based fqn, you will have to do it via programmatically yourself. Here is a code snippet that shows you how to do it:

// ... cache needs to be started first, e.g.
cache_.start();

// region name is ignored here.
String xml = "<region name=\"/dummy\">" +
 "<attribute name=\"maxNodes\">10000</attribute>" +
 "<attribute name=\"timeToLiveSeconds\">4</attribute>" +
 "</region>";
Element element = XmlHelper.stringToElement(xml);

RegionManager regionManager = cache_.getEvictionRegionManager();
// Fqn is the region name
Integer ii = new Integer(1);
Fqn fqn = new Fqn(ii);
// create region will also add it to the eviction policy map.
Region region = regionManager.createRegion(fqn, element);

Then

Integer ii = new Integer(1);
Fqn rootfqn = new Fqn(ii);

Integer in = new Integer(3);
Fqn fqn = new Fqn(rootfqn, in);
cache_.put(fqn, in, in);

will be evicted later.

BTW,

1) There is a test case: ProgrammLRUPolicyTest for couple test cases.
2) I am adding this example to the FAQ documentation as well.