[
https://issues.jboss.org/browse/WFLY-6498?page=com.atlassian.jira.plugin....
]
Richard Achmatowicz edited comment on WFLY-6498 at 4/8/16 10:44 AM:
--------------------------------------------------------------------
The problem here involves Batcher and Batch processing carried out by DistributableCache.
It also involves the order and timing in which get() and release() are called when
accessing a SFSB instance during invocation processing.
The calling of release() after an invocation has completed is set up by the EJB
interceptor StatefulSessionSynchronizationInterceptor.
If we *do not* enclose method invocations within a user transaction, here is roughly what
happens:
// method invocation arrives at server with no UserTransaction id
// no user transaction is created in RemoteTransactionRepository
(EJBRemoteTransactionPropagatingInterceptor)
// new txn is created to wrap the method invocation (CMTTxInterceptor)
// get() is used to get the SFSB instance (StatefulComponentInstanceInterceptor)
// Batch is opened on invocation thread with new txn
// Batch is stored with bean instance
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// method executes
// txn commits (CMTTxInterceptor)
// txn synchronization gets called and calls release()
// Batch associated with SFSB instance is resumed, then closed, which causes Batch txn to
commit
If we *do* enclose method invocations within a user transaction, here is roughly what
happens:
// first method invocation arrives at server with UserTransaction id
// user txn is created in RemoteTransactionRepository
(EJBRemoteTransactionPropagatingInterceptor)
// caller's txn is used to wrap the method invocation (CMTTxInterceptor)
// get() is used to get the SFSB instance (StatefulComponentInstanceInterceptor)
// Batch is opened on invocation thread with new txn
// Batch is stored with bean instance
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// method executes
// second method invocation arrives at server with UserTransaction id
// user txn is resumed in RemoteTransactionRepository
(EJBRemoteTransactionPropagatingInterceptor)
// caller's txn is used to wrap the method invocation (CMTTxInterceptor)
// get() is used to get the SFSB instance (StatefulComponentInstanceInterceptor)
// Batch is opened on invocation thread with new txn - because the new invocation is run
on a different thread and the Batch is not aware of the UserTransaction - instead of
creating a new Batch() we should really interpose
// BANG: lock conflict between the two Batches as the first Batch/transaction is still
uncommitted, has a different lockOwner and they are trying to access the same SFSB
instance
This is a rough description; i'll include a stack trace in a following comment to
illustrate details.
was (Author: rachmato):
The problem here involves Batcher and Batch processing carried out by DistributableCache.
It also involves the order and timing in which get() and release() are called when
accessing a SFSB instance during invocation processing.
The calling of release() after an invocation has completed is set up by the EJB
interceptor StatefulSessionSynchronizationInterceptor.
If we *do not* enclose method invocations within a user transaction, here is roughly what
happens:
// method invocation arrives
// txn is created to wrap the method invocation
(EJBRemoteTransactionPropagatingInterceptor, CMTTxInterceptor)
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// method executes (this involves cache operations on the SFSB instance which take locks)
// Batch is opened
// txn commits (CMTTxInterceptor)
// txn synchronization gets called and calls release()
// Batch is closed
If we *do* enclose method invocations within a user transaction, here is roughly what
happens:
// first method invocation arrives
// user txn is created to wrap the method invocation(s)
// txn synchronization is set up to call release() on txn completion
// method executes (this involves cache operations on the SFSB instance which take locks)
// Batch is opened
// txn is suspended
// Batch close does not trigger commit
// second method invocation arrives
// user txn is resumed to wrap the method invocation(s)
// method executes (this involves cache operations on the SFSB instance which take locks)
// new Batch is opened
// BANG: lock conflict as no one has yet called release()
This is a rough description; i'll include a track trace in a following comment to
illustrate details.
EJBClient UserTransactions with multiple method invocations generate
lock conflicts
------------------------------------------------------------------------------------
Key: WFLY-6498
URL:
https://issues.jboss.org/browse/WFLY-6498
Project: WildFly
Issue Type: Bug
Components: Clustering
Affects Versions: 10.0.0.Final
Reporter: Richard Achmatowicz
Assignee: Paul Ferraro
Fix For: 11.0.0.Alpha1
Using the EJBClient library, we should be able to do the following from a standalone
EJBClient application:
// create a UserTransaction associated with a clustered server node X
// make an invocation on an EJB on X
// make an invocation on an EJB on X
// commit the UserTransaction
However, doing so results in this exception which occurs during processing of the second
invocation:
{noformat}
[0m[31m11:16:22,580 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(default task-57) ISPN000136: Error executing command GetKeyValueCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after
15 seconds for key UnknownSessionID
[4967684957516649565452525270575756545166695455535750486549485166] and requestor
GlobalTransaction:<node-0>:120:local. Lock is held by
GlobalTransaction:<node-0>:118:local
at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAndRecord(AbstractLockingInterceptor.java:190)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:192)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:113)
at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:70)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:77)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
at
org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:345)
at
org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:330)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113)
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
at
org.infinispan.statetransfer.StateTransferInterceptor.visitReadCommand(StateTransferInterceptor.java:176)
at
org.infinispan.statetransfer.StateTransferInterceptor.visitGetKeyValueCommand(StateTransferInterceptor.java:153)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:76)
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113)
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:411)
at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:443)
at
org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:286)
at
org.wildfly.clustering.ejb.infinispan.bean.InfinispanBeanFactory.findValue(InfinispanBeanFactory.java:87)
at
org.wildfly.clustering.ejb.infinispan.bean.InfinispanBeanFactory.findValue(InfinispanBeanFactory.java:49)
at
org.wildfly.clustering.ejb.infinispan.InfinispanBeanManager.findBean(InfinispanBeanManager.java:244)
at
org.jboss.as.ejb3.cache.distributable.DistributableCache.get(DistributableCache.java:124)
at
org.jboss.as.ejb3.component.stateful.StatefulComponentInstanceInterceptor.processInvocation(StatefulComponentInstanceInterceptor.java:59)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:254)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:333)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
at
org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:327)
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:67)
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:200)
at
org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.processMessage(MethodInvocationMessageHandler.java:262)
at
org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:213)
at
org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:76)
at
org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:159)
{noformat}
The exception does not arise if we perform only one invocation within the
UserTransaction.
This exception is repeatable.
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)