[jboss-jira] [JBoss JIRA] (AS7-4260) Occurences of "Exception acquiring ownership of X"

Thu Apr 19 09:00:20 EDT 2012

    [ https://issues.jboss.org/browse/AS7-4260?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12685465#comment-12685465 ] 

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 at 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