[JBoss JIRA] (ISPN-5387) CompositeNotifyingFuture wraps throwable an additional time
by William Burns (JIRA)
William Burns created ISPN-5387:
-----------------------------------
Summary: CompositeNotifyingFuture wraps throwable an additional time
Key: ISPN-5387
URL: https://issues.jboss.org/browse/ISPN-5387
Project: Infinispan
Issue Type: Bug
Components: Core
Affects Versions: 7.1.1.Final
Reporter: William Burns
Fix For: 7.2.0.CR1
The CompositeNotifyingFuture currently wraps a Throwable twice in an ExecutionException, which can cause issues with code that traverses exception chains.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
10 years, 11 months
[JBoss JIRA] (ISPN-5356) Transactional, optimistic-locked caches do not honour Flag.FAIL_SILENTLY
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-5356?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-5356:
----------------------------------------
Hi Mitchell, can you quickly verify if the issue is present when you use the latest Infinispan release which is 7.2.0.Beta2? You should be just swap the jar and try, since it's binary compatible with Infinispan 6.
> Transactional, optimistic-locked caches do not honour Flag.FAIL_SILENTLY
> ------------------------------------------------------------------------
>
> Key: ISPN-5356
> URL: https://issues.jboss.org/browse/ISPN-5356
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 6.0.2.Final
> Environment: Infinispan 6.0.2
> Hibernate ORM 4.3.6
> Apache Tomcat 8
> JDK 1.8.0_25
> Reporter: Mitchell Archibald
> Assignee: Galder Zamarreño
> Fix For: 7.2.0.Final
>
>
> There is a related issue in the Hibernate JIRA, which can be found at:
> https://hibernate.atlassian.net/browse/HHH-7898
> However, I believe this to be an Infinispan issue, as per my analysis below.
> The following Exception is thrown when two threads are simultaneously committing a JTA transaction in which an entry has been written to Hibernate's "replicated-query" cache using the same key.
> {code}
> 10:55:02.238 ERROR saction.TransactionCoordinator - ISPN000255: Error while processing prepare
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [sql: select ...; parameters: ...; named parameters: {...}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2] for requestor [GlobalTransaction:<null>:197882:local]! Lock held by [null]
> at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:198)
> at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:171)
> at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:169)
> at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:98)
> at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.lockAndRecord(OptimisticLockingInterceptor.java:211)
> at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitSingleKeyCommand(OptimisticLockingInterceptor.java:206)
> at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:199)
> at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:70)
> at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:270)
> at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:75)
> at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
> at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
> at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:36)
> at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
> at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
> at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:114)
> at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:101)
> at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
> at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
> at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112)
> at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:96)
> at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
> at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
> at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:110)
> at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:73)
> at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:96)
> at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
> at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:333)
> at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:119)
> at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:101)
> at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:44)
> at com.metiom.core.transaction.TransactionImpl.lambda$commit$0(TransactionImpl.java:115)
> at com.metiom.core.transaction.TransactionImpl$$Lambda$2/330107372.accept(Unknown Source)
> at com.metiom.core.transaction.TransactionImpl.forEachSynchronisation(TransactionImpl.java:264)
> at com.metiom.core.transaction.TransactionImpl.commit(TransactionImpl.java:114)
> at com.metiom.core.transaction.TransactionManagerImpl.commit(TransactionManagerImpl.java:142)
> at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1021)
> at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)
> at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)
> at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:497)
> at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277)
> at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
> ...
> {code}
> The configuration for Hibernate's "replicated-query" cache is as follows (from Hibernate's infinispan-configs.xml)
> {code}
> <!-- An alternative configuration for entity/collection caching that uses replication instead of invalidation -->
> <namedCache name="replicated-entity">
> <clustering mode="replication">
> <stateTransfer fetchInMemoryState="false" timeout="20000"/>
> <sync replTimeout="20000"/>
> </clustering>
> <locking isolationLevel="READ_COMMITTED" concurrencyLevel="1000"
> lockAcquisitionTimeout="15000" useLockStriping="false"/>
> <!-- Eviction configuration. WakeupInterval defines how often the eviction thread runs, in milliseconds.
> 0 means the eviction thread will never run. A separate executor is used for eviction in each cache. -->
> <eviction maxEntries="10000" strategy="LRU"/>
> <expiration maxIdle="100000" wakeUpInterval="5000"/>
> <lazyDeserialization enabled="true"/>
> <transaction transactionMode="TRANSACTIONAL" autoCommit="false"
> lockingMode="OPTIMISTIC"/>
> </namedCache>
> {code}
> Additionally, the cache is configured programmatically with:
> * {{Flag.ZERO_LOCK_ACQUISITION_TIMEOUT}}; and
> * {{Flag.FAIL_SILENTLY}}
> The situation is that two threads are concurrently attempting to lock the same key on commit.
> * During a JTA transaction, a Hibernate query is executed, and Hibernate places a result in the query cache.
> * On commit, the {{SynchronizationAdaptor}} creates a {{PrepareCommand}}, which contains one or more "modifications", one of which is a {{PutKeyValueCommand}}. The {{SynchronizationAdapter}} invokes the {{PrepareCommand}}.
> * When visited, the {{OptimisticLockingInterceptor}} loops through the modifications held by the {{PrepareCommand}} and visits each one.
> * When the {{PutKeyValueCommand}} is visited, {{LockManagerImpl}} discovers that the key is locked, and throws {{TimeoutException}}.
> * The Exception is caught by {{InvocationContextInterceptor}}, and attempts to find out whether the command it was invoking is affected by {{Flag.FAIL_SILENTLY}}. {{PrepareCommand}} does not implement {{FlagAffectedCommand}}, so this test fails and the Exception is propagated.
> It is important to note here that the {{PutKeyValueCommand}} _does_ implement {{FlagAffectedCommand}}, and _does_ have the {{Flag.FAIL_SILENTLY}} flag set. So the problem seems to be that {{OptimisticLockingInterceptor}} is unaware that the modifications to the {{PrepareCommand}} could throw Exceptions which can be suppressed.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
10 years, 11 months
[JBoss JIRA] (ISPN-5386) Tx succeeds on coord, while being rollbacked on other participants due to Tx pruning
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5386?page=com.atlassian.jira.plugin.... ]
Dan Berindei reassigned ISPN-5386:
----------------------------------
Assignee: Dan Berindei
> Tx succeeds on coord, while being rollbacked on other participants due to Tx pruning
> ------------------------------------------------------------------------------------
>
> Key: ISPN-5386
> URL: https://issues.jboss.org/browse/ISPN-5386
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Reporter: Matej Čimbora
> Assignee: Dan Berindei
>
> All participants of transaction share the same topology. TX gets successfully prepared & commited on coordinator.
> {code}
> 03:49:27,759 DEBUG [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,edg-perf08-48196) New view accepted: [edg-perf08-48196|18] (5) [edg-perf08-48196, edg-perf01-23632, edg-perf02-34805, edg-perf03-16232, edg-perf04-41106]
> 03:49:41,051 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (transport-thread-9) Installing new cache topology CacheTopology{id=53, rebalanceId=19, currentCH=DefaultConsistentHash{ns = 512, owners = (5)[edg-perf08-48196: 103+101, edg-perf01-23632: 102+103, edg-perf02-34805: 102+103, edg-perf03-16232: 102+103, edg-perf04-41106: 103+102]}, pendingCH=null, unionCH=null, actualMembers=[edg-perf08-48196, edg-perf01-23632, edg-perf02-34805, edg-perf03-16232, edg-perf04-41106]} on cache testCache
> ...
> 03:51:34,005 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-1) edg-perf08-48196 invoking PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:local, cacheName='testCache', topologyId=53} to recipient list [edg-perf03-16232, edg-perf08-48196, edg-perf02-34805, edg-perf04-41106, edg-perf01-23632]
> 03:51:36,329 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-1) Responses: [sender=edg-perf03-16232,received=true, suspected=false] [sender=edg-perf02-34805, received=true, suspected=false] [sender=edg-perf04-41106, received=true, suspected=false] [sender=edg-perf01-23632, received=true, suspected=false]
> 03:51:36,342 TRACE [org.infinispan.remoting.rpc.RpcManagerImpl] (DefaultStressor-1) edg-perf08-48196 invoking CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:local, cacheName='testCache', topologyId=53} to recipient list [edg-perf03-16232, edg-perf08-48196, edg-perf02-34805, edg-perf04-41106, edg-perf01-23632] with options RpcOptions{timeout=60000, unit=MILLISECONDS, fifoOrder=false, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS_IGNORE_LEAVERS, skipReplicationQueue=false}
> 03:51:36,703 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (DefaultStressor-1) Responses: [sender=edg-perf03-16232, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf02-34805, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf04-41106, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false] [sender=edg-perf01-23632, retval=SuccessfulResponse{responseValue=null} , received=true, suspected=false]
> {code}
> The problem is, that other participating nodes rollback it, as TX with higher id was completed before. Successfull response is returned for both prepare & commit commands.
> {code}
> 03:49:58,190 TRACE [org.infinispan.transaction.TransactionTable] (remote-thread-499) Marking transaction GlobalTransaction:<edg-perf08-48196>:13337:local as completed
> ...
> 03:51:34,122 TRACE [org.infinispan.transaction.TransactionTable] (remote-thread-593) Created and registered remote transaction RemoteTransaction{ ... lookedUpEntries={}, lockedKeys=null, backupKeyLocks=null, lookedUpEntriesTopology=2147483647, isMarkedForRollback=false, tx=GlobalTransaction:<edg-perf08-48196>:13330:remote, state=null}
> 03:51:34,073 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-593) Calling perform() on PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
> 03:51:34,342 TRACE [org.infinispan.interceptors.TxInterceptor] (remote-thread-593) Rolling back remote transaction GlobalTransaction:<edg-perf08-48196>:13330:remote because either already completed (true) or originator no longer in the cluster (false).
> 03:51:34,639 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-593) About to send back response null for command PrepareCommand { ... gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
> 03:51:36,355 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-589) Calling perform() on CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
> 03:51:36,355 TRACE [org.infinispan.commands.tx.AbstractTransactionBoundaryCommand] (remote-thread-589) Did not find a RemoteTransaction for GlobalTransaction:<edg-perf08-48196>:13330:remote
> 03:51:36,355 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread-589) About to send back response SuccessfulResponse{responseValue=null} for command CommitCommand {gtx=GlobalTransaction:<edg-perf08-48196>:13330:remote, cacheName='testCache', topologyId=53}
> {code}
> Exception response should be returned instead to avoid incorrect assumptions about presence of updated entry in the cache.
> [~dan.berindei] spotted lastPrunedTxId modifications are not logged, let's make sure they are.
--
This message was sent by Atlassian JIRA
(v6.3.11#6341)
10 years, 11 months