Affects: Release Notes project_key: JBPAPP6 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}
Link: Added: This issue Cloned from AS7-4260
Workflow: Removed: GIT Pull Request workflow Added: jira Security: Added: Public Docs QE Status: Added: NEW
We have this in EAP builds as well, ER5 confirmed.
Link: Added: This issue is related to JBPAPP-7577
Labels: Removed: JBAS018080 eap6_need_triage Added: JBAS018080 eap6_clustering eap6_need_triage
This exception is still being seen in EAP6-Failover runs as of Tuesday, May 8 (using AS7 master, at least 2 weeks more recent than ER6): http-session-jvmkill-dist-async http-session-shutdown-dist-async These exceptions do not appear in the "default" configuration REPL ASYNC. Investigation still in progress.
I am seeing this on undeploy with DIST SYNC, then trace with NPE is returned to the client: {noformat} 2012/05/20 18:51:45:417 EDT [WARN ][Runner - 382] SFCORE_LOG - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Invalid response code: 500 Content: <html><head><title>JBoss Web/7.0.16..Final-redhat-1 - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 500 - </h1><HR size="1" noshade="noshade"><p><b>type</b> Exception report</p><p><b>message</b> <u></u></p><p><b>description</b> <u>The server encountered an internal error () that prevented it from fulfilling this request.</u></p><p><b>exception</b> <pre>java.lang.NullPointerException org.jboss.as.web.session.ClusteredSession.update(ClusteredSession.java:972) org.jboss.as.web.session.DistributableSessionManager.loadSession(DistributableSessionManager.java:1377) org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:673) org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:84) org.apache.catalina.connector.Request.doGetSession(Request.java:2618) org.apache.catalina.connector.Request.getSession(Request.java:2375) org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:841) org.jboss.weld.context.beanstore.http.LazySessionBeanStore.getSession(LazySessionBeanStore.java:72) org.jboss.weld.context.beanstore.http.LazySessionBeanStore.<init>(LazySessionBeanStore.java:58) org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:31) org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:16) org.jboss.weld.servlet.WeldListener.requestInitialized(WeldListener.java:134) org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505) org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:452) org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) java.lang.Thread.run(Thread.java:662) </pre></p><p><b>note</b> <u>The full stack trace of the root cause is available in the JBoss Web/7.0.16..Final-redhat-1 logs.</u></p><HR size="1" noshade="noshade"><h3>JBoss Web/7.0.16..Final-redhat-1</h3></body></html>> org.jboss.smartfrog.loaddriver.RequestProcessingException: Invalid response code: 500 Content: <html><head><title>JBoss Web/7.0.16..Final-redhat-1 - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 500 - </h1><HR size="1" noshade="noshade"><p><b>type</b> Exception report</p><p><b>message</b> <u></u></p><p><b>description</b> <u>The server encountered an internal error () that prevented it from fulfilling this request.</u></p><p><b>exception</b> <pre>java.lang.NullPointerException org.jboss.as.web.session.ClusteredSession.update(ClusteredSession.java:972) org.jboss.as.web.session.DistributableSessionManager.loadSession(DistributableSessionManager.java:1377) org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:673) org.jboss.as.web.session.DistributableSessionManager.findSession(DistributableSessionManager.java:84) org.apache.catalina.connector.Request.doGetSession(Request.java:2618) org.apache.catalina.connector.Request.getSession(Request.java:2375) org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:841) org.jboss.weld.context.beanstore.http.LazySessionBeanStore.getSession(LazySessionBeanStore.java:72) org.jboss.weld.context.beanstore.http.LazySessionBeanStore.<init>(LazySessionBeanStore.java:58) org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:31) org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:16) org.jboss.weld.servlet.WeldListener.requestInitialized(WeldListener.java:134) org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505) org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:452) org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) java.lang.Thread.run(Thread.java:662) </pre></p><p><b>note</b> <u>The full stack trace of the root cause is available in the JBoss Web/7.0.16..Final-redhat-1 logs.</u></p><HR size="1" noshade="noshade"><h3>JBoss Web/7.0.16..Final-redhat-1</h3></body></html> at org.jboss.smartfrog.loaddriver.http.HttpRequestProcessorFactoryImpl$HttpRequestProcessor.processRequest(HttpRequestProcessorFactoryImpl.java:149) at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:51) at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:87) at java.lang.Thread.run(Thread.java:662) {noformat}
Link: Added: This issue is a dependency of JBPAPP-9290
Link: Removed: This issue is related to JBPAPP-7577
Release Notes Docs Status: Added: Documented as Known Issue Release Notes Text: Added: <para> An exception sometimes occurs during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. The exception appears in the logs as follows: </para> <screen> "Exception acquiring ownership of <replaceable>HASH</replaceable> (via SharedLocalYieldingClusterLockManager)" </screen> <para> The root cause of this exception is unknown, and this issue is under investigation. </para> Affects: Added: Release Notes
Labels: Removed: JBAS018080 eap6_clustering eap6_need_triage Added: JBAS018080 eap601candidate eap6_clustering
This issue was seen only once in the failover test runs for EAP 6.0.1.ER1 (see http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x-failover-http-session-shutdown-repl-sync/43/, perf18). When the test was rerun, the error did not appear and so is intermittent.
I believe the issue here relates to two nodes trying to get access to the same session, where one node is handling an incoming request, and the second node is performing a ClusteredSession.processExpirationPassivation() call. One question: if the session is in use on one host, why is it being expired on another, unless the node on which it expires believe it is out of date?
@Richard, well I do see "Exception acquiring ownership" in run #44 of eap-6x-failover-http-session-shutdown-repl-sync. Logs from whole cluster combined and sorted by time: {noformat} 15:19:37,506 WARN [org.jgroups.protocols.UNICAST2] perf18/ejb: sender window for perf19/ejb not found (perf18) 15:20:37,808 WARN [org.infinispan.cacheviews.CacheViewsManagerImpl] ISPN000169: Error committing cache view 5 for cache remote-connector-client-mappings: org.infinispan.util.concurrent.TimeoutException: Timed out after 60 seconds waiting for a response from perf19/ejb (perf18) 15:20:38,838 WARN [org.infinispan.cacheviews.CacheViewsManagerImpl] ISPN000169: Error committing cache view 5 for cache default-host/clusterbench: org.infinispan.CacheException: org.jgroups.TimeoutException: TimeoutException (perf18) 15:20:44,405 WARN [org.jgroups.protocols.UDP] (Timer-5,<ADDR>) null: no physical address for perf18/web, dropping message (perf20) 15:25:15,195 WARN [org.apache.catalina.session.ManagerBase] JBAS018076: Exception expiring or passivating sesion xWPhssGDzg1MxC1Dww20yfc8.perf20: java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of xWPhssGDzg1MxC1Dww20yfc8 (perf20) 15:26:07,029 WARN [org.jgroups.protocols.UDP] (Timer-5,<ADDR>) null: no physical address for perf20/ejb, dropping message (perf21) 15:26:45,088 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-3523,null) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:6378:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf21) 15:26:45,102 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ajp-perf19/10.16.90.56:8009-66) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:6378:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:26:45,112 ERROR [org.infinispan.transaction.TransactionCoordinator] (ajp-perf19/10.16.90.56:8009-66) Error while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:6378:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:26:45,121 ERROR [org.infinispan.transaction.tm.DummyTransaction] (ajp-perf19/10.16.90.56:8009-66) ISPN000109: beforeCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=6380}, status=1}, lockedKeys=null, backupKeyLocks=[yY-ANGXIqUHE0OdnQ04sZnU7], viewId=9} org.infinispan.transaction.synchronization.SyncLocalTransaction@18ea} org.infinispan.transaction.synchronization.SynchronizationAdapter@1909: org.infinispan.CacheException: Could not prepare. (perf19) 15:26:45,127 WARN [org.jboss.as.clustering.web.impl] (ajp-perf19/10.16.90.56:8009-66) JBAS010300: endBatch(): rolling back transaction with exception: javax.transaction.RollbackException: Exception rolled back, status is: 9 (perf19) 15:27:04,132 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-3746,null) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:7835:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf21) 15:27:04,146 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ajp-perf19/10.16.90.56:8009-15) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:7835:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:27:04,157 ERROR [org.infinispan.transaction.TransactionCoordinator] (ajp-perf19/10.16.90.56:8009-15) Error while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:7835:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:27:04,166 ERROR [org.infinispan.transaction.tm.DummyTransaction] (ajp-perf19/10.16.90.56:8009-15) ISPN000109: beforeCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=7837}, status=1}, lockedKeys=null, backupKeyLocks=[yY-ANGXIqUHE0OdnQ04sZnU7], viewId=9} org.infinispan.transaction.synchronization.SyncLocalTransaction@1e9b} org.infinispan.transaction.synchronization.SynchronizationAdapter@1eba: org.infinispan.CacheException: Could not prepare. (perf19) 15:27:04,169 WARN [org.jboss.as.clustering.web.impl] (ajp-perf19/10.16.90.56:8009-15) JBAS010300: endBatch(): rolling back transaction with exception: javax.transaction.RollbackException: Exception rolled back, status is: 9 (perf19) 15:27:23,175 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-3923,null) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:9133:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf21) 15:27:23,188 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ajp-perf19/10.16.90.56:8009-127) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:9133:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:27:23,198 ERROR [org.infinispan.transaction.TransactionCoordinator] (ajp-perf19/10.16.90.56:8009-127) Error while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [yY-ANGXIqUHE0OdnQ04sZnU7] for requestor [GlobalTransaction:<perf19/web>:9133:remote]! Lock held by [GlobalTransaction:<perf19/web>:6084:remote] (perf19) 15:27:23,207 ERROR [org.infinispan.transaction.tm.DummyTransaction] (ajp-perf19/10.16.90.56:8009-127) ISPN000109: beforeCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=9135}, status=1}, lockedKeys=null, backupKeyLocks=[yY-ANGXIqUHE0OdnQ04sZnU7], viewId=9} org.infinispan.transaction.synchronization.SyncLocalTransaction@23ad} org.infinispan.transaction.synchronization.SynchronizationAdapter@23cc: org.infinispan.CacheException: Could not prepare. (perf19) 15:27:23,209 WARN [org.jboss.as.clustering.web.impl] (ajp-perf19/10.16.90.56:8009-127) JBAS010300: endBatch(): rolling back transaction with exception: javax.transaction.RollbackException: Exception rolled back, status is: 9 (perf19) 15:27:59,744 WARN [org.infinispan.transaction.TransactionTable] ISPN000100: Stopping, but there are 0 local transactions and 2 remote transactions that did not finish in time. (perf21) {noformat} https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-http-session-shutdown-repl-sync/44/console-perf20/ {noformat} [JBossINF] 15:25:15,195 WARN [org.apache.catalina.session.ManagerBase] JBAS018076: Exception expiring or passivating sesion xWPhssGDzg1MxC1Dww20yfc8.perf20: java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of xWPhssGDzg1MxC1Dww20yfc8 [JBossINF] at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:528) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1259) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.clearSessions(DistributableSessionManager.java:463) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.stop(DistributableSessionManager.java:424) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] at org.apache.catalina.core.StandardContext.stop(StandardContext.java:3995) [jbossweb-7.0.16.Final.jar:] [JBossINF] at org.jboss.as.web.deployment.WebDeploymentService.stop(WebDeploymentService.java:107) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] at org.jboss.msc.service.ServiceControllerImpl$StopTask.stopService(ServiceControllerImpl.java:1911) [JBossINF] at org.jboss.msc.service.ServiceControllerImpl$StopTask.run(ServiceControllerImpl.java:1874) [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30] [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30] [JBossINF] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30] [JBossINF] Caused by: org.jboss.as.clustering.lock.TimeoutException: JBAS010213: Cannot acquire lock default-host/clusterbench/xWPhssGDzg1MxC1Dww20yfc8 from cluster [JBossINF] at org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:439) [JBossINF] at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:372) [JBossINF] at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:520) [jboss-as-web-7.1.3.Final-SNAPSHOT.jar:7.1.3.Final-SNAPSHOT] [JBossINF] ... 10 more {noformat}
This is an interesting one and here is one way of looking at it. When a request comes in, it will only be processed if it can grab a lock (which allows multiple concurrent lock holders, via permits) while passing through the locking valve. The code in DistributableSessionManager.stop() will only clear all sessions if all the permits from the lock can be retrieved (i.e. no more pending requests). This was the point of implementing the LockingValve: to synchronize incoming request processing with a server stopping, IIUC. So, in this case, DistributableSessionManager.stop() has got all the permits, and has started to clear up sessions, when another request comes in trying to lock a session being cleaned up. One of the differences since AS6 is that before every request is processed by valves (i.e. LockingValve, JvmRouteValve and ClusteredSessionValve), Weld will, if the request uses injection and is session scoped, will grab the session and use it as backing store for any injected beans, and part of this involves calling Request.getSession() which takes the global lock. This happens before the request reaches the LockingValve. I think this may be the reason for this exception. It's related to AS7-4932.
Labels: Removed: JBAS018080 eap601candidate eap6_clustering Added: JBAS018080 as713tracking eap601candidate eap6_clustering
Fixed in upstream 7.1 branch.
Labels: Removed: JBAS018080 as713tracking eap601candidate eap6_clustering Added: eap601-qe-triage
Release Notes Text: Removed: <para> An exception sometimes occurs during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. The exception appears in the logs as follows: </para> <screen> "Exception acquiring ownership of <replaceable>HASH</replaceable> (via SharedLocalYieldingClusterLockManager)" </screen> <para> The root cause of this exception is unknown, and this issue is under investigation. </para> Added: An exception sometimes occurs during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. The exception appears in the logs as follows: "Exception acquiring ownership of <replaceable>HASH</replaceable> (via SharedLocalYieldingClusterLockManager)" The root cause of this exception is unknown, and this issue is under investigation.
No "Exception acquiring ownership" was seen during EAP 6.0.1.ER2 testing.
Updating docs status, the issue is fixed, should be documented as "resolved issue" instead.
Release Notes Docs Status: Removed: Documented as Known Issue Added: Not Yet Documented Release Notes Text: Removed: An exception sometimes occurs during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. The exception appears in the logs as follows: "Exception acquiring ownership of <replaceable>HASH</replaceable> (via SharedLocalYieldingClusterLockManager)" The root cause of this exception is unknown, and this issue is under investigation.
reopening for release note updates
Writer: Added: sgilda
Writer: Removed: sgilda Added: tomwells
Release Notes Docs Status: Removed: Not Yet Documented Added: Needs More Info
Could someone clarify how this exception was fixed for the release notes please.
Release Notes Docs Status: Removed: Needs More Info Added: Documented as Resolved Issue Release Notes Text: Added: An exception sometimes occurred during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. This occurred because two threads were competing for the same lock on the key. The threads will now retry once in order to avoid the exception.
Release Notes Docs Status: Removed: Documented as Resolved Issue Writer: Removed: tomwells Release Notes Text: Removed: An exception sometimes occurred during shutdown of a cluster node when using DIST SYNC cache mode, or during a node crash when using REPL SYNC cache mode. This occurred because two threads were competing for the same lock on the key. The threads will now retry once in order to avoid the exception. Docs QE Status: Removed: NEW
This issue was left open because of documentation after JIRA -> BZ migration and was already verified. Therefore closing as verified.