5 Replies Latest reply on Aug 30, 2005 6:38 PM by Ben Wang

    failed to replicate session

    Bugs Bunny Newbie

      I get a problem with session replication in context with more than 600 requests (2 requests per session => 300 sessions). Up to this count all things are ready. After that the performance break in (strong) and i can't get any HTTPSession. How can i solve this problem and what is the reason?

      I use two machines with JBoss AS 4.0.1sp1 and jdk 1.4.2_06 on Windows XP:

      "Cluster1" : LoadBalancer.sar from docs with sticky session and the war and ejb modules ("all" configuration)
      "Cluster2" : just the war and ejb modules ("all" configuration)

      Here the error-message(s):

      22.Aug 16:52:19 ERROR [ControllerServletBase] [No HttpSession] doPost(): java.lang.RuntimeException: JBossCacheManager.processSessionRepl(): failed to replicate session.
      java.lang.RuntimeException: JBossCacheManager.processSessionRepl(): failed to replicate session.
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:480)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.storeSession(JBossCacheManager.java:248)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.add(JBossCacheManager.java:280)
       at org.apache.catalina.session.StandardSession.setId(StandardSession.java:354)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.createSession(JBossCacheManager.java:206)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.createSession(JBossCacheManager.java:167)
       at org.apache.coyote.tomcat5.CoyoteRequest.doGetSession(CoyoteRequest.java:2274)
       at org.apache.coyote.tomcat5.CoyoteRequest.getSession(CoyoteRequest.java:2116)
       at org.apache.coyote.tomcat5.CoyoteRequestFacade.getSession(CoyoteRequestFacade.java:526)
       at gui.web.controller.ControllerServletBase.checkHttpSession(ControllerServletBase.java:437)
       at gui.web.controller.ControllerServletBase.doPost(ControllerServletBase.java:789)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
       at gui.web.controller.AuthorityServletBase.service(AuthorityServletBase.java:188)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
       at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:75)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:186)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
       at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
       at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
       at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198)
       at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
       at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:66)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:150)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:80)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:54)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
       at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
       at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
       at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
       at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
       at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104)
       at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520)
       at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929)
       at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160)
       at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:799)
       at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
       at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:577)
       at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
       at java.lang.Thread.run(Thread.java:534)
      Caused by: org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=Swift/7635, BranchQual=, localId=7635] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.util.NestedRuntimeException: ; - nested throwable: (javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions.))
       at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:344)
       at org.jboss.tm.TxManager.commit(TxManager.java:200)
       at org.jboss.web.tomcat.tc5.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:466)
       ... 50 more
      Caused by: org.jboss.util.NestedRuntimeException: ; - nested throwable: (javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions.)
       at org.jboss.cache.interceptors.ReplicationInterceptor$SynchronizationHandler.beforeCompletion(ReplicationInterceptor.java:441)
       at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:71)
       at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1383)
       at org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1075)
       at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:296)
       ... 52 more
      Caused by: javax.transaction.NotSupportedException: Transaction already active, cannot nest transactions.
       at org.jboss.tm.TxManager.begin(TxManager.java:169)
       at org.jboss.cache.interceptors.ReplicationInterceptor.createNewLocalTransaction(ReplicationInterceptor.java:248)
       at org.jboss.cache.interceptors.ReplicationInterceptor.handlePrepare(ReplicationInterceptor.java:283)
       at org.jboss.cache.interceptors.ReplicationInterceptor.replicate(ReplicationInterceptor.java:168)
       at org.jboss.cache.TreeCache._replicate(TreeCache.java:2733)
       at sun.reflect.GeneratedMethodAccessor100.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
       at java.lang.reflect.Method.invoke(Method.java:324)
       at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236)
       at org.jgroups.blocks.RpcDispatcher.handle(RpcDispatcher.java:220)
       at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:615)
       at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:512)
       at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:326)
       at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(MessageDispatcher.java:722)
       at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(MessageDispatcher.java:554)
       at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:691)
       ... 1 more
      


        • 1. Re: failed to replicate session
          Ben Wang Master

          Can you try out 4.0.2 again to see if that helps? Also, maybe you want to use mod_jk load balancer instead?

          -Ben

          • 2. Re: failed to replicate session
            Bugs Bunny Newbie

            Hi Ben,

            when i try it with JBoss 4.0.2 i get a ClassCastException while cast the result of lookup to any of my home-interface-classes.

            private lookup(String name) {
             EJBHome home = null;
             Object ref = context.lookup(name);
             EJBMetaData meta = ((EJBHome) ref).getEJBMetaData();
            
             return (EJBHome) PortableRemoteObject.narrow(ref, meta
             .getHomeInterfaceClass());
            }
            


            The context was created like this:
            static {
             ctxInit = new Properties();
             ctxInit.put(Context.INITIAL_CONTEXT_FACTORY, "org.jnp.interfaces.NamingContextFactory");
             ctxInit.put(Context.URL_PKG_PREFIXES, "jboss.naming:org.jnp.interfaces");
             //ctxInit.put(Context.PROVIDER_URL, "localhost:1099"); //JNDI
             ctxInit.put(Context.PROVIDER_URL, "localhost:1100"); //HA-JNDI
            }
            
            ....
            
            context = new InitialContext(ctxInit);
            


            While using the version 4.0.1 it doesn't occurs any exception while lookup!

            I'M NOT AMUSED!


            • 3. Re: failed to replicate session
              Bugs Bunny Newbie

              Hi Ben,

              when i use JBoss 4.0.1sp1 + Apache2 with mod_jv v1.2 i as LoadBalancer i get some other exceptions:

              Exception #1:

              11:56:26,250 ERROR [RpcDispatcher] failed invoking method
              java.lang.UnsupportedOperationException: commit() should not be called on TreeCache directly
               at org.jboss.cache.TreeCache.commit(TreeCache.java:2783)
               at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
               at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
               at java.lang.reflect.Method.invoke(Method.java:324)
               at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236)
               at org.jboss.cache.interceptors.CallInterceptor.invoke(CallInterceptor.java:37)
               at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:40)
               at org.jboss.cache.interceptors.LockInterceptor.invoke(LockInterceptor.java:126)
               at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:40)
               at org.jboss.cache.interceptors.CreateIfNotExistsInterceptor.invoke(CreateIfNotExistsInterceptor.java:47)
               at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:40)
               at org.jboss.cache.interceptors.ReplicationInterceptor.replicate(ReplicationInterceptor.java:210)
               at org.jboss.cache.TreeCache._replicate(TreeCache.java:2733)
               at sun.reflect.GeneratedMethodAccessor181.invoke(Unknown Source)
               at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
               at java.lang.reflect.Method.invoke(Method.java:324)
               at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236)
               at org.jgroups.blocks.RpcDispatcher.handle(RpcDispatcher.java:220)
               at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:615)
               at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:512)
               at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:326)
               at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.handleUp(MessageDispatcher.java:722)
               at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.access$300(MessageDispatcher.java:554)
               at org.jgroups.blocks.MessageDispatcher$1.run(MessageDispatcher.java:691)
               at java.lang.Thread.run(Thread.java:534)
              


              Exception #2:
              11:56:24,343 ERROR [IdentityLock] read lock for /JSESSION/wind3gui/xscsNjmfjJnfLzgrpuMr1w** could not be acquired after 15000 ms. Lock map ownership Read lock owners: []
              Write lock owner: <SWIFT:1349>:1268
               (caller=Thread[TP-Processor1,5,jboss])
              11:56:24,343 INFO [STDOUT] org.jboss.cache.lock.TimeoutException: lock for /JSESSION/wind3gui/xscsNjmfjJnfLzgrpuMr1w** could not be acquired after 15000ms. Lock map ownership Read lock owners: []
              Write lock owner: <SWIFT:1349>:1268
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:227)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.Node.acquireReadLock(Node.java:418)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.Node.acquire(Node.java:399)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.LockInterceptor.lock(LockInterceptor.java:187)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.LockInterceptor.invoke(LockInterceptor.java:134)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:40)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.CreateIfNotExistsInterceptor.invoke(CreateIfNotExistsInterceptor.java:47)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:40)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:51)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3132)
              11:56:24,343 INFO [STDOUT] at org.jboss.cache.TreeCache.get(TreeCache.java:1664)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.TreeCache.get(TreeCache.java:1648)
              11:56:24,359 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor88.invoke(Unknown Source)
              11:56:24,359 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              11:56:24,359 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:144)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.server.Invocation.invoke(Invocation.java:72)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:249)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642)
              11:56:24,359 INFO [STDOUT] at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:177)
              11:56:24,359 INFO [STDOUT] at $Proxy133.get(Unknown Source)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheService._get(JBossCacheService.java:304)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheService.nodeDirty(JBossCacheService.java:576)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheService.nodeModified(JBossCacheService.java:570)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.TreeCache.notifyNodeModified(TreeCache.java:3203)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.TreeCache._put(TreeCache.java:2442)
              11:56:24,359 INFO [STDOUT] at sun.reflect.GeneratedMethodAccessor95.invoke(Unknown Source)
              11:56:24,359 INFO [STDOUT] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              11:56:24,359 INFO [STDOUT] at java.lang.reflect.Method.invoke(Method.java:324)
              11:56:24,359 INFO [STDOUT] at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.interceptors.LockInterceptor.rollback(LockInterceptor.java:285)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.interceptors.LockInterceptor.access$200(LockInterceptor.java:23)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.interceptors.LockInterceptor$SynchronizationHandler.afterCompletion(LockInterceptor.java:366)
              11:56:24,359 INFO [STDOUT] at org.jboss.cache.interceptors.OrderedSynchronizationHandler.afterCompletion(OrderedSynchronizationHandler.java:79)
              11:56:24,359 INFO [STDOUT] at org.jboss.tm.TransactionImpl.doAfterCompletion(TransactionImpl.java:1418)
              11:56:24,359 INFO [STDOUT] at org.jboss.tm.TransactionImpl.completeTransaction(TransactionImpl.java:1090)
              11:56:24,359 INFO [STDOUT] at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:341)
              11:56:24,359 INFO [STDOUT] at org.jboss.tm.TxManager.commit(TxManager.java:200)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheManager.processSessionRepl(JBossCacheManager.java:466)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.JBossCacheManager.storeSession(JBossCacheManager.java:248)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:37)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.tc5.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:91)
              11:56:24,359 INFO [STDOUT] at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
              11:56:24,359 INFO [STDOUT] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
              11:56:24,359 INFO [STDOUT] at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
              11:56:24,359 INFO [STDOUT] at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:54)
              11:56:24,359 INFO [STDOUT] at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102)
              


              I don't known but could it be that the reason of exception #2 is an overloaded network? What does you mean?

              This exception comes rarer as without mod_jk but it comes:
              22.Aug 16:52:19 ERROR [ControllerServletBase] [No HttpSession] doPost(): java.lang.RuntimeException:
               JBossCacheManager.processSessionRepl(): failed to replicate session.
              


              • 4. Re: failed to replicate session
                Bugs Bunny Newbie

                Sorry, i forgot ....

                This messages came immediately after java.lang.UnsupportedOperationException. Perhaps it can help.

                14:46:47,375 INFO [STDOUT] Can't find resource org.jboss.web.tomcat.session.LocalStrings org.jboss.web.tomcat.tc5.WebCtxLoader$ENCLoader@988dd6
                14:46:47,375 INFO [STDOUT] [Ljava.net.URL;@d86cae
                


                • 5. Re: failed to replicate session
                  Ben Wang Master

                  The other thing I'd suggest is to replace jboss-cache.jar come from 4.0.2 release and try it out again.

                  In addition, can you try out a mod_jk load balancer for your test? Taht way, we make sure node1 is not cpu bound.

                  -Ben