You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ignite.apache.org by Andrey Davydov <an...@gmail.com> on 2019/08/09 14:16:14 UTC
TimeoutException not wrapped in CacheException
On ignite 2.7.5 I got TransactionTimeoutException not wrapped
in CacheException. If it is normal behaviour and I should catch
TransactionTimeoutException too. My current logic is to
catch CacheException and check CacheException.getCause() if it
was TransactionTimeoutException.
Thanks.
Full statck trace:
Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
Failed to acquire lock within provided timeout for transaction
[timeout=150, tx=GridDhtTxLocal
[nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196, nearMiniId=1,
nearFinFutId=null, nearFinMiniId=0, nearXidVer=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1],
super=GridDhtTxLocalAdapter [nearOnOriginatingNode=false, nearNodes=[],
dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=[1895344369],
recovery=false, mvccEnabled=false, txMap=[IgniteTxEntry
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], cacheId=1895344369, txKey=IgniteTxKey
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], cacheId=1895344369], val=[op=READ, val=null],
prevVal=[op=NOOP, val=null], oldVal=[op=NOOP, val=null],
entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
explicitVer=null, dhtVer=null, filters=[], filtersPassed=false,
filtersSet=false, entry=GridDhtCacheEntry [rdrs=[], part=127,
super=GridDistributedCacheEntry [super=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=0, order=0,
nodeOrder=0], hash=1903256846, extras=GridCacheMvccEntryExtras
[mvcc=GridCacheMvcc [locs=[GridCacheMvccCandidate
[nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
[topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null, ownerVer=null,
serOrder=GridCacheVersion [topVer=176751246, order=1565274668396,
nodeOrder=1], key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true],
masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
locked=false, nodeId=null, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0,
serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0], xidVer=null],
IgniteTxEntry [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], cacheId=1895344369, txKey=IgniteTxKey
[key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], cacheId=1895344369], val=[op=DELETE, val=null],
prevVal=[op=NOOP, val=null], oldVal=[op=NOOP, val=null],
entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
explicitVer=null, dhtVer=null, filters=[], filtersPassed=false,
filtersSet=false, entry=GridDhtCacheEntry [rdrs=[], part=121,
super=GridDistributedCacheEntry [super=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
order=1565274668382, nodeOrder=2], hash=1903256840,
extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
[locs=[GridCacheMvccCandidate [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
ver=GridCacheVersion [topVer=176751246, order=1565274668397, nodeOrder=2],
threadId=883, id=412843, topVer=AffinityTopologyVersion [topVer=3,
minorTopVer=1], reentry=null,
otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491, otherVer=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1], mappedDhtNodes=null,
mappedNearNodes=null, ownerVer=null, serOrder=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1],
key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true],
masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]], prepared=1,
locked=false, nodeId=null, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0,
serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
forceSkipCompletedVers=false, super=IgniteTxAdapter
[xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
order=1565274668398, nodeOrder=2], implicit=false, loc=true, threadId=883,
startTime=1565337963940, nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
startVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], endVer=null, isolation=SERIALIZABLE, concurrency=OPTIMISTIC,
timeout=150, sysInvalidate=false, sys=false, plc=2, commitVer=null,
finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1], txCounters=null,
duration=152ms, onePhaseCommit=false], size=2]]]]
at
org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
~[ignite-core-2.7.5.jar:2.7.5]
at
org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
~[ignite-core-2.7.5.jar:2.7.5]
at
org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
~[ignite-core-2.7.5.jar:2.7.5]
at
org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
~[ignite-core-2.7.5.jar:2.7.5]
...
Caused by:
org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
Failed to acquire lock within provided timeout for transaction
[timeout=150, tx=GridDhtTxLocal
[nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196, nearMiniId=1,
nearFinFutId=null, nearFinMiniId=0, nearXidVer=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1],
super=GridDhtTxLocalAdapter [nearOnOriginatingNode=false, nearNodes=[],
dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=[1895344369],
recovery=false, mvccEnabled=false, txMap=[IgniteTxEntry
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], cacheId=1895344369, txKey=IgniteTxKey
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], cacheId=1895344369], val=[op=READ, val=null],
prevVal=[op=NOOP, val=null], oldVal=[op=NOOP, val=null],
entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
explicitVer=null, dhtVer=null, filters=[], filtersPassed=false,
filtersSet=false, entry=GridDhtCacheEntry [rdrs=[], part=127,
super=GridDistributedCacheEntry [super=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=0, order=0,
nodeOrder=0], hash=1903256846, extras=GridCacheMvccEntryExtras
[mvcc=GridCacheMvcc [locs=[GridCacheMvccCandidate
[nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
[topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null, ownerVer=null,
serOrder=GridCacheVersion [topVer=176751246, order=1565274668396,
nodeOrder=1], key=KeyCacheObjectImpl [part=127, val=cancel_queue#FIRSTG,
hasValBytes=true],
masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
locked=false, nodeId=null, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0,
serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0], xidVer=null],
IgniteTxEntry [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], cacheId=1895344369, txKey=IgniteTxKey
[key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], cacheId=1895344369], val=[op=DELETE, val=null],
prevVal=[op=NOOP, val=null], oldVal=[op=NOOP, val=null],
entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
explicitVer=null, dhtVer=null, filters=[], filtersPassed=false,
filtersSet=false, entry=GridDhtCacheEntry [rdrs=[], part=121,
super=GridDistributedCacheEntry [super=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
order=1565274668382, nodeOrder=2], hash=1903256840,
extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
[locs=[GridCacheMvccCandidate [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
ver=GridCacheVersion [topVer=176751246, order=1565274668397, nodeOrder=2],
threadId=883, id=412843, topVer=AffinityTopologyVersion [topVer=3,
minorTopVer=1], reentry=null,
otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491, otherVer=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1], mappedDhtNodes=null,
mappedNearNodes=null, ownerVer=null, serOrder=GridCacheVersion
[topVer=176751246, order=1565274668396, nodeOrder=1],
key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
hasValBytes=true],
masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]], prepared=1,
locked=false, nodeId=null, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0,
serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
forceSkipCompletedVers=false, super=IgniteTxAdapter
[xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
order=1565274668398, nodeOrder=2], implicit=false, loc=true, threadId=883,
startTime=1565337963940, nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
startVer=GridCacheVersion [topVer=176751246, order=1565274668397,
nodeOrder=2], endVer=null, isolation=SERIALIZABLE, concurrency=OPTIMISTIC,
timeout=150, sysInvalidate=false, sys=false, plc=2, commitVer=null,
finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1], txCounters=null,
duration=152ms, onePhaseCommit=false], size=2]]]]
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
~[ignite-core-2.7.5.jar:2.7.5]
at
org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
~[ignite-core-2.7.5.jar:2.7.5]
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
~[ignite-core-2.7.5.jar:2.7.5]
... 1 more
RE: TimeoutException not wrapped in CacheException
Posted by Andrey Davydov <an...@gmail.com>.
Please update documentation on https://apacheignite.readme.io/docs/transactions#section-handling-failed-transactions
Andrey.
От: Andrei Aleksandrov
Отправлено: 9 августа 2019 г. в 18:35
Кому: user@ignite.apache.org
Тема: Re: TimeoutException not wrapped in CacheException
Hi,
Sorry, it's my fault.
I thought that you get TransactionTimeoutExceptionfrom from some IgniteCache method. So it's not expected there.
From commit method you can't get the CacheException of course.
So I guess that you should handle only exceptions that mentioned in Java Doc.
BR,
Andrei
8/9/2019 6:21 PM, Andrey Davydov пишет:
As I see In javadocs for org.apache.ignite.transactions.Transaction
/**
* Commits this transaction by initiating {@code two-phase-commit} process.
*
* @throws IgniteException If commit failed.
* @throws TransactionTimeoutException If transaction is timed out.
* @throws TransactionRollbackException If transaction is automatically rolled back.
* @throws TransactionOptimisticException If transaction concurrency is {@link TransactionConcurrency#OPTIMISTIC}
* and commit is optimistically failed.
* @throws TransactionHeuristicException If transaction has entered an unknown state.
*/
@IgniteAsyncSupported
public void commit() throws IgniteException;
And as we see in trace, exception come from org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit
So system behaviour meets javadoc but don't meet docs and example on https://apacheignite.readme.io/docs/transactions
On Fri, Aug 9, 2019 at 6:12 PM Andrey Davydov <an...@gmail.com> wrote:
Sorry fo misprint, test does not check that there are no any way to get TimeoutException
On Fri, Aug 9, 2019 at 5:55 PM Andrey Davydov <an...@gmail.com> wrote:
It is a little bit difficult to reproduce. We got unhadled exception on pre prod performance test of our system. I will try to reproduce it on weekend.
You test just check that if you get CacheException then TimeoutException is inside it, but doesn't check that there are no any way to get CacheException. As I check listened in stack trace lines from 2.7.5 sources (loaded from maven), i dont see where TOE shoud be wrapped to CE
If there is full list of Exceptions when it is valid to retry transaction (Optimistic or Pessimistic). As I found in different pages of docs, now I catch (optimistic tx):
TransactionOptimisticException - try to rerun transaction
ClusterTopologyException - retryReadyFuture().get() and try to rerun transaction
CacheException check if getCause is Timeout then try to rerun or rethrow in other cases
Thanks.
On Fri, Aug 9, 2019 at 5:31 PM Andrei Aleksandrov <ae...@gmail.com> wrote:
Hi,
It looks strange because even Ignite tests expect that
TransactionTimeoutException will be wrapped in CacheException. For
example IgniteTxConfigCacheSelfTest:
try (final Transaction tx = ignite.transactions().txStart()) {
assert tx != null;
cache.put("key0", "val0");
sleepForTxFailure();
cache.put("key", "val");
fail("Timeout exception must be thrown");
}
catch (CacheException e) {
assert e.getCause() instanceof TransactionTimeoutException;
}
So could you please provide the reproducer for your issue? We will check
it and create the JIRA for it.
BR,
Andrei
8/9/2019 5:16 PM, Andrey Davydov пишет:
> On ignite 2.7.5 I got TransactionTimeoutException not wrapped
> in CacheException. If it is normal behaviour and I should catch
> TransactionTimeoutException too. My current logic is to
> catch CacheException and check CacheException.getCause() if it
> was TransactionTimeoutException.
>
> Thanks.
>
> Full statck trace:
>
> Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
> Failed to acquire lock within provided timeout for transaction
> [timeout=150, tx=GridDhtTxLocal
> [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=[],
> dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> super=IgniteTxLocalAdapter [completedBase=null,
> sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> [rdrs=[], part=127, super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
> prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry [rdrs=[], part=121,
> super=GridDistributedCacheEntry [super=GridCacheMapEntry
> [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> order=1565274668382, nodeOrder=2], hash=1903256840,
> extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
> prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> prepared=1, locked=false, nodeId=null, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> forceSkipCompletedVers=false, super=IgniteTxAdapter
> [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> threadId=883, startTime=1565337963940,
> nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> sysInvalidate=false, sys=false, plc=2, commitVer=null,
> finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> at
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
> ~[ignite-core-2.7.5.jar:2.7.5]
> ...
> Caused by:
> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
> Failed to acquire lock within provided timeout for transaction
> [timeout=150, tx=GridDhtTxLocal
> [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=[],
> dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> super=IgniteTxLocalAdapter [completedBase=null,
> sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> [rdrs=[], part=127, super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
> prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry [rdrs=[], part=121,
> super=GridDistributedCacheEntry [super=GridCacheMapEntry
> [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> order=1565274668382, nodeOrder=2], hash=1903256840,
> extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
> prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> prepared=1, locked=false, nodeId=null, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> forceSkipCompletedVers=false, super=IgniteTxAdapter
> [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> threadId=883, startTime=1565337963940,
> nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> sysInvalidate=false, sys=false, plc=2, commitVer=null,
> finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> ~[ignite-core-2.7.5.jar:2.7.5]
> ... 1 more
Re: TimeoutException not wrapped in CacheException
Posted by Andrei Aleksandrov <ae...@gmail.com>.
Hi,
Sorry, it's my fault.
I thought that you get TransactionTimeoutExceptionfrom from some
IgniteCache method. So it's not expected there.
From commit method you can't get the CacheException of course.
So I guess that you should handle only exceptions that mentioned in Java
Doc.
BR,
Andrei
8/9/2019 6:21 PM, Andrey Davydov пишет:
> As I see In javadocs for org.apache.ignite.transactions.Transaction
>
> /**
> * Commits this transaction by initiating {@code two-phase-commit}
> process.
> *
> * @throws IgniteException If commit failed.
> * @throws TransactionTimeoutException If transaction is timed out.
> * @throws TransactionRollbackException If transaction is
> automatically rolled back.
> * @throws TransactionOptimisticException If transaction
> concurrency is {@link TransactionConcurrency#OPTIMISTIC}
> * and commit is optimistically failed.
> * @throws TransactionHeuristicException If transaction has
> entered an unknown state.
> */
> @IgniteAsyncSupported
> public void commit() throws IgniteException;
>
> And as we see in trace, exception come
> from org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit
> So system behaviour meets javadoc but don't meet docs and example on
> https://apacheignite.readme.io/docs/transactions
>
>
> On Fri, Aug 9, 2019 at 6:12 PM Andrey Davydov
> <andrey.davydov@gmail.com <ma...@gmail.com>> wrote:
>
> Sorry fo misprint, test does not check that there are no any way
> to get TimeoutException
>
> On Fri, Aug 9, 2019 at 5:55 PM Andrey Davydov
> <andrey.davydov@gmail.com <ma...@gmail.com>> wrote:
>
> It is a little bit difficult to reproduce. We got unhadled
> exception on pre prod performance test of our system. I will
> try to reproduce it on weekend.
>
> You test just check that if you get CacheException then
> TimeoutException is inside it, but doesn't check that there
> are no any way to get CacheException. As I check listened in
> stack trace lines from 2.7.5 sources (loaded from maven), i
> dont see where TOE shoud be wrapped to CE
>
> If there is full list of Exceptions when it is valid to retry
> transaction (Optimistic or Pessimistic). As I found in
> different pages of docs, now I catch (optimistic tx):
> TransactionOptimisticException - try to rerun transaction
> ClusterTopologyException - retryReadyFuture().get() and try to
> rerun transaction
> CacheException check if getCause is Timeout then try to rerun
> or rethrow in other cases
>
> Thanks.
>
> On Fri, Aug 9, 2019 at 5:31 PM Andrei Aleksandrov
> <aealexsandrov@gmail.com <ma...@gmail.com>> wrote:
>
> Hi,
>
> It looks strange because even Ignite tests expect that
> TransactionTimeoutException will be wrapped
> in CacheException. For
> example IgniteTxConfigCacheSelfTest:
>
> try (final Transaction tx =
> ignite.transactions().txStart()) {
> assert tx != null;
>
> cache.put("key0", "val0");
>
> sleepForTxFailure();
>
> cache.put("key", "val");
>
> fail("Timeout exception must be thrown");
> }
> catch (CacheException e) {
> assert e.getCause() instanceof
> TransactionTimeoutException;
> }
>
> So could you please provide the reproducer for your issue?
> We will check
> it and create the JIRA for it.
>
> BR,
> Andrei
>
> 8/9/2019 5:16 PM, Andrey Davydov пишет:
> > On ignite 2.7.5 I got TransactionTimeoutException not
> wrapped
> > in CacheException. If it is normal behaviour and I
> should catch
> > TransactionTimeoutException too. My current logic is to
> > catch CacheException and check CacheException.getCause()
> if it
> > was TransactionTimeoutException.
> >
> > Thanks.
> >
> > Full statck trace:
> >
> > Caused by:
> org.apache.ignite.transactions.TransactionTimeoutException:
> > Failed to acquire lock within provided timeout for
> transaction
> > [timeout=150, tx=GridDhtTxLocal
> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> > nearXidVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], super=GridDhtTxLocalAdapter
> > [nearOnOriginatingNode=false, nearNodes=[],
> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> > super=IgniteTxLocalAdapter [completedBase=null,
> > sndTransformedVals=false, depEnabled=false,
> txState=IgniteTxStateImpl
> > [activeCacheIds=[1895344369], recovery=false,
> mvccEnabled=false,
> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> cacheId=1895344369],
> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP,
> > val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1,
> > conflictVer=null, explicitVer=null, dhtVer=null,
> filters=[],
> > filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry
> > [rdrs=[], part=127, super=GridDistributedCacheEntry
> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > hash=1903256846, extras=GridCacheMvccEntryExtras
> [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> threadId=883,
> > id=412844, topVer=AffinityTopologyVersion [topVer=3,
> minorTopVer=1],
> > reentry=null,
> otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1],
> key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>
> > prevVer=GridCacheVersion [topVer=176751246,
> order=1565274668397,
> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]],
> prepared=1,
> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0,
> nodeOrder=0],
> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl
> [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> cacheId=1895344369],
> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null,
> ttl=-1,
> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> > dhtVer=null, filters=[], filtersPassed=false,
> filtersSet=false,
> > entry=GridDhtCacheEntry [rdrs=[], part=121,
> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> > hasValBytes=true], val=null, ver=GridCacheVersion
> [topVer=176751246,
> > order=1565274668382, nodeOrder=2], hash=1903256840,
> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> threadId=883,
> > id=412843, topVer=AffinityTopologyVersion [topVer=3,
> minorTopVer=1],
> > reentry=null,
> otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1],
> key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>
> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> > order=1565274668397, nodeOrder=2]]], rmts=null]],
> flags=3]]],
> > prepared=1, locked=false, nodeId=null, locMapped=false,
> > expiryPlc=null, transferExpiryPlc=false, flags=0,
> partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0,
> nodeOrder=0],
> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> > forceSkipCompletedVers=false, super=IgniteTxAdapter
> > [xidVer=GridCacheVersion [topVer=176751246,
> order=1565274668397,
> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> > order=1565274668398, nodeOrder=2], implicit=false,
> loc=true,
> > threadId=883, startTime=1565337963940,
> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> startVer=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> endVer=null,
> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC,
> timeout=150,
> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
> > finalizing=NONE, invalidParts=null, state=PREPARING,
> timedOut=false,
> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > txCounters=null, duration=152ms, onePhaseCommit=false],
> size=2]]]]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > ...
> > Caused by:
> >
> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
>
> > Failed to acquire lock within provided timeout for
> transaction
> > [timeout=150, tx=GridDhtTxLocal
> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> > nearXidVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], super=GridDhtTxLocalAdapter
> > [nearOnOriginatingNode=false, nearNodes=[],
> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> > super=IgniteTxLocalAdapter [completedBase=null,
> > sndTransformedVals=false, depEnabled=false,
> txState=IgniteTxStateImpl
> > [activeCacheIds=[1895344369], recovery=false,
> mvccEnabled=false,
> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> cacheId=1895344369],
> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP,
> > val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1,
> > conflictVer=null, explicitVer=null, dhtVer=null,
> filters=[],
> > filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry
> > [rdrs=[], part=127, super=GridDistributedCacheEntry
> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > hash=1903256846, extras=GridCacheMvccEntryExtras
> [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> threadId=883,
> > id=412844, topVer=AffinityTopologyVersion [topVer=3,
> minorTopVer=1],
> > reentry=null,
> otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1],
> key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>
> > prevVer=GridCacheVersion [topVer=176751246,
> order=1565274668397,
> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]],
> prepared=1,
> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0,
> nodeOrder=0],
> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl
> [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> cacheId=1895344369],
> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null,
> ttl=-1,
> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> > dhtVer=null, filters=[], filtersPassed=false,
> filtersSet=false,
> > entry=GridDhtCacheEntry [rdrs=[], part=121,
> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> > hasValBytes=true], val=null, ver=GridCacheVersion
> [topVer=176751246,
> > order=1565274668382, nodeOrder=2], hash=1903256840,
> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> threadId=883,
> > id=412843, topVer=AffinityTopologyVersion [topVer=3,
> minorTopVer=1],
> > reentry=null,
> otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246,
> order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1],
> key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>
> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> > order=1565274668397, nodeOrder=2]]], rmts=null]],
> flags=3]]],
> > prepared=1, locked=false, nodeId=null, locMapped=false,
> > expiryPlc=null, transferExpiryPlc=false, flags=0,
> partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0,
> nodeOrder=0],
> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> > forceSkipCompletedVers=false, super=IgniteTxAdapter
> > [xidVer=GridCacheVersion [topVer=176751246,
> order=1565274668397,
> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> > order=1565274668398, nodeOrder=2], implicit=false,
> loc=true,
> > threadId=883, startTime=1565337963940,
> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752,
> startVer=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2],
> endVer=null,
> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC,
> timeout=150,
> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
> > finalizing=NONE, invalidParts=null, state=PREPARING,
> timedOut=false,
> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > txCounters=null, duration=152ms, onePhaseCommit=false],
> size=2]]]]
> > at
> >
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > ... 1 more
>
Re: TimeoutException not wrapped in CacheException
Posted by Andrey Davydov <an...@gmail.com>.
As I see In javadocs for org.apache.ignite.transactions.Transaction
/**
* Commits this transaction by initiating {@code two-phase-commit}
process.
*
* @throws IgniteException If commit failed.
* @throws TransactionTimeoutException If transaction is timed out.
* @throws TransactionRollbackException If transaction is automatically
rolled back.
* @throws TransactionOptimisticException If transaction concurrency is
{@link TransactionConcurrency#OPTIMISTIC}
* and commit is optimistically failed.
* @throws TransactionHeuristicException If transaction has entered an
unknown state.
*/
@IgniteAsyncSupported
public void commit() throws IgniteException;
And as we see in trace, exception come
from org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit
So system behaviour meets javadoc but don't meet docs and example on
https://apacheignite.readme.io/docs/transactions
On Fri, Aug 9, 2019 at 6:12 PM Andrey Davydov <an...@gmail.com>
wrote:
> Sorry fo misprint, test does not check that there are no any way to get
> TimeoutException
>
> On Fri, Aug 9, 2019 at 5:55 PM Andrey Davydov <an...@gmail.com>
> wrote:
>
>> It is a little bit difficult to reproduce. We got unhadled exception on
>> pre prod performance test of our system. I will try to reproduce it on
>> weekend.
>>
>> You test just check that if you get CacheException then TimeoutException
>> is inside it, but doesn't check that there are no any way to get
>> CacheException. As I check listened in stack trace lines from 2.7.5 sources
>> (loaded from maven), i dont see where TOE shoud be wrapped to CE
>>
>> If there is full list of Exceptions when it is valid to retry transaction
>> (Optimistic or Pessimistic). As I found in different pages of docs, now I
>> catch (optimistic tx):
>> TransactionOptimisticException - try to rerun transaction
>> ClusterTopologyException - retryReadyFuture().get() and try to rerun
>> transaction
>> CacheException check if getCause is Timeout then try to rerun or rethrow
>> in other cases
>>
>> Thanks.
>>
>> On Fri, Aug 9, 2019 at 5:31 PM Andrei Aleksandrov <
>> aealexsandrov@gmail.com> wrote:
>>
>>> Hi,
>>>
>>> It looks strange because even Ignite tests expect that
>>> TransactionTimeoutException will be wrapped in CacheException. For
>>> example IgniteTxConfigCacheSelfTest:
>>>
>>> try (final Transaction tx = ignite.transactions().txStart()) {
>>> assert tx != null;
>>>
>>> cache.put("key0", "val0");
>>>
>>> sleepForTxFailure();
>>>
>>> cache.put("key", "val");
>>>
>>> fail("Timeout exception must be thrown");
>>> }
>>> catch (CacheException e) {
>>> assert e.getCause() instanceof TransactionTimeoutException;
>>> }
>>>
>>> So could you please provide the reproducer for your issue? We will check
>>> it and create the JIRA for it.
>>>
>>> BR,
>>> Andrei
>>>
>>> 8/9/2019 5:16 PM, Andrey Davydov пишет:
>>> > On ignite 2.7.5 I got TransactionTimeoutException not wrapped
>>> > in CacheException. If it is normal behaviour and I should catch
>>> > TransactionTimeoutException too. My current logic is to
>>> > catch CacheException and check CacheException.getCause() if it
>>> > was TransactionTimeoutException.
>>> >
>>> > Thanks.
>>> >
>>> > Full statck trace:
>>> >
>>> > Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
>>> > Failed to acquire lock within provided timeout for transaction
>>> > [timeout=150, tx=GridDhtTxLocal
>>> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
>>> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
>>> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], super=GridDhtTxLocalAdapter
>>> > [nearOnOriginatingNode=false, nearNodes=[],
>>> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
>>> > super=IgniteTxLocalAdapter [completedBase=null,
>>> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
>>> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
>>> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
>>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
>>> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
>>> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
>>> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
>>> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
>>> > [rdrs=[], part=127, super=GridDistributedCacheEntry
>>> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
>>> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>>> > [locs=[GridCacheMvccCandidate
>>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>>> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true],
>>> >
>>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>>>
>>> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>>> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
>>> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
>>> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
>>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
>>> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
>>> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
>>> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
>>> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
>>> > entry=GridDhtCacheEntry [rdrs=[], part=121,
>>> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
>>> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
>>> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
>>> > order=1565274668382, nodeOrder=2], hash=1903256840,
>>> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>>> > [locs=[GridCacheMvccCandidate
>>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>>> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true],
>>> >
>>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>>>
>>> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
>>> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
>>> > prepared=1, locked=false, nodeId=null, locMapped=false,
>>> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
>>> > forceSkipCompletedVers=false, super=IgniteTxAdapter
>>> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>>> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
>>> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
>>> > threadId=883, startTime=1565337963940,
>>> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
>>> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
>>> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
>>> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
>>> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
>>> > at
>>> >
>>> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > at
>>> >
>>> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > at
>>> >
>>> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
>>>
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > at
>>> >
>>> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
>>>
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > ...
>>> > Caused by:
>>> >
>>> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
>>> > Failed to acquire lock within provided timeout for transaction
>>> > [timeout=150, tx=GridDhtTxLocal
>>> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
>>> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
>>> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], super=GridDhtTxLocalAdapter
>>> > [nearOnOriginatingNode=false, nearNodes=[],
>>> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
>>> > super=IgniteTxLocalAdapter [completedBase=null,
>>> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
>>> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
>>> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
>>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
>>> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
>>> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
>>> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
>>> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
>>> > [rdrs=[], part=127, super=GridDistributedCacheEntry
>>> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
>>> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>>> > [locs=[GridCacheMvccCandidate
>>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>>> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
>>> > val=cancel_queue#FIRSTG, hasValBytes=true],
>>> >
>>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>>>
>>> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>>> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
>>> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
>>> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
>>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
>>> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
>>> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
>>> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
>>> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
>>> > entry=GridDhtCacheEntry [rdrs=[], part=121,
>>> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
>>> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
>>> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
>>> > order=1565274668382, nodeOrder=2], hash=1903256840,
>>> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>>> > [locs=[GridCacheMvccCandidate
>>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>>> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
>>> > val=cancel_queue#FIRSTA, hasValBytes=true],
>>> >
>>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>>>
>>> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
>>> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
>>> > prepared=1, locked=false, nodeId=null, locMapped=false,
>>> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>>> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
>>> > forceSkipCompletedVers=false, super=IgniteTxAdapter
>>> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>>> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
>>> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
>>> > threadId=883, startTime=1565337963940,
>>> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
>>> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
>>> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
>>> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
>>> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
>>> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>>> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
>>> > at
>>> >
>>> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
>>>
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > at
>>> >
>>> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
>>>
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > at
>>> >
>>> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
>>> > ~[ignite-core-2.7.5.jar:2.7.5]
>>> > ... 1 more
>>>
>>
Re: TimeoutException not wrapped in CacheException
Posted by Andrey Davydov <an...@gmail.com>.
Sorry fo misprint, test does not check that there are no any way to get
TimeoutException
On Fri, Aug 9, 2019 at 5:55 PM Andrey Davydov <an...@gmail.com>
wrote:
> It is a little bit difficult to reproduce. We got unhadled exception on
> pre prod performance test of our system. I will try to reproduce it on
> weekend.
>
> You test just check that if you get CacheException then TimeoutException
> is inside it, but doesn't check that there are no any way to get
> CacheException. As I check listened in stack trace lines from 2.7.5 sources
> (loaded from maven), i dont see where TOE shoud be wrapped to CE
>
> If there is full list of Exceptions when it is valid to retry transaction
> (Optimistic or Pessimistic). As I found in different pages of docs, now I
> catch (optimistic tx):
> TransactionOptimisticException - try to rerun transaction
> ClusterTopologyException - retryReadyFuture().get() and try to rerun
> transaction
> CacheException check if getCause is Timeout then try to rerun or rethrow
> in other cases
>
> Thanks.
>
> On Fri, Aug 9, 2019 at 5:31 PM Andrei Aleksandrov <ae...@gmail.com>
> wrote:
>
>> Hi,
>>
>> It looks strange because even Ignite tests expect that
>> TransactionTimeoutException will be wrapped in CacheException. For
>> example IgniteTxConfigCacheSelfTest:
>>
>> try (final Transaction tx = ignite.transactions().txStart()) {
>> assert tx != null;
>>
>> cache.put("key0", "val0");
>>
>> sleepForTxFailure();
>>
>> cache.put("key", "val");
>>
>> fail("Timeout exception must be thrown");
>> }
>> catch (CacheException e) {
>> assert e.getCause() instanceof TransactionTimeoutException;
>> }
>>
>> So could you please provide the reproducer for your issue? We will check
>> it and create the JIRA for it.
>>
>> BR,
>> Andrei
>>
>> 8/9/2019 5:16 PM, Andrey Davydov пишет:
>> > On ignite 2.7.5 I got TransactionTimeoutException not wrapped
>> > in CacheException. If it is normal behaviour and I should catch
>> > TransactionTimeoutException too. My current logic is to
>> > catch CacheException and check CacheException.getCause() if it
>> > was TransactionTimeoutException.
>> >
>> > Thanks.
>> >
>> > Full statck trace:
>> >
>> > Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
>> > Failed to acquire lock within provided timeout for transaction
>> > [timeout=150, tx=GridDhtTxLocal
>> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
>> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
>> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], super=GridDhtTxLocalAdapter
>> > [nearOnOriginatingNode=false, nearNodes=[],
>> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
>> > super=IgniteTxLocalAdapter [completedBase=null,
>> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
>> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
>> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
>> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
>> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
>> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
>> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
>> > [rdrs=[], part=127, super=GridDistributedCacheEntry
>> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
>> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>> > [locs=[GridCacheMvccCandidate
>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true],
>> >
>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>>
>> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
>> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
>> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
>> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
>> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
>> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
>> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
>> > entry=GridDhtCacheEntry [rdrs=[], part=121,
>> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
>> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
>> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
>> > order=1565274668382, nodeOrder=2], hash=1903256840,
>> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>> > [locs=[GridCacheMvccCandidate
>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true],
>> >
>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>>
>> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
>> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
>> > prepared=1, locked=false, nodeId=null, locMapped=false,
>> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
>> > forceSkipCompletedVers=false, super=IgniteTxAdapter
>> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
>> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
>> > threadId=883, startTime=1565337963940,
>> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
>> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
>> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
>> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
>> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
>> > at
>> >
>> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > at
>> >
>> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > at
>> >
>> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
>>
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > at
>> >
>> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
>>
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > ...
>> > Caused by:
>> >
>> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
>> > Failed to acquire lock within provided timeout for transaction
>> > [timeout=150, tx=GridDhtTxLocal
>> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
>> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
>> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], super=GridDhtTxLocalAdapter
>> > [nearOnOriginatingNode=false, nearNodes=[],
>> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
>> > super=IgniteTxLocalAdapter [completedBase=null,
>> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
>> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
>> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
>> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
>> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
>> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
>> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
>> > [rdrs=[], part=127, super=GridDistributedCacheEntry
>> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
>> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>> > [locs=[GridCacheMvccCandidate
>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
>> > val=cancel_queue#FIRSTG, hasValBytes=true],
>> >
>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>>
>> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
>> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
>> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
>> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
>> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
>> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
>> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
>> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
>> > entry=GridDhtCacheEntry [rdrs=[], part=121,
>> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
>> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
>> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
>> > order=1565274668382, nodeOrder=2], hash=1903256840,
>> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
>> > [locs=[GridCacheMvccCandidate
>> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
>> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
>> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
>> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
>> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
>> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
>> > val=cancel_queue#FIRSTA, hasValBytes=true],
>> >
>> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>>
>> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
>> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
>> > prepared=1, locked=false, nodeId=null, locMapped=false,
>> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
>> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
>> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
>> > forceSkipCompletedVers=false, super=IgniteTxAdapter
>> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
>> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
>> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
>> > threadId=883, startTime=1565337963940,
>> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
>> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
>> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
>> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
>> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
>> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
>> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
>> > at
>> >
>> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
>>
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > at
>> >
>> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
>>
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > at
>> >
>> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
>> > ~[ignite-core-2.7.5.jar:2.7.5]
>> > ... 1 more
>>
>
Re: TimeoutException not wrapped in CacheException
Posted by Andrey Davydov <an...@gmail.com>.
It is a little bit difficult to reproduce. We got unhadled exception on pre
prod performance test of our system. I will try to reproduce it on weekend.
You test just check that if you get CacheException then TimeoutException is
inside it, but doesn't check that there are no any way to get
CacheException. As I check listened in stack trace lines from 2.7.5 sources
(loaded from maven), i dont see where TOE shoud be wrapped to CE
If there is full list of Exceptions when it is valid to retry transaction
(Optimistic or Pessimistic). As I found in different pages of docs, now I
catch (optimistic tx):
TransactionOptimisticException - try to rerun transaction
ClusterTopologyException - retryReadyFuture().get() and try to rerun
transaction
CacheException check if getCause is Timeout then try to rerun or rethrow in
other cases
Thanks.
On Fri, Aug 9, 2019 at 5:31 PM Andrei Aleksandrov <ae...@gmail.com>
wrote:
> Hi,
>
> It looks strange because even Ignite tests expect that
> TransactionTimeoutException will be wrapped in CacheException. For
> example IgniteTxConfigCacheSelfTest:
>
> try (final Transaction tx = ignite.transactions().txStart()) {
> assert tx != null;
>
> cache.put("key0", "val0");
>
> sleepForTxFailure();
>
> cache.put("key", "val");
>
> fail("Timeout exception must be thrown");
> }
> catch (CacheException e) {
> assert e.getCause() instanceof TransactionTimeoutException;
> }
>
> So could you please provide the reproducer for your issue? We will check
> it and create the JIRA for it.
>
> BR,
> Andrei
>
> 8/9/2019 5:16 PM, Andrey Davydov пишет:
> > On ignite 2.7.5 I got TransactionTimeoutException not wrapped
> > in CacheException. If it is normal behaviour and I should catch
> > TransactionTimeoutException too. My current logic is to
> > catch CacheException and check CacheException.getCause() if it
> > was TransactionTimeoutException.
> >
> > Thanks.
> >
> > Full statck trace:
> >
> > Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
> > Failed to acquire lock within provided timeout for transaction
> > [timeout=150, tx=GridDhtTxLocal
> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], super=GridDhtTxLocalAdapter
> > [nearOnOriginatingNode=false, nearNodes=[],
> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> > super=IgniteTxLocalAdapter [completedBase=null,
> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> > [rdrs=[], part=127, super=GridDistributedCacheEntry
> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>
> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> > entry=GridDhtCacheEntry [rdrs=[], part=121,
> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> > order=1565274668382, nodeOrder=2], hash=1903256840,
> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>
> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> > prepared=1, locked=false, nodeId=null, locMapped=false,
> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> > forceSkipCompletedVers=false, super=IgniteTxAdapter
> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> > threadId=883, startTime=1565337963940,
> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > ...
> > Caused by:
> > org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
> > Failed to acquire lock within provided timeout for transaction
> > [timeout=150, tx=GridDhtTxLocal
> > [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> > nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> > nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], super=GridDhtTxLocalAdapter
> > [nearOnOriginatingNode=false, nearNodes=[],
> > dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> > super=IgniteTxLocalAdapter [completedBase=null,
> > sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> > [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> > txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> > val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> > val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> > conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> > filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> > [rdrs=[], part=127, super=GridDistributedCacheEntry
> > [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> > ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> > id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> > val=cancel_queue#FIRSTG, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
>
> > prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> > nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> > locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> > transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> > txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> > val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> > oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> > conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> > dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> > entry=GridDhtCacheEntry [rdrs=[], part=121,
> > super=GridDistributedCacheEntry [super=GridCacheMapEntry
> > [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> > hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> > order=1565274668382, nodeOrder=2], hash=1903256840,
> > extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> > [locs=[GridCacheMvccCandidate
> > [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> > id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> > otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> > nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> > ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> > order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> > val=cancel_queue#FIRSTA, hasValBytes=true],
> >
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
>
> > prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> > order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> > prepared=1, locked=false, nodeId=null, locMapped=false,
> > expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> > serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> > xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> > forceSkipCompletedVers=false, super=IgniteTxAdapter
> > [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> > nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> > order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> > threadId=883, startTime=1565337963940,
> > nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> > [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> > isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> > sysInvalidate=false, sys=false, plc=2, commitVer=null,
> > finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> > topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> > txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> > at
> >
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
>
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > at
> >
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> > ~[ignite-core-2.7.5.jar:2.7.5]
> > ... 1 more
>
Re: TimeoutException not wrapped in CacheException
Posted by Andrei Aleksandrov <ae...@gmail.com>.
Hi,
It looks strange because even Ignite tests expect that
TransactionTimeoutException will be wrapped in CacheException. For
example IgniteTxConfigCacheSelfTest:
try (final Transaction tx = ignite.transactions().txStart()) {
assert tx != null;
cache.put("key0", "val0");
sleepForTxFailure();
cache.put("key", "val");
fail("Timeout exception must be thrown");
}
catch (CacheException e) {
assert e.getCause() instanceof TransactionTimeoutException;
}
So could you please provide the reproducer for your issue? We will check
it and create the JIRA for it.
BR,
Andrei
8/9/2019 5:16 PM, Andrey Davydov пишет:
> On ignite 2.7.5 I got TransactionTimeoutException not wrapped
> in CacheException. If it is normal behaviour and I should catch
> TransactionTimeoutException too. My current logic is to
> catch CacheException and check CacheException.getCause() if it
> was TransactionTimeoutException.
>
> Thanks.
>
> Full statck trace:
>
> Caused by: org.apache.ignite.transactions.TransactionTimeoutException:
> Failed to acquire lock within provided timeout for transaction
> [timeout=150, tx=GridDhtTxLocal
> [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=[],
> dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> super=IgniteTxLocalAdapter [completedBase=null,
> sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> [rdrs=[], part=127, super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
> prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry [rdrs=[], part=121,
> super=GridDistributedCacheEntry [super=GridCacheMapEntry
> [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> order=1565274668382, nodeOrder=2], hash=1903256840,
> extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
> prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> prepared=1, locked=false, nodeId=null, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> forceSkipCompletedVers=false, super=IgniteTxAdapter
> [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> threadId=883, startTime=1565337963940,
> nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> sysInvalidate=false, sys=false, plc=2, commitVer=null,
> finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> at
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:935)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.IgniteUtils$13.apply(IgniteUtils.java:930)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1021)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.processors.cache.transactions.TransactionProxyImpl.commit(TransactionProxyImpl.java:305)
> ~[ignite-core-2.7.5.jar:2.7.5]
> ...
> Caused by:
> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
> Failed to acquire lock within provided timeout for transaction
> [timeout=150, tx=GridDhtTxLocal
> [nearNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> nearFutId=74752d17c61-0341ea15-fcbd-48ef-b655-299a6d885196,
> nearMiniId=1, nearFinFutId=null, nearFinMiniId=0,
> nearXidVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=[],
> dhtNodes=[18e6b4a9-c39d-463a-9260-b5ed5057a491,
> 1144f759-6d1f-4aa3-9592-cc0b3481eb15], explicitLock=false,
> super=IgniteTxLocalAdapter [completedBase=null,
> sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> [activeCacheIds=[1895344369], recovery=false, mvccEnabled=false,
> txMap=[IgniteTxEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], cacheId=1895344369],
> val=[op=READ, val=null], prevVal=[op=NOOP, val=null], oldVal=[op=NOOP,
> val=null], entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1,
> conflictVer=null, explicitVer=null, dhtVer=null, filters=[],
> filtersPassed=false, filtersSet=false, entry=GridDhtCacheEntry
> [rdrs=[], part=127, super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true], val=null,
> ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> hash=1903256846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412844, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=127,
> val=cancel_queue#FIRSTG, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=1,
> prevVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], nextVer=null]], rmts=null]], flags=2]]], prepared=1,
> locked=false, nodeId=null, locMapped=false, expiryPlc=null,
> transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null], IgniteTxEntry [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369,
> txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true], cacheId=1895344369],
> val=[op=DELETE, val=null], prevVal=[op=NOOP, val=null],
> oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null,
> dhtVer=null, filters=[], filtersPassed=false, filtersSet=false,
> entry=GridDhtCacheEntry [rdrs=[], part=121,
> super=GridDistributedCacheEntry [super=GridCacheMapEntry
> [key=KeyCacheObjectImpl [part=121, val=cancel_queue#FIRSTA,
> hasValBytes=true], val=null, ver=GridCacheVersion [topVer=176751246,
> order=1565274668382, nodeOrder=2], hash=1903256840,
> extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
> [locs=[GridCacheMvccCandidate
> [nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, ver=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], threadId=883,
> id=412843, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> reentry=null, otherNodeId=18e6b4a9-c39d-463a-9260-b5ed5057a491,
> otherVer=GridCacheVersion [topVer=176751246, order=1565274668396,
> nodeOrder=1], mappedDhtNodes=null, mappedNearNodes=null,
> ownerVer=null, serOrder=GridCacheVersion [topVer=176751246,
> order=1565274668396, nodeOrder=1], key=KeyCacheObjectImpl [part=121,
> val=cancel_queue#FIRSTA, hasValBytes=true],
> masks=local=1|owner=1|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0|read=0,
> prevVer=null, nextVer=GridCacheVersion [topVer=176751246,
> order=1565274668397, nodeOrder=2]]], rmts=null]], flags=3]]],
> prepared=1, locked=false, nodeId=null, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=GridCacheVersion [topVer=0, order=0, nodeOrder=0],
> xidVer=null]]], mvccWaitTxs=null, qryEnlisted=false,
> forceSkipCompletedVers=false, super=IgniteTxAdapter
> [xidVer=GridCacheVersion [topVer=176751246, order=1565274668397,
> nodeOrder=2], writeVer=GridCacheVersion [topVer=176751246,
> order=1565274668398, nodeOrder=2], implicit=false, loc=true,
> threadId=883, startTime=1565337963940,
> nodeId=73a0c88f-3628-4c12-bd75-d273b77a6752, startVer=GridCacheVersion
> [topVer=176751246, order=1565274668397, nodeOrder=2], endVer=null,
> isolation=SERIALIZABLE, concurrency=OPTIMISTIC, timeout=150,
> sysInvalidate=false, sys=false, plc=2, commitVer=null,
> finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false,
> topVer=AffinityTopologyVersion [topVer=3, minorTopVer=1],
> txCounters=null, duration=152ms, onePhaseCommit=false], size=2]]]]
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxPrepareFuture$PrepareTimeoutObject.onTimeout(GridDhtTxPrepareFuture.java:1983)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
> ~[ignite-core-2.7.5.jar:2.7.5]
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> ~[ignite-core-2.7.5.jar:2.7.5]
> ... 1 more