TimeOutException using 1.1 with fragmented cache
smievoll Sep 2, 2004 8:39 AMI'm trying to set up a fault tolerant JBossCache configuration in a WAN environment, but am experiencing a few difficulties. The current setup is 4 machines that is to be split between two locations, but currently they're connected together in a test configuration using two simple switches.
After upgrading to JC 1.1 I started getting the following TimeOutException after disconecting the cable between the switches and so creating two separate partitions of the cluster.
What is attempted to be done is the creation of two nodes in the TreeCache initiated by 10.0.0.11. The nodes should be replicated to 10.0.0.12 and it seems it's when this is beeing done the exceptions occurs.
The first log-excerpt is from my own code on 10.0.0.11. This is after both caches have accepted the new view configuration (see JBossCache logs below). Please ignore the Axis stuff, it's there because runtime exceptions isn't caught anywhere below. (I see from another thread that your working on your use of exceptions :-). From the JC logs it seems the two nodes are eventually created in 10.0.0.12, but each creation causes an exception in the initiator (10.0.0.11).
On reconnection of all four machines and subsequent merge of views this problem disappears. I'm not able to fully understand what happens; is it the remote call on 10.0.0.11 it self that times out, or is it 10.0.0.12 that's reporting a timeout. The clocks on the two machines are syncronized.
Is this intended behaviour? Would increasing the timeout values on locks help? I'm currently using these values:
<attribute name="SyncReplTimeout">15000</attribute> <attribute name="LockAcquisitionTimeout">15000</attribute> <attribute name="LockLeaseTimeout">20000</attribute>
I'm running jGroups with a TCP/TCPPING/MERGE2 configuration.
Thanks.
2004-08-31 15:11:09,031 WARN [SimpleAxisServlet] [-] "Invocation of the axis engine failed" AxisFault faultCode: {http://schemas.xmlsoap.org/soap/envelope/}Server.userException faultSubcode: faultString: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) faultActor: faultNode: faultDetail: {http://xml.apache.org/axis/}stackTrace: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3179) at org.jboss.cache.TreeCache.put(TreeCache.java:1709) at no.feide.moria.store.MoriaCacheStore.insertIntoStore(MoriaCacheStore.java:849) at no.feide.moria.store.MoriaCacheStore.createAuthnAttempt(MoriaCacheStore.java:283) at no.feide.moria.controller.MoriaController.initiateAuthentication(MoriaController.java:593) at no.feide.moria.webservices.v1_1.Authentication.initiateAuthentication(Authentication.java:102) 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:324) at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:402) at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:309) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:333) at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:71) at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:150) at org.apache.axis.SimpleChain.invoke(SimpleChain.java:120) at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:481) at org.apache.axis.server.AxisServer.invoke(AxisServer.java:323) at no.feide.moria.servlet.SimpleAxisServlet.doPost(SimpleAxisServlet.java:327) at javax.servlet.http.HttpServlet.service(HttpServlet.java:165) at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:339) at javax.servlet.http.HttpServlet.service(HttpServlet.java:103) at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:113) at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:190) at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:177) at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:221) at com.caucho.server.hmux.HmuxRequest.handleRequest(HmuxRequest.java:392) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:323) at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:430) at com.caucho.util.ThreadPool.run(ThreadPool.java:377) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2145) at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2167) at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:89) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3176) ... 30 more org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.apache.axis.AxisFault.makeFault(AxisFault.java:129) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:343) at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:71) at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:150) at org.apache.axis.SimpleChain.invoke(SimpleChain.java:120) at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:481) at org.apache.axis.server.AxisServer.invoke(AxisServer.java:323) at no.feide.moria.servlet.SimpleAxisServlet.doPost(SimpleAxisServlet.java:327) at javax.servlet.http.HttpServlet.service(HttpServlet.java:165) at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:339) at javax.servlet.http.HttpServlet.service(HttpServlet.java:103) at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:113) at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:190) at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:177) at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:221) at com.caucho.server.hmux.HmuxRequest.handleRequest(HmuxRequest.java:392) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:323) at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:430) at com.caucho.util.ThreadPool.run(ThreadPool.java:377) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3179) at org.jboss.cache.TreeCache.put(TreeCache.java:1709) at no.feide.moria.store.MoriaCacheStore.insertIntoStore(MoriaCacheStore.java:849) at no.feide.moria.store.MoriaCacheStore.createAuthnAttempt(MoriaCacheStore.java:283) at no.feide.moria.controller.MoriaController.initiateAuthentication(MoriaController.java:593) at no.feide.moria.webservices.v1_1.Authentication.initiateAuthentication(Authentication.java:102) 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:324) at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:402) at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:309) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:333) ... 18 more Caused by: org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2145) at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2167) at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:89) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3176) ... 30 more 2004-08-31 15:12:31,806 WARN [SimpleAxisServlet] [-] "Invocation of the axis engine failed" AxisFault faultCode: {http://schemas.xmlsoap.org/soap/envelope/}Server.userException faultSubcode: faultString: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) faultActor: faultNode: faultDetail: {http://xml.apache.org/axis/}stackTrace: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3179) at org.jboss.cache.TreeCache.put(TreeCache.java:1709) at no.feide.moria.store.MoriaCacheStore.insertIntoStore(MoriaCacheStore.java:849) at no.feide.moria.store.MoriaCacheStore.createAuthnAttempt(MoriaCacheStore.java:283) at no.feide.moria.controller.MoriaController.initiateAuthentication(MoriaController.java:593) at no.feide.moria.webservices.v1_1.Authentication.initiateAuthentication(Authentication.java:102) 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:324) at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:402) at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:309) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:333) at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:71) at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:150) at org.apache.axis.SimpleChain.invoke(SimpleChain.java:120) at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:481) at org.apache.axis.server.AxisServer.invoke(AxisServer.java:323) at no.feide.moria.servlet.SimpleAxisServlet.doPost(SimpleAxisServlet.java:327) at javax.servlet.http.HttpServlet.service(HttpServlet.java:165) at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:339) at javax.servlet.http.HttpServlet.service(HttpServlet.java:103) at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:113) at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:190) at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:177) at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:221) at com.caucho.server.hmux.HmuxRequest.handleRequest(HmuxRequest.java:392) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:323) at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:430) at com.caucho.util.ThreadPool.run(ThreadPool.java:377) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2145) at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2167) at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:89) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3176) ... 30 more org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.apache.axis.AxisFault.makeFault(AxisFault.java:129) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:343) at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:71) at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:150) at org.apache.axis.SimpleChain.invoke(SimpleChain.java:120) at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:481) at org.apache.axis.server.AxisServer.invoke(AxisServer.java:323) at no.feide.moria.servlet.SimpleAxisServlet.doPost(SimpleAxisServlet.java:327) at javax.servlet.http.HttpServlet.service(HttpServlet.java:165) at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:339) at javax.servlet.http.HttpServlet.service(HttpServlet.java:103) at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:113) at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:190) at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:177) at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:221) at com.caucho.server.hmux.HmuxRequest.handleRequest(HmuxRequest.java:392) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:323) at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:430) at com.caucho.util.ThreadPool.run(ThreadPool.java:377) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.util.NestedRuntimeException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false; - nested throwable: (org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3179) at org.jboss.cache.TreeCache.put(TreeCache.java:1709) at no.feide.moria.store.MoriaCacheStore.insertIntoStore(MoriaCacheStore.java:849) at no.feide.moria.store.MoriaCacheStore.createAuthnAttempt(MoriaCacheStore.java:283) at no.feide.moria.controller.MoriaController.initiateAuthentication(MoriaController.java:593) at no.feide.moria.webservices.v1_1.Authentication.initiateAuthentication(Authentication.java:102) 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:324) at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:402) at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:309) at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:333) ... 18 more Caused by: org.jboss.cache.lock.TimeoutException: rsp=sender=10.0.0.12:7890, retval=null, received=false, suspected=false at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2145) at org.jboss.cache.TreeCache.callRemoteMethods(TreeCache.java:2167) at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:89) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3176) ... 30 more
JC log 10.0.0.11:
2004-08-31 15:06:43,932 INFO [TreeCache] viewAccepted(): new members: [10.0.0.11:7890, 10.0.0.12:7890] 2004-08-31 15:10:53,856 DEBUG [TreeCache] _put(null, "/Login Ticket/ioCAix7SAAAA-rT4IndfEPtZC2RvW7*mArS0vjILMssBaocG-5eFjN1VCBOo1Uk9SRhRUWiEHKUGXWAWhcM", {MoriaData=no.feide.moria.store.MoriaAuthnAttempt@1de7497, TimeToLive=1093969373810, TicketType=Login Ticket, Principal=demo}) 2004-08-31 15:10:53,856 DEBUG [Node] createChild: fqn=/Login Ticket 2004-08-31 15:10:53,862 DEBUG [Node] createChild: fqn=/Login Ticket/ioCAix7SAAAA-rT4IndfEPtZC2RvW7*mArS0vjILMssBaocG-5eFjN1VCBOo1Uk9SRhRUWiEHKUGXWAWhcM 2004-08-31 15:10:53,863 DEBUG [TreeCache] callRemoteMethods(): valid members are [10.0.0.12:7890] 2004-08-31 15:12:16,766 DEBUG [TreeCache] _put(null, "/Login Ticket/ioCAix7SAAAA-rT5Zn7eveJfvNkqy4cRyOJuDzadpcswm6rUZYwb6Dt3BYdU-xNmuqTVtNwkJNpFZJ-uJ4s", {MoriaData=no.feide.moria.store.MoriaAuthnAttempt@13e6346, TimeToLive=1093969456766, TicketType=Login Ticket, Principal=demo}) 2004-08-31 15:12:16,767 DEBUG [Node] createChild: fqn=/Login Ticket/ioCAix7SAAAA-rT5Zn7eveJfvNkqy4cRyOJuDzadpcswm6rUZYwb6Dt3BYdU-xNmuqTVtNwkJNpFZJ-uJ4s 2004-08-31 15:12:16,767 DEBUG [TreeCache] callRemoteMethods(): valid members are [10.0.0.12:7890]
JC log 10.0.0.12:
2004-08-31 15:06:43,993 INFO [TreeCache] viewAccepted(): new members: [10.0.0.11:7890, 10.0.0.12:7890] 2004-08-31 15:13:23,771 DEBUG [TreeCache] _put(null, "/Login Ticket/ioCAix7SAAAA-rT4IndfEPtZC2RvW7*mArS0vjILMssBaocG-5eFjN1VCBOo1Uk9SRhRUWiEHKUGXWAWhcM", {TicketType=Login Ticket, TimeToLive=1093969373810, MoriaData=no.feide.moria.store.MoriaAuthnAttempt@122c9df, Principal=demo}) 2004-08-31 15:13:23,771 DEBUG [Node] createChild: fqn=/Login Ticket 2004-08-31 15:13:23,775 DEBUG [Node] createChild: fqn=/Login Ticket/ioCAix7SAAAA-rT4IndfEPtZC2RvW7*mArS0vjILMssBaocG-5eFjN1VCBOo1Uk9SRhRUWiEHKUGXWAWhcM 2004-08-31 15:16:05,701 DEBUG [TreeCache] _put(null, "/Login Ticket/ioCAix7SAAAA-rT5Zn7eveJfvNkqy4cRyOJuDzadpcswm6rUZYwb6Dt3BYdU-xNmuqTVtNwkJNpFZJ-uJ4s", {TicketType=Login Ticket, TimeToLive=1093969456766, MoriaData=no.feide.moria.store.MoriaAuthnAttempt@1a70b8, Principal=demo}) 2004-08-31 15:16:05,720 DEBUG [Node] createChild: fqn=/Login Ticket/ioCAix7SAAAA-rT5Zn7eveJfvNkqy4cRyOJuDzadpcswm6rUZYwb6Dt3BYdU-xNmuqTVtNwkJNpFZJ-uJ4s