0 Replies Latest reply on Apr 5, 2004 5:51 AM by marcoantonioni

    SFSB prolem during state replication in HA cluster (2) ? (tr

      <<< start of trace activities .... >>>

      ... from BE2 node ...
      10:58:59,673 INFO [Server] JBoss (MX MicroKernel) [3.2.3 (build: CVSTag=JBoss_3_2_3 date=200311301445)] Started in 40s:87ms
      10:59:28,124 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      10:59:28,134 INFO [STDOUT] setSessionContext
      10:59:28,134 INFO [STDOUT] ejbCreate: bean [bean-one] with [1] items to consume.
      10:59:28,144 INFO [STDOUT] ejbPassivate
      10:59:28,164 INFO [STDOUT] getHandle: org.jboss.proxy.ejb.handle.StatefulHandleImpl@104a4b6
      10:59:28,204 INFO [STDOUT] ejbActivate
      10:59:28,274 INFO [STDOUT] whoAreYou: bean-one, requester: alfa
      10:59:28,274 INFO [STDOUT] isModified: false
      10:59:28,274 INFO [STDOUT] getMaxItems: bean-one, maxItems: 1
      10:59:28,274 INFO [STDOUT] isModified: false
      10:59:28,284 INFO [STDOUT] getNextItem: bean-one, nextItem: 1
      10:59:28,284 INFO [STDOUT] isModified: false
      10:59:28,284 INFO [STDOUT] ejbRemove: bean-one
      ...

      ... the other BE1 node still silent ...
      10:58:20,006 INFO [Server] JBoss (MX MicroKernel) [3.2.3 (build: CVSTag=JBoss_3_2_3 date=200311301445)] Started in40s:758ms
      10:58:48,687 INFO [DefaultPartition] New cluster view: 2 ([192.168.1.9:1099, 192.168.1.9:1199, 192.168.1.9:1299] delta: 1)
      10:58:48,697 INFO [DefaultPartition:ReplicantManager] Dead members: 0
      ...

      try a next click on Web app, this is a lucky click !!!

      ... the request hits yet the BE2 node ...
      11:05:13,010 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:13,010 INFO [STDOUT] setSessionContext
      11:05:13,010 INFO [STDOUT] ejbCreate: bean [bean-one] with [2] items to consume.
      11:05:13,010 INFO [STDOUT] ejbPassivate
      11:05:13,020 INFO [STDOUT] getHandle: org.jboss.proxy.ejb.handle.StatefulHandleImpl@e9493a
      11:05:13,070 INFO [STDOUT] ejbActivate
      11:05:13,160 INFO [STDOUT] whoAreYou: bean-one, requester: alfa
      11:05:13,160 INFO [STDOUT] isModified: false
      11:05:13,170 INFO [STDOUT] getMaxItems: bean-one, maxItems: 2
      11:05:13,170 INFO [STDOUT] isModified: false
      11:05:13,180 INFO [STDOUT] getNextItem: bean-one, nextItem: 2
      11:05:13,180 INFO [STDOUT] isModified: false
      11:05:13,180 INFO [STDOUT] getNextItem: bean-one, nextItem: 1
      11:05:13,180 INFO [STDOUT] isModified: false
      11:05:13,190 INFO [STDOUT] ejbRemove: bean-one
      ...

      ... the other BE1 node still silent ...
      ...

      try a further click on Web app, this is NOT a lucky click !!!

      ... this time the request is routed to BE1 node ...
      11:05:17,316 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:17,326 INFO [STDOUT] setSessionContext
      11:05:17,326 INFO [STDOUT] ejbCreate: bean [bean-one] with [2] items to consume.
      11:05:17,326 INFO [STDOUT] ejbPassivate
      11:05:17,336 INFO [STDOUT] getHandle: org.jboss.proxy.ejb.handle.StatefulHandleImpl@18e8fbd
      11:05:17,376 INFO [STDOUT] ejbActivate
      ...

      and BE1 stops works without say nothing while the BE2 node go crazy ...

      ... from BE2 trace ...
      11:05:17,416 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:17,416 INFO [STDOUT] setSessionContext
      11:05:17,466 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:17,466 INFO [STDOUT] setSessionContext
      11:05:17,466 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:17,466 INFO [STDOUT] setSessionContext

      ::::: ---->>> i've intentionally omitted the whole 1304 trace rows <<<---- ::::::

      11:05:19,059 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:19,059 INFO [STDOUT] setSessionContext
      11:05:19,059 INFO [STDOUT] CTOR: TestHAEjbStatefulBean
      11:05:19,059 INFO [STDOUT] setSessionContext
      ... and stops works ...

      consequently the Web app receive a RemoteException.

      ... from front end FE1 trace ...
      10:57:34,160 INFO [Server] JBoss (MX MicroKernel) [3.2.3 (build: CVSTag=JBoss_3_2_3 date=200311301445)] Started in 35s:210ms
      10:58:08,039 INFO [DefaultPartition] New cluster view (id: 1, delta: 1) : [192.168.1.9:1099, 192.168.1.9:1199]
      10:58:08,039 INFO [DefaultPartition:ReplicantManager] Dead members: 0
      10:58:48,697 INFO [DefaultPartition] New cluster view (id: 2, delta: 1) : [192.168.1.9:1099, 192.168.1.9:1199, 192.168.1.9:1299]
      10:58:48,697 INFO [DefaultPartition:ReplicantManager] Dead members: 0
      10:59:27,914 INFO [STDOUT] Using: java.naming.provider.url = localhost:1100
      10:59:27,914 INFO [STDOUT] Using: java.naming.factory.initial = org.jnp.interfaces.NamingContextFactory
      10:59:27,924 INFO [STDOUT] Using: result jsp = result.jsp
      10:59:28,094 INFO [STDOUT] name: alfa beanName: bean-one strLoops: 1
      11:05:12,980 INFO [STDOUT] name: alfa beanName: bean-one strLoops: 1
      11:05:17,296 INFO [STDOUT] name: alfa beanName: bean-one strLoops: 1
      11:05:19,389 ERROR [STDERR] java.rmi.ServerException: RemoteException occurred in server thread; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :

      ::::: ---->>> i've intentionally omitted the whole identical trace rows <<<---- ::::::

      :
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is

      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :
      Could not get EJBObject; nested exception is:
      RuntimeErrorException: Error in MBean operation 'invoke(org.jboss.invocation.Invocation)' Cause: java.lang.StackOverflowError
      11:05:19,409 ERROR [STDERR] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:292)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.Transport$1.run(Transport.java:148)
      11:05:19,409 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
      11:05:19,409 ERROR [STDERR] at java.lang.Thread.run(Thread.java:534)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:247)
      11:05:19,409 ERROR [STDERR] at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:223)
      11:05:19,409 ERROR [STDERR] at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:133)
      11:05:19,409 ERROR [STDERR] at org.jboss.invocation.jrmp.server.JRMPInvoker_Stub.invoke(Unknown Source)
      11:05:19,409 ERROR [STDERR] at org.jboss.invocation.jrmp.interfaces.JRMPInvokerProxyHA.invoke(JRMPInvokerProxyHA.java:189)
      11:05:19,409 ERROR [STDERR] at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:96)
      11:05:19,409 ERROR [STDERR] at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
      11:05:19,409 ERROR [STDERR] at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
      11:05:19,409 ERROR [STDERR] at org.jboss.proxy.ejb.StatefulSessionInterceptor.invoke(StatefulSessionInterceptor.java:104)
      11:05:19,409 ERROR [STDERR] at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
      11:05:19,409 ERROR [STDERR] at $Proxy45.remove(Unknown Source)
      11:05:19,409 ERROR [STDERR] at it.ibm.com.it42021.test.web.ServletTestHAJBossEjbStateful.execute(ServletTestHAJBossEjbStateful.java:164)
      11:05:19,409 ERROR [STDERR] at it.ibm.com.it42021.test.web.ServletTestHAJBossEjbStateful.doGet(ServletTestHAJBossEjbStateful.java:53)
      11:05:19,409 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
      11:05:19,409 ERROR [STDERR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      11:05:19,409 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      11:05:19,419 ERROR [STDERR] at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.invoke(JBossSecurityMgrRealm.java:220)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.valves.CertificatesValve.invoke(CertificatesValve.java:246)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.jboss.web.tomcat.tc4.statistics.ContainerStatsValve.invoke(ContainerStatsValve.java:76)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.jboss.web.tomcat.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:78)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2417)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:65)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:577)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
      11:05:19,419 ERROR [STDERR] at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
      11:05:19,419 ERROR [STDERR] at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
      11:05:19,419 ERROR [STDERR] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
      11:05:19,419 ERROR [STDERR] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
      11:05:19,419 ERROR [STDERR] at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
      11:05:19,419 ERROR [STDERR] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
      11:05:19,419 ERROR [STDERR] at java.lang.Thread.run(Thread.java:534)
      11:05:19,429 ERROR [STDERR] Caused by: java.rmi.NoSuchObjectException: Could not activate; CausedByException is:
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :

      ::::: ---->>> i've intentionally omitted the whole identical trace rows <<<---- ::::::

      :
      Could not get EJBObject; nested exception is:
      java.rmi.NoSuchObjectException: Could not activate; CausedByException is
      :
      Could not get EJBObject; nested exception is:
      RuntimeErrorException: Error in MBean operation 'invoke(org.jboss.invocation.Invocation)' Cause: java.lang.StackOverflowError
      11:05:19,429 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulHASessionInstanceCache.get(StatefulHASessionInstanceCache.java:109)
      11:05:19,429 ERROR [STDERR] at org.jboss.ejb.plugins.StatefulSessionInstanceInterceptor.invoke(StatefulSessionInstanceInterceptor.java:210)
      11:05:19,429 ERROR [STDERR] at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
      11:05:19,429 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
      11:05:19,429 ERROR [STDERR] at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
      11:05:19,439 ERROR [STDERR] at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
      11:05:19,439 ERROR [STDERR] at org.jboss.ejb.plugins.CleanShutdownInterceptor.invoke(CleanShutdownInterceptor.java:264)
      11:05:19,439 ERROR [STDERR] at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
      11:05:19,439 ERROR [STDERR] at org.jboss.ejb.StatefulSessionContainer.internalInvoke(StatefulSessionContainer.java:416)
      11:05:19,439 ERROR [STDERR] at org.jboss.ejb.Container.invoke(Container.java:700)
      11:05:19,439 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
      11:05:19,439 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      11:05:19,439 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
      11:05:19,439 ERROR [STDERR] at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
      11:05:19,439 ERROR [STDERR] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
      11:05:19,439 ERROR [STDERR] at org.jboss.invocation.jrmp.server.JRMPInvokerHA.invoke(JRMPInvokerHA.java:163)
      11:05:19,439 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      11:05:19,439 ERROR [STDERR] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      11:05:19,439 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      11:05:19,439 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:324)
      11:05:19,439 ERROR [STDERR] at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
      11:05:19,439 ERROR [STDERR] at sun.rmi.transport.Transport$1.run(Transport.java:148)
      11:05:19,439 ERROR [STDERR] at java.security.AccessController.doPrivileged(Native Method)
      11:05:19,439 ERROR [STDERR] at sun.rmi.transport.Transport.serviceCall(Transport.java:144)
      11:05:19,439 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
      11:05:19,439 ERROR [STDERR] at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
      11:05:19,439 ERROR [STDERR] ... 1 more
      ...