[jboss-jira] [JBoss JIRA] (WFLY-6498) EJBClient UserTransactions with multiple method invocations generate lock conflicts

Richard Achmatowicz (JIRA) issues at jboss.org
Fri Apr 8 11:07:00 EDT 2016


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

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}
> 11: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)



More information about the jboss-jira mailing list