5 Replies Latest reply on Aug 30, 2005 6:38 PM by ben.wang

failed to replicate session

xenon131 Aug 23, 2005 7:46 AM

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 Aug 24, 2005 5:31 PM (in response to xenon131)

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
Actions

2. Re: failed to replicate session

xenon131 Aug 29, 2005 6:59 AM (in response to xenon131)

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

xenon131 Aug 30, 2005 6:55 AM (in response to xenon131)

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

xenon131 Aug 30, 2005 8:53 AM (in response to xenon131)
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
Actions
5. Re: failed to replicate session

ben.wang Aug 30, 2005 6:38 PM (in response to xenon131)

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
Actions

Go to original post