JBossDeveloper

Thanks, it worked (after multiple: 1. clean, 2.build 3.goto 1 again; eclipse and ant after some attempts finally did what they should and it worked).

Unfourtunately there still is an error that shows up:

... //Server Start
13:35:47,062 INFO [STDOUT] I have been created by de.somewhere.test.ejbean.NatPersLstSFBea
... // some verbose Hibernate output about creating factory and c3p0 pool stuff
13:41:21,234 WARN [CacheLoaderInterceptor] CacheLoader.get(Fqn) returned a null; assuming the node nodes not exist.
13:41:21,234 WARN [CacheLoaderInterceptor] The CacheLoader interface has changed since JBossCache 1.3.x
13:41:21,234 WARN [CacheLoaderInterceptor] Please see http://jira.jboss.com/jira/browse/JBCACHE-118
13:41:21,234 WARN [CacheLoaderInterceptor] CacheLoader.get() should return an empty Map if the node does exist but doesn't have any attributes.
13:58:06,859 INFO [STDOUT] I will be serial soon de.somewhere.test.ejbean.NatPersLstSFBean //done from @PrePassivate
14:00:08,359 INFO [STDOUT] I have been created by de.somewhere.test.ejbean.NatPersLstSFBean //done from @Init
14:03:35,046 ERROR [STDERR] java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException
14:03:35,046 ERROR [STDERR] at org.jboss.ejb3.interceptor.LifecycleInterceptorHandler.prePassivate(LifecycleInterceptorHandler.java:160)
14:03:35,046 ERROR [STDERR] at org.jboss.ejb3.stateful.StatefulContainer.invokePrePassivate(StatefulContainer.java:351)
14:03:35,046 ERROR [STDERR] at org.jboss.ejb3.stateful.StatefulBeanContext.prePassivate(StatefulBeanContext.java:178)
14:03:35,046 ERROR [STDERR] at org.jboss.ejb3.cache.tree.StatefulEvictionPolicy.passivate(StatefulEvictionPolicy.java:73)
14:03:35,046 ERROR [STDERR] at org.jboss.ejb3.cache.tree.StatefulEvictionPolicy.evict(StatefulEvictionPolicy.java:63)
14:03:35,062 ERROR [STDERR] at org.jboss.cache.eviction.BaseEvictionAlgorithm.evictCacheNode(BaseEvictionAlgorithm.java:210)
14:03:35,062 ERROR [STDERR] at org.jboss.cache.eviction.LRUAlgorithm.evict(LRUAlgorithm.java:90)
14:03:35,062 ERROR [STDERR] at org.jboss.cache.eviction.LRUAlgorithm.prune(LRUAlgorithm.java:121)
14:03:35,062 ERROR [STDERR] at org.jboss.cache.eviction.BaseEvictionAlgorithm.process(BaseEvictionAlgorithm.java:98)
14:03:35,062 ERROR [STDERR] at org.jboss.cache.eviction.EvictionTimerTask.run(EvictionTimerTask.java:80)
14:03:35,062 ERROR [STDERR] at java.util.TimerThread.mainLoop(Timer.java:512)
14:03:35,062 ERROR [STDERR] at java.util.TimerThread.run(Timer.java:462)
14:03:35,062 ERROR [STDERR] Caused by: java.lang.RuntimeException: java.io.IOException
14:03:35,062 ERROR [STDERR] at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:365)
14:03:35,062 ERROR [STDERR] at org.jboss.ejb3.stateful.StatefulBeanContext.getInterceptorInstances(StatefulBeanContext.java:333)
14:03:35,062 ERROR [STDERR] at org.jboss.ejb3.interceptor.LifecycleInvocationContextImpl.getLifecycleInvocationContext(LifecycleInvocationContextImpl.java:65)
14:03:35,062 ERROR [STDERR] at org.jboss.ejb3.interceptor.LifecycleInterceptorHandler.prePassivate(LifecycleInterceptorHandler.java:151)
14:03:35,062 ERROR [STDERR] ... 11 more
14:03:35,062 ERROR [STDERR] Caused by: java.io.IOException
14:03:35,062 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:107)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:269)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
14:03:35,062 ERROR [STDERR] at org.jboss.serial.persister.ProxyPersister.readData(ProxyPersister.java:66)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readSlotWithFields(RegularObjectPersister.java:353)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:273)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.ArrayPersister.readObjectArray(ArrayPersister.java:196)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.ArrayPersister.readData(ArrayPersister.java:172)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.io.JBossObjectInputStream.readObjectOverride(JBossObjectInputStream.java:165)
14:03:35,078 ERROR [STDERR] at java.io.ObjectInputStream.readObject(ObjectInputStream.java:333)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.io.MarshalledObject.get(MarshalledObject.java:68)
14:03:35,078 ERROR [STDERR] at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:342)
14:03:35,078 ERROR [STDERR] ... 14 more
14:03:35,078 ERROR [STDERR] Caused by: java.lang.reflect.InvocationTargetException
14:03:35,078 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
14:03:35,078 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
14:03:35,078 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
14:03:35,078 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:585)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:103)
14:03:35,078 ERROR [STDERR] ... 38 more
14:03:35,078 ERROR [STDERR] Caused by: org.jboss.serial.exception.SerializationException: Object reference 5 was not found
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:117)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.RegularObjectPersister.readSlotWithFields(RegularObjectPersister.java:353)
14:03:35,078 ERROR [STDERR] at org.jboss.serial.persister.ObjectInputStreamProxy.defaultReadObject(ObjectInputStreamProxy.java:78)
14:03:35,078 ERROR [STDERR] at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.readObject(ThreadLocalSessionContext.java:334)
14:03:35,078 ERROR [STDERR] ... 43 more

14:03:35,078 WARN [CacheLoaderInterceptor] CacheLoader.get(Fqn) returned a null; assuming the node nodes not exist.
14:03:35,078 WARN [CacheLoaderInterceptor] The CacheLoader interface has changed since JBossCache 1.3.x
14:03:35,078 WARN [CacheLoaderInterceptor] Please see http://jira.jboss.com/jira/browse/JBCACHE-118
14:03:35,078 WARN [CacheLoaderInterceptor] CacheLoader.get() should return an empty Map if the node does exist but doesn't have any attributes.
14:03:35,078 WARN [CacheLoaderInterceptor] CacheLoader.get(Fqn) returned a null; assuming the node nodes not exist.
14:03:35,078 WARN [CacheLoaderInterceptor] The CacheLoader interface has changed since JBossCache 1.3.x
14:03:35,078 WARN [CacheLoaderInterceptor] Please see http://jira.jboss.com/jira/browse/JBCACHE-118
14:03:35,078 WARN [CacheLoaderInterceptor] CacheLoader.get() should return an empty Map if the node does exist but doesn't have any attributes.
14:06:03,984 ERROR [STDERR] java.lang.NullPointerException
14:06:03,984 ERROR [STDERR] at org.jboss.ejb3.cache.tree.StatefulEvictionPolicy.evict(StatefulEvictionPolicy.java:48)
14:06:03,984 ERROR [STDERR] at org.jboss.cache.eviction.BaseEvictionAlgorithm.evictCacheNode(BaseEvictionAlgorithm.java:210)
14:06:04,015 ERROR [STDERR] at org.jboss.cache.eviction.BaseEvictionAlgorithm.emptyRecycleQueue(BaseEvictionAlgorithm.java:461)
14:06:04,015 ERROR [STDERR] at org.jboss.cache.eviction.BaseEvictionAlgorithm.process(BaseEvictionAlgorithm.java:97)
14:06:04,015 ERROR [STDERR] at org.jboss.cache.eviction.EvictionTimerTask.run(EvictionTimerTask.java:80)
14:06:04,015 ERROR [STDERR] at java.util.TimerThread.mainLoop(Timer.java:512)
14:06:04,015 ERROR [STDERR] at java.util.TimerThread.run(Timer.java:462)
...

Hi Ben,
it shows up on both nodes, but I do have RoundRobin in use for the SFSB. It does not show up absoluteley simultaniously, one node starts shortly before the other.

I am not sure, but I thought I rather mention it, just in case it is related.
(If not just ignore it). I still have a problem with Hibernate 3.2.0 CR3
(this was with 3.2.0CR2 http://www.jboss.com/index.html?module=bb&op=viewtopic&t=84650
and about http://opensource.atlassian.com/projects/hibernate/browse/HHH-1816)

09:06:03,640 WARN [SessionFactoryObjectFactory] Not found: 2c9096850c573a72010c5741866f0002 // First invokation of the SFSB ( client ends after this)
09:06:03,640 WARN [SessionFactoryObjectFactory] Not found: java:Hibernate/MyHibernateSessionFactory // Second invokation of the SFSB (with a new instance of the client)

Hi, I have still not been able to solve the above Problem (In short: "EJB3.0 SFSB in a cluster --> error with the eviction in the cache")
I tried it with CR2 and also with 1.4.0GA, results are the same.
Are there any hints you can give, were I should/could step through to get behind this ?(my debug walks havent really brought any light into this).

Sincerly

Marc

Just in case anyone wants to know:
I have checked out the latest ejb3 source from the 4.0.4.SP1 branch and integrated it in the 4.0.4GA source, since I noticed that there are changes in the org.jboss.ejb3.cache.* (like in the StatefulEvictionPolicy 1.1.6.11) that might have an impact on my issue.
In some way they do, but unfourtunately still dont solve my problem.
The way the error message shows up is different in that it doesnt show up endlessly, but that is about it.

Since hib 3.2.CR3 also a new message shows up

...
17:23:20,031 WARN [SessionFactoryObjectFactory] InitialContext did not implemen
t EventContext ...

17:22:56,406 WARN [SessionFactoryObjectFactory] Not found: 2c9096b20c91acb4010c
91ae85a50002
17:22:56,421 WARN [SessionFactoryObjectFactory] Not found: java:Hibernate/MyHib
ernateSessionFactory

No Problem ! :-).

I have some more questions (again :- ). Rather basic, maybee somewhat "stupid" questions.
First, in each of the EJB3 SFSB Caches there is this "jboss:internal:uinitialized:null" thing. What is the purpose of this ? e.g.:

/NatPersLstSFBean
jboss:internal:uninitialized: null

 /4sgm5-99wwev-eqgp80f9-1-eqgpe5gq-7
jboss:internal:uninitialized: null
bean: org.jboss.ejb3.stateful.StatefulBeanContext@1019819

 /4sgm5-99wwev-eqgp80f9-1-eqgph66s-b
jboss:internal:uninitialized: null
bean: org.jboss.ejb3.stateful.StatefulBeanContext@1a8bce8
....

17:20:33,578 WARN [CacheLoaderInterceptor] CacheLoader.get(Fqn) returned a null
; assuming the node nodes not exist.
17:20:33,671 WARN [CacheLoaderInterceptor] The CacheLoader interface has change
d since JBossCache 1.3.x
17:20:33,671 WARN [CacheLoaderInterceptor] Please see http://jira.jboss.com/jir
a/browse/JBCACHE-118
17:20:33,671 WARN [CacheLoaderInterceptor] CacheLoader.get() should return an e
mpty Map if the node does exist but doesn't have any attributes.

java.lang.RuntimeException: cluster invocation failed, last exception was:
 at org.jboss.aspects.remoting.ClusterChooserInterceptor.invoke(ClusterChooserInterceptor.java:129)
...

Hi Ben,
thanks for the quick reply !

I some times dont get the error when I just start up the servers and run the test once (takes about 5 minutes). When I then start the test again, the error will show up, as soon as I receive the WARN from the CachLoaderInterceptor. Once this has shown up, the error will always come up, even after the 300 seconds of the eviction time out have been long passed (just after a couple of invocations the server will show the CachLoaderInterceptor Message again and the client will bail out with the "cluster invocation failed").
But it also happens that the servers, after a new start show up the CachLoaderInterceptor WARN after just one minute. So it is not really reproducible.

Sincerly

Marc

I have been on this a bit more,
the last mentioned exception still is the same.

I have been trying to get the Hibernate second level cache up, but as soon as I run more than one node in a cluster it starts failing, but to make it interessting, not always.
It complains about none serializeability of an object, (the entitys used all implement serializable). I have tried through some settings (Pessimistic/Optimistic, RW/RC/RUC/SERI, INV-ASYNC/INV_SYNC). There is some difference in the behavior, but it always ends with the same problem -> Here a shot from the output:

2006-09-05 17:12:16,989 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx
if not present for Thread[http-o06-2.somewhere.de%2F172.16.20.10-8080-3,5,jboss]
2006-09-05 17:12:16,989 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss
.cache.transaction.DummyTransaction@6f975a, handlers=[]
2006-09-05 17:12:16,989 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx
if not present for Thread[http-o06-2.somewhere.de%2F172.16.20.10-8080-3,5,jboss]
2006-09-05 17:12:16,989 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction org.jboss.cache.transaction.DummyTrans
action@6f975a is already registered.
2006-09-05 17:12:16,989 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cac
he.transaction.DummyTransaction@6f975a, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<o06-2:3299
3>:13, tx=org.jboss.cache.transaction.DummyTransaction@6f975a)]
2006-09-05 17:12:16,990 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cach
e.transaction.DummyTransaction@6f975a, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<o06-2:32993
>:13, tx=org.jboss.cache.transaction.DummyTransaction@6f975a)]
2006-09-05 17:12:16,990 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? true
2006-09-05 17:12:16,991 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTr
ansaction:<o06-2:32993>:13
2006-09-05 17:12:16,991 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
2006-09-05 17:12:17,324 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx
if not present for Thread[http-o06-2.somewhere.de%2F172.16.20.10-8080-3,5,jboss]
2006-09-05 17:12:17,331 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx
if not present for Thread[http-o06-2.somewhere.de%2F172.16.20.10-8080-3,5,jboss]
2006-09-05 17:12:17,331 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257,
GlobalId=o06-2.somewhere.de/11, BranchQual=, localId=11] is already registered.
2006-09-05 17:12:17,337 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx
if not present for Thread[http-o06-2.somewhere.de%2F172.16.20.10-8080-3,5,jboss]
2006-09-05 17:12:17,337 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257,
GlobalId=o06-2.somewhere.de/11, BranchQual=, localId=11] is already registered.
2006-09-05 17:12:17,338 DEBUG [org.jboss.cache.interceptors.InvalidationInterceptor] Is a CRUD method
2006-09-05 17:12:17,338 DEBUG [org.jboss.cache.interceptors.InvalidationInterceptor] Cache [o06-2:32996] replicating _evict(/
de/somewhere/clustertest/persi/Nation/de.somewhere.clustertest.persi.Nation#1)
2006-09-05 17:12:17,338 ERROR [org.jgroups.blocks.RpcDispatcher] exception=java.lang.IllegalArgumentException: LegacyTreeCach
eMarshaller.extractFqn(): Unknown method call name: _evict
2006-09-05 17:12:17,339 INFO [org.jboss.cache.interceptors.TxInterceptor] There was a problem handling this request
java.io.NotSerializableException: RpcDispatcher returned a null. This is most often caused by args for _replicate(_evict(/de
/somewhere/clustertest/persi/Nation/de.somewhere.clustertest.persi.Nation#1)) not being serializable.
 at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:4166)
 at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:4113)
 at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:4214)
 at org.jboss.cache.interceptors.BaseRpcInterceptor.replicateCall(BaseRpcInterceptor.java:110)
 at org.jboss.cache.interceptors.BaseRpcInterceptor.replicateCall(BaseRpcInterceptor.java:88)
 at org.jboss.cache.interceptors.InvalidationInterceptor.invalidateAcrossCluster(InvalidationInterceptor.java:157)
 at org.jboss.cache.interceptors.InvalidationInterceptor.invoke(InvalidationInterceptor.java:77)

Hi Manik,
it is Release 1.4.0.GA (July 10, 2006).
I havent tryed it with the sp1.

Sincerely
Marc

Hi Manik,

Thanks for your reply and for pointing to the SP1, sorry it took me a bit to use the 1.4.0SP1 and reply, since I needed to recompile and deploy the AS.
The last posted error vanished and I am able to use the cache now (partially).
The before mentioned "[CacheLoaderInterceptor]" trouble is still there when using the SFSB (as expected, since this is a ejb3 thing and the way they use the cache, if I am not misstaken) and always knocks out the client.

I did have some problems with the SLSB and the hib 2nd lvl cache, but I guess they are due to other causes. But just in case...
What happened when I used the cache as a Hibernate second level cache was that in when using the provided config (for hib 2nd lvl cache, altered the TM Lookup form generic to JBoss) with: