[
https://issues.jboss.org/browse/AS7-4260?page=com.atlassian.jira.plugin.s...
]
Richard Achmatowicz commented on AS7-4260:
------------------------------------------
Still looking into this one. What I can see happening is as follows:
1. when a failover occurs, a new jvmRoute is being computed by (i) looking up the cache to
get the DistributionManager (ii) finding out which addresses own the session key (iii) use
the JvmRouteRegistry to look up the new jvmRoute for the key, using the address of the
key
2. the jvmRoute is then adjusted and the request continues processing on the node which it
arrived at
3. when the request is returned, the load balancer then uses the new jvmRoute to process
the request
For example:
{noformat}
11:49:46,418 TRACE [org.jboss.as.web.session.JvmRouteValve]
(ajp-perf18-10.16.90.54-8009-361) checkJvmRoute(): check if need to re-route based on
JvmRoute. Session id: mdbFou-te-0qzdaY1T6FXyaw.perf21 jvmRoute: perf18
11:49:46,418 TRACE [org.jboss.as.web.session.JvmRouteValve]
(ajp-perf18-10.16.90.54-8009-361) handleJvmRoute(): We have detected a failover with
different jvmRoute. old one: perf21, new one: perf18. Will reset the session id.
...
11:49:46,420 TRACE [org.jboss.as.web.session.JvmRouteValve]
(ajp-perf18-10.16.90.54-8009-361) resetSessionId(): changed catalina session to=
[mdbFou-te-0qzdaY1T6FXyaw.perf19] old one= [mdbFou-te-0qzdaY1T6FXyaw.perf21]
{noformat}
In the above, the request arrives at perf18, the jvmRoute assigned is perf19 (based on key
ownership), but the request processing is completed at perf18 until the request is
returned. In processing at perf18, perf18 will have to take the global lock. If for some
reason, the global lock were not being released, then the next time the request was
processed by perf19, it would not be able to obtain the lock and the exception would
occur. This would at least explain how two requests involving the same session were
arising.
Unfortunately, when I add TRACE logging to try to see more of what is going on, the
exceptions do not occur.
Occurences of "Exception acquiring ownership of X (via
SharedLocalYieldingClusterLockManager)"
----------------------------------------------------------------------------------------------
Key: AS7-4260
URL:
https://issues.jboss.org/browse/AS7-4260
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.1.Final
Reporter: Radoslav Husar
Assignee: Richard Achmatowicz
Labels: JBAS018080
Fix For: 7.1.3.Final (EAP)
Attachments: SessionTravel.gif, view-perf18.log, view-perf19.log,
view-perf20.log, view-perf21.log
There are often occurrences of "Exception acquiring ownership of X":
During shutdown, using dist:
{noformat}
13:09:28,290 WARN [org.apache.catalina.session.ManagerBase]
(ContainerBackgroundProcessor[StandardEngine[jboss.web]]) JBAS018080: Standard expiration
of session qLQps+CQJxEi6pJTBSzis0g3 failed; switching to a brute force cleanup. Problem is
JBAS018060: Exception acquiring ownership of qLQps+CQJxEi6pJTBSzis0g3
{noformat}
During server crash, using repl:
{noformat}
12:55:49,556 INFO [org.jboss.as.clustering.impl.CoreGroupCommunicationService.ejb]
(Incoming-2,null) JBAS010248: New cluster view for partition ejb: 6
(org.jboss.as.clustering.impl.CoreGroupCommunicationService$GroupView@327579f6 delta: -1,
merge: false)
12:55:49,557 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport]
(Incoming-2,null) ISPN000094: Received new cluster view: [perf21/ejb|6] [perf21/ejb,
perf20/ejb, perf18/ejb]
12:56:31,694 ERROR [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host]]
(ajp-perf20-10.16.90.58-8009-211) Exception sending request initialized lifecycle event to
listener instance of class org.jboss.weld.servlet.WeldListener:
java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of
MvwC8KGWTuKPjD1-JjLW7URZ
at
org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:528)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1260)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at org.jboss.as.web.session.ClusteredSession.isValid(ClusteredSession.java:1208)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at org.jboss.as.web.session.ClusteredSession.isValid(ClusteredSession.java:598)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at
org.jboss.as.web.session.DistributableSessionManager.add(DistributableSessionManager.java:917)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at
org.jboss.as.web.session.DistributableSessionManager.loadSession(DistributableSessionManager.java:1407)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at
org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:686)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at
org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:85)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
at org.apache.catalina.connector.Request.doGetSession(Request.java:2618)
[jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.connector.Request.getSession(Request.java:2375)
[jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:841)
[jbossweb-7.0.13.Final.jar:]
at
org.jboss.weld.context.beanstore.http.LazySessionBeanStore.getSession(LazySessionBeanStore.java:72)
[weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at
org.jboss.weld.context.beanstore.http.LazySessionBeanStore.<init>(LazySessionBeanStore.java:58)
[weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at
org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:31)
[weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at
org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:16)
[weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.jboss.weld.servlet.WeldListener.requestInitialized(WeldListener.java:134)
[weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
[jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
[jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
[jbossweb-7.0.13.Final.jar:]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368)
[jbossweb-7.0.13.Final.jar:]
at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505)
[jbossweb-7.0.13.Final.jar:]
at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:445)
[jbossweb-7.0.13.Final.jar:]
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:930)
[jbossweb-7.0.13.Final.jar:]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
Caused by: org.jboss.as.clustering.lock.TimeoutException: JBAS010223: Cannot acquire lock
//default-host//clusterbench/MvwC8KGWTuKPjD1-JjLW7URZ from cluster
at
org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:439)
at
org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:372)
at
org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:520)
[jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
... 23 more
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see:
http://www.atlassian.com/software/jira