[
https://issues.apache.org/jira/browse/IGNITE-11591?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ivan Rakov updated IGNITE-11591:
--------------------------------
Description:
If transaction is timed out due to lock acquisition failure, corresponding
error will show up in server log on DHT (primary) node:
{code:java}
[2019-03-20
21:13:10,831][ERROR][grid-timeout-worker-#23%transactions.TxRollbackOnTimeoutTest0%][GridDhtColocatedCache]
<test> Failed to acquire lock for request: GridNearLockRequest
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=0], miniId=1,
dhtVers=GridCacheVersion[] [null], subjId=651a30e1-45ac-4b35-86d2-028d1f81d8dc,
taskNameHash=0, createTtl=-1, accessTtl=-1, flags=6, txLbl=null, filter=null,
super=GridDistributedLockRequest [nodeId=651a30e1-45ac-4b35-86d2-028d1f81d8dc,
nearXidVer=GridCacheVersion [topVer=164585585, order=1553105588524,
nodeOrder=4], threadId=262,
futId=5967e4c9961-d32ea2a6-1789-47d7-bdbf-aa66e6d8c35b, timeout=890,
isInTx=true, isInvalidate=false, isRead=false, isolation=REPEATABLE_READ,
retVals=[false], txSize=2, flags=0, keysCnt=1, super=GridDistributedBaseMessage
[ver=GridCacheVersion [topVer=164585585, order=1553105588524, nodeOrder=4],
committedVers=null, rolledbackVers=null, cnt=0, super=GridCacheIdMessage
[cacheId=3556498]]]]
class org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
Failed to acquire lock within provided timeout for transaction [timeout=890,
tx=GridDhtTxLocal[xid=f219e4c9961-00000000-09cf-6071-0000-000000000001,
xidVersion=GridCacheVersion [topVer=164585585, order=1553105588527,
nodeOrder=1], concurrency=PESSIMISTIC, isolation=REPEATABLE_READ,
state=MARKED_ROLLBACK, invalidate=false, rollbackOnly=true,
nodeId=c7dccddb-dee1-4499-94b1-038963500000, timeout=890, duration=891]]
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1766)
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1714)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$2.applyx(GridEmbeddedFuture.java:86)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:292)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:285)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblock(GridFutureAdapter.java:347)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblockAll(GridFutureAdapter.java:335)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:511)
at
org.apache.ignite.internal.processors.cache.GridCacheCompoundIdentityFuture.onDone(GridCacheCompoundIdentityFuture.java:56)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:490)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:793)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.access$900(GridDhtLockFuture.java:89)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture$LockTimeoutObject.onTimeout(GridDhtLockFuture.java:1189)
at
org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.j
{code}
It would be much more useful if this message also contained information about
transaction that actually owns corresponding lock (or information about all
transactions that are ahead in queue if there are several).
was:
If transaction is timed out due to lock acquisition failure, corresponding
error will show up in server log on DHT node:
{code:java}
[2019-03-20
21:13:10,831][ERROR][grid-timeout-worker-#23%transactions.TxRollbackOnTimeoutTest0%][GridDhtColocatedCache]
<test> Failed to acquire lock for request: GridNearLockRequest
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=0], miniId=1,
dhtVers=GridCacheVersion[] [null], subjId=651a30e1-45ac-4b35-86d2-028d1f81d8dc,
taskNameHash=0, createTtl=-1, accessTtl=-1, flags=6, txLbl=null, filter=null,
super=GridDistributedLockRequest [nodeId=651a30e1-45ac-4b35-86d2-028d1f81d8dc,
nearXidVer=GridCacheVersion [topVer=164585585, order=1553105588524,
nodeOrder=4], threadId=262,
futId=5967e4c9961-d32ea2a6-1789-47d7-bdbf-aa66e6d8c35b, timeout=890,
isInTx=true, isInvalidate=false, isRead=false, isolation=REPEATABLE_READ,
retVals=[false], txSize=2, flags=0, keysCnt=1, super=GridDistributedBaseMessage
[ver=GridCacheVersion [topVer=164585585, order=1553105588524, nodeOrder=4],
committedVers=null, rolledbackVers=null, cnt=0, super=GridCacheIdMessage
[cacheId=3556498]]]]
class org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
Failed to acquire lock within provided timeout for transaction [timeout=890,
tx=GridDhtTxLocal[xid=f219e4c9961-00000000-09cf-6071-0000-000000000001,
xidVersion=GridCacheVersion [topVer=164585585, order=1553105588527,
nodeOrder=1], concurrency=PESSIMISTIC, isolation=REPEATABLE_READ,
state=MARKED_ROLLBACK, invalidate=false, rollbackOnly=true,
nodeId=c7dccddb-dee1-4499-94b1-038963500000, timeout=890, duration=891]]
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1766)
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1714)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$2.applyx(GridEmbeddedFuture.java:86)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:292)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:285)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblock(GridFutureAdapter.java:347)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.unblockAll(GridFutureAdapter.java:335)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:511)
at
org.apache.ignite.internal.processors.cache.GridCacheCompoundIdentityFuture.onDone(GridCacheCompoundIdentityFuture.java:56)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:490)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:793)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.access$900(GridDhtLockFuture.java:89)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture$LockTimeoutObject.onTimeout(GridDhtLockFuture.java:1189)
at
org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.j
{code}
It would be much more useful if this message also contained information about
transaction that actually owns corresponding lock (or information about all
transactions that are ahead in queue if there are several).
> Add info about lock candidates that are ahead in queue to transaction timeout
> error message
> -------------------------------------------------------------------------------------------
>
> Key: IGNITE-11591
> URL: https://issues.apache.org/jira/browse/IGNITE-11591
> Project: Ignite
> Issue Type: Improvement
> Reporter: Ivan Rakov
> Priority: Major
> Fix For: 2.8
>
>
> If transaction is timed out due to lock acquisition failure, corresponding
> error will show up in server log on DHT (primary) node:
> {code:java}
> [2019-03-20
> 21:13:10,831][ERROR][grid-timeout-worker-#23%transactions.TxRollbackOnTimeoutTest0%][GridDhtColocatedCache]
> <test> Failed to acquire lock for request: GridNearLockRequest
> [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=0], miniId=1,
> dhtVers=GridCacheVersion[] [null],
> subjId=651a30e1-45ac-4b35-86d2-028d1f81d8dc, taskNameHash=0, createTtl=-1,
> accessTtl=-1, flags=6, txLbl=null, filter=null,
> super=GridDistributedLockRequest
> [nodeId=651a30e1-45ac-4b35-86d2-028d1f81d8dc, nearXidVer=GridCacheVersion
> [topVer=164585585, order=1553105588524, nodeOrder=4], threadId=262,
> futId=5967e4c9961-d32ea2a6-1789-47d7-bdbf-aa66e6d8c35b, timeout=890,
> isInTx=true, isInvalidate=false, isRead=false, isolation=REPEATABLE_READ,
> retVals=[false], txSize=2, flags=0, keysCnt=1,
> super=GridDistributedBaseMessage [ver=GridCacheVersion [topVer=164585585,
> order=1553105588524, nodeOrder=4], committedVers=null, rolledbackVers=null,
> cnt=0, super=GridCacheIdMessage [cacheId=3556498]]]]
> class
> org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
> Failed to acquire lock within provided timeout for transaction [timeout=890,
> tx=GridDhtTxLocal[xid=f219e4c9961-00000000-09cf-6071-0000-000000000001,
> xidVersion=GridCacheVersion [topVer=164585585, order=1553105588527,
> nodeOrder=1], concurrency=PESSIMISTIC, isolation=REPEATABLE_READ,
> state=MARKED_ROLLBACK, invalidate=false, rollbackOnly=true,
> nodeId=c7dccddb-dee1-4499-94b1-038963500000, timeout=890, duration=891]]
> at
> org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1766)
> at
> org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:1714)
> at
> org.apache.ignite.internal.util.future.GridEmbeddedFuture$2.applyx(GridEmbeddedFuture.java:86)
> at
> org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:292)
> at
> org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:285)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:399)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.unblock(GridFutureAdapter.java:347)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.unblockAll(GridFutureAdapter.java:335)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:511)
> at
> org.apache.ignite.internal.processors.cache.GridCacheCompoundIdentityFuture.onDone(GridCacheCompoundIdentityFuture.java:56)
> at
> org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:490)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:793)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.access$900(GridDhtLockFuture.java:89)
> at
> org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture$LockTimeoutObject.onTimeout(GridDhtLockFuture.java:1189)
> at
> org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:234)
> at
> org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
> at java.lang.Thread.run(Thread.j
> {code}
> It would be much more useful if this message also contained information about
> transaction that actually owns corresponding lock (or information about all
> transactions that are ahead in queue if there are several).
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
