ignite-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ivan Rakov (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (IGNITE-11591) Add info about lock candidates that are ahead in queue to transaction timeout error message
Date Thu, 21 Mar 2019 12:02:00 GMT

     [ 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)

Mime
View raw message