947420 – Unable to acquire lock after [0 milliseconds] with session passivation on

Bug 947420 - Unable to acquire lock after [0 milliseconds] with session passivation on

Summary: Unable to acquire lock after [0 milliseconds] with session passivation on

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	JBoss Enterprise Application Platform 6
Classification:	JBoss
Component:	Clustering
Sub Component:
Version:	6.1.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	medium
Target Milestone:	---
Target Release:	EAP 6.1.0
Assignee:	Paul Ferraro
QA Contact:
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2013-04-02 11:28 UTC by Jitka Kozana
Modified:	2014-05-27 01:29 UTC (History)
CC List:	5 users (show)
Fixed In Version:
Clone Of:
Environment:
Last Closed:
Type:	Bug
Embargoed:

Attachments	(Terms of Use)

Description Jitka Kozana 2013-04-02 11:28:31 UTC

During soak test (cache: REPL_ASYNC) this TimeoutException were sometimes logged:

[JBossINF] ^[[0m^[[31m09:30:02,227 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [XiC7zdePhT9GUivFKtXL6+SO] for requestor [Thread[ContainerBackgroundProcessor[StandardEngine[jboss.web]],5,main]]! Lock held by [XY]
[JBossINF]      at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213)
[JBossINF]      at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196)
[JBossINF]      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114)
[JBossINF]      at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.visitEvictCommand(AbstractTxLockingInterceptor.java:79)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
[JBossINF]      at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
[JBossINF]      at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
[JBossINF]      at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.statetransfer.StateTransferInterceptor.visitEvictCommand(StateTransferInterceptor.java:179)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.CacheMgmtInterceptor.visitEvictCommand(CacheMgmtInterceptor.java:84)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
[JBossINF]      at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
[JBossINF]      at org.infinispan.commands.AbstractVisitor.visitEvictCommand(AbstractVisitor.java:87)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
[JBossINF]      at org.infinispan.interceptors.BatchingInterceptor.visitEvictCommand(BatchingInterceptor.java:66)
[JBossINF]      at org.infinispan.commands.write.EvictCommand.acceptVisitor(EvictCommand.java:49)
[JBossINF]      at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
[JBossINF]      at org.infinispan.CacheImpl.evict(CacheImpl.java:430)
[JBossINF]      at org.infinispan.CacheImpl.evict(CacheImpl.java:423)
[JBossINF]      at org.infinispan.AbstractDelegatingCache.evict(AbstractDelegatingCache.java:60)
[JBossINF]      at org.infinispan.AbstractDelegatingCache.evict(AbstractDelegatingCache.java:60)
[JBossINF]      at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$4.invoke(DistributedCacheManager.java:307)
[JBossINF]      at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$4.invoke(DistributedCacheManager.java:304)
[JBossINF]      at org.jboss.as.clustering.infinispan.invoker.SimpleCacheInvoker.invoke(SimpleCacheInvoker.java:34)
[JBossINF]      at org.jboss.as.clustering.infinispan.invoker.BatchCacheInvoker.invoke(BatchCacheInvoker.java:48)
[JBossINF]      at org.jboss.as.clustering.infinispan.invoker.RetryingCacheInvoker.invoke(RetryingCacheInvoker.java:81)
[JBossINF]      at org.jboss.as.clustering.web.infinispan.DistributedCacheManager$ForceSynchronousCacheInvoker.invoke(DistributedCacheManager.java:542)
[JBossINF]      at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.evictSession(DistributedCacheManager.java:311)
[JBossINF]      at org.jboss.as.web.session.DistributableSessionManager.processSessionPassivation(DistributableSessionManager.java:519) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.jboss.as.web.session.DistributableSessionManager.access$600(DistributableSessionManager.java:84) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.jboss.as.web.session.DistributableSessionManager$PassivationCheck.passivate(DistributableSessionManager.java:1569) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.jboss.as.web.session.DistributableSessionManager$PassivationCheck.access$300(DistributableSessionManager.java:1541) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.jboss.as.web.session.DistributableSessionManager.processExpirationPassivation(DistributableSessionManager.java:1305) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.jboss.as.web.session.AbstractSessionManager.processExpires(AbstractSessionManager.java:137) [jboss-as-web-7.2.0.Final-redhat-3.jar:7.2.0.Final-redhat-3]
[JBossINF]      at org.apache.catalina.session.ManagerBase.backgroundProcess(ManagerBase.java:367) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1302) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1588) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1600) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1600) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1574) [jbossweb-7.2.0.Final-redhat-1.jar:7.2.0.Final-redhat-1]
[JBossINF]      at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_43]
[JBossINF]

where XY was one either [null] or [GlobalTransaction:<perf19/web>:4995270:remote]

No failover occured during this test and only a few of these TO were seen during 24hrs run.

Comment 1 Jitka Kozana 2013-04-15 06:07:35 UTC

Seen again during the same test in EAP 6.1.0.ER4 testing cycle.

Comment 2 Jitka Kozana 2013-04-15 06:38:17 UTC

Link to job:
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-Clustering/view/EAP6-Clustering-Soak/job/eap-6x-clustering-soak-http-repl-async-web/24/

Link to the server.log:
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-Clustering/view/EAP6-Clustering-Soak/job/eap-6x-clustering-soak-http-repl-async-web/24/console-perf18/

Comment 3 Jitka Kozana 2013-04-29 08:41:15 UTC

Occured in ER5 runs as well. 

Link to job: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-clustering-soak-http-repl-async-web/25/

Comment 4 Radoslav Husar 2013-05-14 11:28:26 UTC

I suppose that this issue have been fixed with the Infinispan upgrade. Moving onto QA.

Comment 5 Jitka Kozana 2013-05-14 11:40:07 UTC

Verified during 6.1.0.ER8 testing (where we have the upgraded Infinispan 5.2.6.Final).

Comment 8 mark yarborough 2013-07-23 18:45:49 UTC

Details inside vpn: https://post-office.corp.redhat.com/mailman/private/eap-pm-list/2013-July/msg00105.html

Note You need to log in before you can comment on or make changes to this bug.