[JBoss JIRA] (WFLY-6498) EJBClient UserTransactions with multiple method invocations generate lock conflicts
10:07 a.m.
[
https://issues.jboss.org/browse/WFLY-6498?page=com.atlassian.jira.plugin....
]
Richard Achmatowicz edited comment on WFLY-6498 at 4/8/16 11:06 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 (DistributableCache)
// Batch is stored with bean instance (DistributableCache)
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// business part of 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 (DistributableCache)
NOTE: there are two transactions involved here: one created in CMTTx whose scope covers
the EJBClient invocation and one created in Batcher whose scope covers the ISPN operations
on Distributablecache.
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 (DistributableCache)
// Batch is stored with bean instance (DistributableCache)
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// business part of 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 (DistributableCache)
// 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.
NOTE: there are, at the moment, three transactions involved here: one created in
EJBRemoteTransactionPropagatingInterceptor whose scope covers both the EJBClient
invocations, one created in Batcher whose scope covers the ISPN operations on
DistributableCache for the first invocation, and one created in Batcher whose scope covers
the ISPN operations on DistributableCache for the second invocation. I assume that the
creation of the second Batch is to be avoided and we need to interpose the two uses of the
Batch.
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 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 (DistributableCache)
// Batch is stored with bean instance (DistributableCache)
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// business part of 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 (DistributableCache)
NOTE: there are two transactions involved here: one created in CMTTx whose scope covers
the EJBClient invocation and one created in Batcher whose scope covers the ISPN operations
on Distributablecache.
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 (DistributableCache)
// Batch is stored with bean instance (DistributableCache)
// txn synchronization is set up to call release() on txn completion
(StatefulSessionSynchronizationInterceptor)
// business part of 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 (DistributableCache)
// 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.
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)
3760
days inactive
3760
days old
0 comments
1 participants
participants (1)
-
Richard Achmatowicz (JIRA)