[
https://issues.jboss.org/browse/AS7-4260?page=com.atlassian.jira.plugin.s...
]
Richard Achmatowicz edited comment on AS7-4260 at 4/19/12 8:59 AM:
-------------------------------------------------------------------
Some work in progress. I added some logging to JvmRouteValve, ClusteredValve and
SharedLocalYieldingClusterLockManagerSupport in order to seee (i) which session related
requests are coming into each node and (ii) what is happening when the global lock is
being acquired (which triggers the exception).
I did a run of the session replication test, processed the logs and ended up with four
logs which track the activity of a single session which triggers the exception.
I have attached the logs as view-perf18, view-perf19, view-perf20 and view-perf21.
I have also created a small graphic showing the relationships between hosts, views
received, failures and which hosts are receiving requests involving that session. The
graphic is called sessionTravel.gif. What is clear is that in view 10, both perf18 and
pef19 are trying to acquire the session ownership.
There are some issues with the JVMRoute processing which i'm still looking into. What
is odd is that two requests involving the same session are being processed by different
hosts.
was (Author: rachmato):
Some work in progress. I added some logging to JvmRouteValve, ClusteredValve and
SharedLocalYieldingClusterLockManagerSupport in order to seee (i) which session related
requests are coming into each node and (ii) what is happening when the global lock is
being acquired (which triggers the exception).
I did a run of the session replication test, processed the logs and ended up with four
logs which track the activity of a single session which triggers the exception.
I have attached the logs as view-perf18, view-perf19, view-perf20 and view-perf21.
I have also created a small graphic showing the relationships between hosts, views
received, failures and which hosts are receiving requests involving that session. The
graphic is called sessionTravel.gif. What is clear is that in view 10, both perf18 and
pef19 are trying to acquire the session ownership.
There are some issues with the JVMRoute processing which i'm still looking into.
Occurences of "Exception acquiring ownership of X"
--------------------------------------------------
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, eap6_need_triage
Fix For: 7.1.2.Final-redhat1
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