SFSB 3.0, replication trouble

[marcreis]

We are using a modified 4.0.4GA. StatfullRemoteProxyFactory, StatefullClusterProxyFactory, StatlessRemoteProxyFactory, StatelessClusterProxyFactory,RemoteProxyFactory and InvokerLocator have been changed. They now fetch the bindURL from a System.property, since we needed to use the host name. The invoker locator is changed (Mehtod resolveHost and Constructor) to be able to use the host name and not look it up to the ip. Also we use the ServerServletInvoker so that we can go over Http.

On maschine 1 a Statefull Bean is invoked, on maschine 2 the second invokation of the SFSB will be received cause to RoundRobin.
This results in the following warning on the second maschine

10:25:44,281 WARN [SessionFactoryObjectFactory] Not found: 2c9096850bad968e010b
ad9899550001

As a result, both SFSB are invoked on the first maschine.
After time x the SFSB will be serialized. This causes this error on the second maschine, since there is nothing there to evict:

10:31:51,468 ERROR [STDERR] java.lang.NullPointerException
10:31:51,468 ERROR [STDERR] at org.jboss.ejb3.cache.tree.StatefulEvictionPol
icy.evict(StatefulEvictionPolicy.java:48)
10:31:51,468 ERROR [STDERR] at org.jboss.cache.eviction.LRUAlgorithm.evictCa
cheNode(LRUAlgorithm.java:197)
10:31:51,468 ERROR [STDERR] at org.jboss.cache.eviction.LRUAlgorithm.prune(L
RUAlgorithm.java:303)
10:31:51,468 ERROR [STDERR] at org.jboss.cache.eviction.LRUAlgorithm.process
(LRUAlgorithm.java:55)
10:31:51,468 ERROR [STDERR] at org.jboss.cache.eviction.EvictionTimerTask.ru
n(EvictionTimerTask.java:37)
10:31:51,468 ERROR [STDERR] at java.util.TimerThread.mainLoop(Timer.java:512
)
10:31:51,468 ERROR [STDERR] at java.util.TimerThread.run(Timer.java:462)

Complete Error in the server.log which mainly shows that the hibernate SessionFactoryObjectFactory cant lookup the object:

2006-06-07 10:38:22,343 INFO [org.jboss.system.server.Server] JBoss (MX MicroKernel) [4.0.4.GA (build: CVSTag=JBoss_4_0_4_GA date=200605221016)] Started in 36s:609ms
2006-06-07 10:38:22,468 DEBUG [org.jboss.cache.eviction.RegionManager] getRegions(): size of region 2
2006-06-07 10:45:49,484 DEBUG [org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
2006-06-07 10:46:24,046 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9096850bad968e010bad9899550001
2006-06-07 10:46:24,046 WARN [org.hibernate.impl.SessionFactoryObjectFactory] Not found: 2c9096850bad968e010bad9899550001
2006-06-07 10:46:24,046 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] {2c9096b20bada466010bada468280000=org.hibernate.impl.SessionFactoryImpl@64eff0}
2006-06-07 10:46:24,046 DEBUG [org.jboss.remoting.transport.servlet.ServletServerInvoker] Error thrown calling invoke on server invoker.
org.jboss.ejb3.stateful.ForwardId: java.lang.RuntimeException: java.io.IOException
 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:314)
 at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:106)
 at org.jboss.aspects.remoting.AOPRemotingInvocationHandler.invoke(AOPRemotingInvocationHandler.java:82)
 at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:828)
 at org.jboss.remoting.transport.servlet.ServletServerInvoker.processRequest(ServletServerInvoker.java:211)
 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 javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:201)
 at $Proxy62.processRequest(Unknown Source)
 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.processRequest(ServerInvokerServlet.java:139)
 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.doPost(ServerInvokerServlet.java:168)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)
 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
 at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
 at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
 at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
 at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.RuntimeException: java.io.IOException
 at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:365)
 at org.jboss.ejb3.stateful.StatefulBeanContext.getInstance(StatefulBeanContext.java:309)
 at org.jboss.ejb3.stateful.StatefulInstanceInterceptor.invoke(StatefulInstanceInterceptor.java:75)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.remoting.ReplicantsManagerInterceptor.invoke(ReplicantsManagerInterceptor.java:51)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:78)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:47)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:308)
 ... 37 more
Caused by: java.io.IOException
 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:107)
 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:269)
 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
 at org.jboss.serial.persister.ProxyPersister.readData(ProxyPersister.java:66)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithFields(RegularObjectPersister.java:353)
 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:273)
 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
 at org.jboss.serial.persister.ArrayPersister.readObjectArray(ArrayPersister.java:196)
 at org.jboss.serial.persister.ArrayPersister.readData(ArrayPersister.java:172)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
 at org.jboss.serial.io.JBossObjectInputStream.readObjectOverride(JBossObjectInputStream.java:165)
 at java.io.ObjectInputStream.readObject(ObjectInputStream.java:333)
 at org.jboss.serial.io.MarshalledObject.get(MarshalledObject.java:68)
 at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:342)
 ... 49 more
Caused by: java.lang.reflect.InvocationTargetException
 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.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:103)
 ... 73 more
Caused by: java.io.IOException
 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:107)
 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:269)
 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)
 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)
 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)
 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithFields(RegularObjectPersister.java:353)
 at org.jboss.serial.persister.ObjectInputStreamProxy.defaultReadObject(ObjectInputStreamProxy.java:78)
 at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.readObject(ThreadLocalSessionContext.java:334)
 ... 78 more
Caused by: java.lang.reflect.InvocationTargetException
 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.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:103)
 ... 86 more
Caused by: java.io.InvalidObjectException: could not locate session factory by uuid [2c9096850bad968e010bad9899550001] during session deserialization
 at org.hibernate.impl.SessionFactoryImpl.deserialize(SessionFactoryImpl.java:1038)
 at org.hibernate.impl.SessionImpl.readObject(SessionImpl.java:1866)
 ... 91 more

Sometimes also a split of the cluster accures when invoking the SFSB (not sure if this is do to the "heavy load" when invoking the SFSB on node one, incorrect communication or what ever, just thought I would mention it).

12:37:15,796 INFO [TreeCache] viewAccepted(): [mc0430-204:1192|2] [mc0430-204:1
192]
12:37:16,531 INFO [TreeCache] viewAccepted(): [mc0430-204:1189|2] [mc0430-204:1
189]
12:37:22,609 INFO [TreeCache] viewAccepted(): [mc0430-204:1178|2] [mc0430-204:1
178]
12:37:24,031 WARN [FD] ping_dest is null: members=[mc0430-116:1361 (additional
data: 16 bytes), mc0430-204:1185 (additional data: 17 bytes)], pingable_mbrs=[mc
0430-204:1185 (additional data: 17 bytes)], local_addr=mc0430-204:1185 (addition
al data: 17 bytes)
12:37:24,531 INFO [DefaultPartition] Suspected member: mc0430-116:1361 (additio
nal data: 16 bytes)
12:37:24,531 INFO [DefaultPartition] New cluster view for partition DefaultPart
ition (id: 2, delta: -1) : [192.168.22.50:1099]
12:37:24,531 INFO [DefaultPartition] I am (192.168.22.50:1099) received membersh
ipChanged event:
12:37:24,531 INFO [DefaultPartition] Dead members: 1 ([192.168.22.5:1099])
12:37:24,531 INFO [DefaultPartition] New Members : 0 ([])
12:37:24,531 INFO [DefaultPartition] All Members : 1 ([192.168.22.50:1099])
12:37:25,093 INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../
deploy-hasingleton/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
12:37:25,468 INFO [A] Bound to JNDI name: queue/A
12:37:25,468 INFO [B] Bound to JNDI name: queue/B
12:37:25,468 INFO [C] Bound to JNDI name: queue/C
12:37:25,484 INFO [D] Bound to JNDI name: queue/D
12:37:25,484 INFO [ex] Bound to JNDI name: queue/ex
12:37:25,500 INFO [testTopic] Bound to JNDI name: topic/testTopic
12:37:25,500 INFO [securedTopic] Bound to JNDI name: topic/securedTopic
12:37:25,500 INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic

12:37:25,515 INFO [testQueue] Bound to JNDI name: queue/testQueue
12:37:25,562 INFO [UILServerILService] JBossMQ UIL service available at : mc043
0-204.somewhere.de/192.168.22.50:8093
12:37:25,625 INFO [DLQ] Bound to JNDI name: queue/DLQ
12:37:43,421 INFO [TreeCache] viewAccepted(): [mc0430-204:1189|3] [mc0430-204:1
189, mc0430-116:1397]
12:37:43,421 INFO [TreeCache] viewAccepted(): [mc0430-204:1192|3] [mc0430-204:1
192, mc0430-116:1398]
12:37:43,484 INFO [TreeCache] viewAccepted(): [mc0430-204:1178|3] [mc0430-204:1
178, mc0430-116:1396]
12:37:43,765 INFO [TreeCache] locking the / subtree to return the in-memory (tr
ansient) state
12:37:43,765 INFO [TreeCache] locking the / subtree to return the in-memory (tr
ansient) state
12:37:43,781 INFO [TreeCache] locking the / subtree to return the in-memory (tr
ansient) state
12:37:43,781 INFO [StateTransferGenerator_1241] returning the state for tree ro
oted in /(4096 bytes)
12:37:43,781 INFO [StateTransferGenerator_1241] returning the state for tree ro
oted in /(1024 bytes)
12:37:43,781 INFO [StateTransferGenerator_1241] returning the state for tree ro
oted in /(1024 bytes)
/12:37:45,062 INFO [DefaultPartition] New cluster view for partition DefaultPart
ition (id: 3, delta: 1) : [192.168.22.50:1099, 192.168.22.5:1099]
12:37:45,062 INFO [DefaultPartition] I am (192.168.22.50:1099) received membersh
ipChanged event:
12:37:45,062 INFO [DefaultPartition] Dead members: 0 ([])
12:37:45,062 INFO [DefaultPartition] New Members : 1 ([192.168.22.5:1099])
12:37:45,062 INFO [DefaultPartition] All Members : 2 ([192.168.22.50:1099, 172.1
6.22.5:1099])
12:40:25,625 WARN [SessionFactoryObjectFactory] Not found: 2c9096850badffa2010b
ae021e840001

Some more detailed logg shows a littel bit more info to the problem, but not its root:

2006-06-07 13:23:30,718 DEBUG [org.hibernate.pretty.Printer] de.somewhere.test.persi.NatPers{Vorname=Martina, Nachname=Schoßig, Id=97522}

2006-06-07 13:23:30,718 DEBUG [org.hibernate.pretty.Printer] more......

2006-06-07 13:23:30,718 DEBUG [org.hibernate.transaction.JDBCTransaction] committed JDBC Connection

2006-06-07 13:23:30,718 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection

2006-06-07 13:23:30,718 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]

2006-06-07 13:23:30,734 DEBUG [org.hibernate.impl.SessionFactoryImpl] serializing: 2c9096850bae3a54010bae3b62bb0001

2006-06-07 13:23:36,218 DEBUG [org.jboss.remoting.marshal.MarshalFactory] Tried to find marshaller from locator by both data type and class name but was unsuccessful. Will try to load it from remote server.

2006-06-07 13:23:43,421 DEBUG [org.jboss.remoting.marshal.MarshalFactory] Could not find unmarshaller by data type ('null'). Will try to load dynamically.

2006-06-07 13:23:43,437 DEBUG [org.jboss.remoting.transport.servlet.ServletServerInvoker] Error thrown calling invoke on server invoker.

org.jboss.ejb3.stateful.ForwardId: javax.ejb.EJBNoSuchObjectException: Could not find Stateful bean: 4sgm1e-z8wo26-eo5l8emd-1-eo5lfdx9-c

 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:314)

 at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:106)

 at org.jboss.aspects.remoting.AOPRemotingInvocationHandler.invoke(AOPRemotingInvocationHandler.java:82)

 at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:828)

 at org.jboss.remoting.transport.servlet.ServletServerInvoker.processRequest(ServletServerInvoker.java:211)

 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 javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:201)

 at $Proxy62.processRequest(Unknown Source)

 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.processRequest(ServerInvokerServlet.java:139)

 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.doPost(ServerInvokerServlet.java:168)

 at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

 at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)

 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)

 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)

 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)

 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)

 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)

 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)

 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)

 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)

 at org.jboss.web.tomcat.tc5.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:461)

 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)

 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)

 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)

 at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)

 at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)

 at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)

 at java.lang.Thread.run(Thread.java:595)

Caused by: javax.ejb.EJBNoSuchObjectException: Could not find Stateful bean: 4sgm1e-z8wo26-eo5l8emd-1-eo5lfdx9-c

 at org.jboss.ejb3.cache.tree.StatefulTreeCache.get(StatefulTreeCache.java:99)

 at org.jboss.ejb3.stateful.StatefulInstanceInterceptor.invoke(StatefulInstanceInterceptor.java:59)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.aspects.remoting.ReplicantsManagerInterceptor.invoke(ReplicantsManagerInterceptor.java:51)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:78)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:47)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:308)

 ... 38 more

2006-06-07 13:23:43,437 DEBUG [org.jboss.remoting.marshal.MarshalFactory] Tried to find marshaller from locator by both data type and class name but was unsuccessful. Will try to load it from remote server.

2006-06-07 13:25:44,593 DEBUG [org.jboss.remoting.marshal.MarshalFactory] Could not find unmarshaller by data type ('null'). Will try to load dynamically.

2006-06-07 13:25:44,640 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9096b20bae36da010bae37b9a90001

2006-06-07 13:25:44,640 WARN [org.hibernate.impl.SessionFactoryObjectFactory] Not found: 2c9096b20bae36da010bae37b9a90001

2006-06-07 13:25:44,718 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] {2c9096850bae3a54010bae3a56e90000=org.hibernate.impl.SessionFactoryImpl@900e24, 2c9096850bae3a54010bae3b62bb0001=org.hibernate.impl.SessionFactoryImpl@22b7f8}

2006-06-07 13:25:44,718 DEBUG [org.jboss.remoting.transport.servlet.ServletServerInvoker] Error thrown calling invoke on server invoker.

org.jboss.ejb3.stateful.ForwardId: java.lang.RuntimeException: java.io.IOException

 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:314)

 at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:106)

 at org.jboss.aspects.remoting.AOPRemotingInvocationHandler.invoke(AOPRemotingInvocationHandler.java:82)

 at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:828)

 at org.jboss.remoting.transport.servlet.ServletServerInvoker.processRequest(ServletServerInvoker.java:211)

 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 javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:201)

 at $Proxy62.processRequest(Unknown Source)

 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.processRequest(ServerInvokerServlet.java:139)

 at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.doPost(ServerInvokerServlet.java:168)

 at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

 at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)

 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)

 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)

 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)

 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)

 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)

 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)

 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)

 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)

 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)

 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)

 at org.jboss.web.tomcat.tc5.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:461)

 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)

 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)

 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)

 at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)

 at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)

 at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)

 at java.lang.Thread.run(Thread.java:595)

Caused by: java.lang.RuntimeException: java.io.IOException

 at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:365)

 at org.jboss.ejb3.stateful.StatefulBeanContext.getInstance(StatefulBeanContext.java:309)

 at org.jboss.ejb3.stateful.StatefulInstanceInterceptor.invoke(StatefulInstanceInterceptor.java:75)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.aspects.remoting.ReplicantsManagerInterceptor.invoke(ReplicantsManagerInterceptor.java:51)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:78)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:47)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)

 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)

 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:308)

 ... 38 more

Caused by: java.io.IOException

 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:107)

 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:269)

 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)

 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)

 at org.jboss.serial.persister.ProxyPersister.readData(ProxyPersister.java:66)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)

 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)

 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithFields(RegularObjectPersister.java:353)

 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:273)

 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)

 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)

 at org.jboss.serial.persister.ArrayPersister.readObjectArray(ArrayPersister.java:196)

 at org.jboss.serial.persister.ArrayPersister.readData(ArrayPersister.java:172)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)

 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)

 at org.jboss.serial.io.JBossObjectInputStream.readObjectOverride(JBossObjectInputStream.java:165)

 at java.io.ObjectInputStream.readObject(ObjectInputStream.java:333)

 at org.jboss.serial.io.MarshalledObject.get(MarshalledObject.java:68)

 at org.jboss.ejb3.stateful.StatefulBeanContext.extractBeanAndInterceptors(StatefulBeanContext.java:342)

 ... 50 more

Caused by: java.lang.reflect.InvocationTargetException

 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.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:103)

 ... 74 more

Caused by: java.io.IOException

 at org.jboss.serial.persister.RegularObjectPersister.readSlotWithMethod(RegularObjectPersister.java:107)

 at org.jboss.serial.persister.RegularObjectPersister.defaultRead(RegularObjectPersister.java:269)

 at org.jboss.serial.persister.RegularObjectPersister.readData(RegularObjectPersister.java:241)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.readObjectDescriptionFromStreaming(ObjectDescriptorFactory.java:411)

 at org.jboss.serial.objectmetamodel.ObjectDescriptorFactory.objectFromDescription(ObjectDescriptorFactory.java:81)

 at org.jboss.serial.objectmetamodel.DataContainer$DataContainerDirectInput.readObject(DataContainer.java:639)

 at org.jboss.s

I have looked over most of the ejb3/remoting/cluster code concerning the sessions replication/proxy creation to find a spot where the modifikations could cause this problem, but am not able to identify any thing specific.
From the loggs it seems like the ServletServerInvoker trys to do an invocation which leads to the hibernate.implSessionFactoryImpl trieing to serialize the SFSB und then the Marshall Factory to use the InvokerLocator to determin the Marshaller/Unmarshaller, which goes bad, for what ever reason. I checked the cluster log, but there every thing seem fine, which kind of wonders me. I thought I would find a spot where It would complain about being unable to replicate the state or give a hint to some kind of communication failure.
I would apriciate some hints on where to look for the cause of this or how to get closer to the root.

Thx !

[ben.wang]

This is too much information to read over. Can you produce a sample jar file and also client code for me try it out?

Thanks,

-Ben

[marcreis]

Hi
Sorry for the information overflow...
I guess this sums it up:

[org.jboss.cache.eviction.RegionManager] getRegions(): size of region 2
[org.jboss.resource.connectionmanager.IdleRemover] run: IdleRemover notifying pools, interval: 450000
[org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9096850bad968e010bad9899550001
[org.hibernate.impl.SessionFactoryObjectFactory] Not found: 2c9096850bad968e010bad9899550001
[org.hibernate.impl.SessionFactoryObjectFactory] {2c9096b20bada466010bada468280000=org.hibernate.impl.SessionFactoryImpl@64eff0}
[org.jboss.remoting.transport.servlet.ServletServerInvoker] Error thrown calling invoke on server invoker.
org.jboss.ejb3.stateful.ForwardId: java.lang.RuntimeException: java.io.IOException
 at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:314)
 at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:106)

I could give you an ear with the EJB's and Client, but I dont belive this would help a lot (except for clearing up the config of the client).
The App and client ist is rather simple. The App just uses a Hibernate session to do a sql query on a Oracle DB and give the result to the Client.
I guess I would need to also send you the server modifikations and setup.
The main Problem seems to be that the SFSB is not replicating correctly and so cant be invoked an the second node. This could be caused by the combination of using httpha-invoker.sar and using the host name rather than the ip. The problem is that I cant find the point were it fails, do to lack of knowledge of the things that happen on the server.

If you want I can pack that all up and send it to you.

Thanks for your time !
(and sorry for the overflow of text)

[ben.wang]

OK. Actually I am looking at the ejb3 sfsb replication now. There is one outstanding issue with the nested bean.

http://jira.jboss.com/jira/browse/EJBTHREE-612

Simply stating, it is broken for replication when you have nested bean because of replication ahppens for the nested bean first (instead of parent bean).

Your case may be slightly different though. Can you post your bean class?

[marcreis]

Sure ! Somethings might be pointless, as it is a class just for testing purpose.

@RemoteBinding(jndiBinding="EJBTEST/NatPerLstSFBean/remote")
 /* This is set as a System.property
clientBindUrl="servlet://mc0430-116.somewhere.de:8080/invoker/JNDIFactory"
*/
@LocalBinding(jndiBinding="comp/env/EJBTEST/NatPerLstSFBean/local")
@Stateful
@Clustered(partition= "DefaultPartition", loadBalancePolicy = org.jboss.ha.framework.interfaces.RoundRobin.class)
public class NatPersLstSFBean implements INatPersLstLocal,
 INatPersLstRemote,
 Serializable{
 @Resource SessionContext sctx;
 //@PersistenceManager EntityManager em;
 private int hitCount = 0;
 private Session sess = null;
 List<NatPers> myResult = null;
 private String oldletterLastName= "";

 public int getIntValue(String intString) {
 hitCount++;
 return hitCount;
 }

 @PermitAll
 public List<NatPers> getNatPersLst(String letterLastName){
 if (sess==null || sess.isConnected()==false)
 sess = new HibTestUtil().sessionFactory.getCurrentSession(); // Could this cause the problem when clustering ?

 try{
 sess.beginTransaction();
 System.out.println("about to create query");
 Query qry = sess.createSQLQuery(
 " SELECT PersonID, Name, Vorname from NATPERSON np" +
 " WHERE np.name like '"+ letterLastName + "%' " +
 " ORDER BY NAME, VORNAME" ).addEntity("np",NatPers.class);
 //qry.setCacheable(false);
 System.out.println("about to save result");
 myResult = (List<NatPers>) qry.list();
 sess.getTransaction().commit();
 }catch (Exception e){
 e.printStackTrace();
 sess.getTransaction().rollback();
 }
 String sctxUserName="";
 try{
 if (sctx !=null){
 sctxUserName = sctx.getCallerPrincipal().getName();
 System.out.println(sctxUserName);
 }
 }catch(Exception e){System.out.println(e);}

 return myResult;
 }
 @Init
 public void createSession(){
 System.out.println("I have been created by"+

 " " +this.getClass().getName());
 }
 @Remove
 public void endSession(){
 System.out.println("I am ending "+this.getClass().getName());
 }
 @PrePassivate
 public void doSerialization(){
 System.out.println("I will be serial soon "+this.getClass().getName());
 }

 @PostActivate
 public void doDeSerialization(){
 System.out.println("I am deserialized again "+this.getClass().getName());
 }
}

Mainly it fetches a hibernate session from a factory and uses this to to the query on the db and passes the result back to the client. The client invokes the methodes a couple times in a row and ends.
After what you said, could it for some reason be that the getCurrentSession() method trys to somehow use the factory of node one ?

Sincerely
Marc

[marcreis]

I have gone through all of the logs files. I thing it seems to be the problem that
Node A registers org.hibernate.impl.SessionFactoryImpl with uid x1
An invokation on A does fine, when turning to Node B "SessionFactoryObjectFactory" trys to look up the uid x1, which it cant find since node B only has y1.
Same happens the other way around when initially invoking on B, it registers the SessionFactory with uid y2 (also has y1), next invoke goes to A where it trys to look up uid y2 but A only has x1 and so the lookup in ther SesionFactoryObjectFactory fails.

a part of the server.log from Node B for this:

 ...
 DEBUG [org.hibernate.SQL] SELECT PersonID...
 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache] .... ----> CACHE HIT
 DEBUG [com.mchange.v2.c3p0.stmt.GooGooStatementCache] checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 4; checked out: 1; num connections: 2; num keys: 4

 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9096850bb7af1e010bb7b881390001
 WARN [org.hibernate.impl.SessionFactoryObjectFactory] Not found: 2c9096850bb7af1e010bb7b881390001
 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] {2c9096b20bb7bf7f010bb7bf80ca0000=org.hibernate.impl.SessionFactoryImpl@115dc7f, 2c9096b20bb7bf7f010bb7c08d670001=org.hibernate.impl.SessionFactoryImpl@4aad7f}
 DEBUG [org.jboss.remoting.transport.servlet.ServletServerInvoker] Error thrown calling invoke on server invoker.
org.jboss.ejb3.stateful.ForwardId: java.lang.RuntimeException: java.io.IOException at org.jboss.ejb3.stateful.StatefulContainer.dynamicInvoke(StatefulContainer.java:314)
 at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:106)
....

[marcreis]

I have just "stumbled" over a solution.I thought about would could cause the SessionFactory Problem (for the x't time) and had a stupid idea...
Clear the Farm folder on both nodes before start up (so all is up before deploying the App). Start the nodes up. Then drop the ear to deploy in the farm folder -> SFSB works fine.

Tried it with combinations of leaving the ear in the farm folder and then startign up -> SessionFactoryObjectFactory fails to lookup the uid.

So no inital farm no harm ;-)

[marcreis]

I guess I was to euphoric... so forget my last post :(.
Its still there. I tested invoking initialy on node 2 and deploying first on node 1. That worked, no idea why. I tried it three time and all was good. Then
I invoked first on node 1 and the problem is there again and also in other combinations of invoking and deploying.....

[ben.wang]

OK. So you are not using nested bean but a Hibernate session instead. In this case, I think Steve has just fixed this bug mentioned in EJBTHREE-612:
http://opensource.atlassian.com/projects/hibernate/browse/HHH-1816

[marcreis]

Thanks !

[marcreis]

In my case, rhe above issue still shows up.
I tried with the 3.2.rc3 (using the hibernate3.jar as well as trying to integreate this in the build of a server).

Sincerly

Marc