[
https://issues.apache.org/jira/browse/IGNITE-11591?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16799255#comment-16799255
]
Ivan Rakov commented on IGNITE-11591:
-------------------------------------
Let's extend logging added in IGNITE-11059. I propose to:
1) Dump pending locks info for every timed out transaction, but for
transactions with timeout less than minute add throttling based on
HitRateMetrics (e.g. print no more than 10 messages per minute)
2) Make messages rate configurable and changeable in runtime (we can add new
method for this - something like TransactionsMXBean#setPendingLocksMessageRate).
> 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
> Assignee: Andrey Kalinin
> 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)
