We got into the key lock situation again today.
Does the below error help in identifying anything?
Apr 13, 2017 2:16:09 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: <Position> Failed to acquire lock for request: GridNearLockRequest
[topVer=AffinityTopologyVersion [topVer=1980, minorTopVer=34],
miniId=0628e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632, implicitTx=false,
implicitSingleTx=false, onePhaseCommit=false, dhtVers=[null],
subjId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18, taskNameHash=0,
hasTransforms=false, syncCommit=true, accessTtl=-1, retVal=true,
firstClientReq=false, filter=null, super=GridDistributedLockRequest
[nodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18, nearXidVer=GridCacheVersion
[topVer=103141927, time=1492107359249, order=1492027414045, nodeOrder=13],
threadId=83, futId=e528e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632,
timeout=10000, isInTx=true, isInvalidate=false, isRead=true,
isolation=REPEATABLE_READ, retVals=[true], txSize=0, flags=0, keysCnt=1,
super=GridDistributedBaseMessage [ver=GridCacheVersion [topVer=103141927,
time=1492107359249, order=1492027414045, nodeOrder=13], committedVers=null,
rolledbackVers=null, cnt=0, super=GridCacheMessage [msgId=4632574,
depInfo=null, err=null, skipPrepare=false, cacheId=812449097,
cacheId=812449097]]]]
class
org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
Failed to acquire lock within provided timeout for transaction
[timeout=10000,
tx=org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxLocalAdapter$1@7597f862]
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:3924)
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:3874)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$2.applyx(GridEmbeddedFuture.java:91)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:297)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:290)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:263)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListeners(GridFutureAdapter.java:251)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:381)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:347)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:752)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.access$600(GridDhtLockFuture.java:79)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture$LockTimeoutObject.onTimeout(GridDhtLockFuture.java:1116)
at
org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:159)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
at java.lang.Thread.run(Thread.java:745)
Apr 13, 2017 2:16:09 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: <Position> Future execution resulted in error: GridDhtEmbeddedFuture
[super=GridEmbeddedFuture [embedded=GridEmbeddedFuture
[embedded=GridDhtLockFuture
[nearNodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18,
nearLockVer=GridCacheVersion [topVer=103141927, time=1492107359249,
order=1492027414045, nodeOrder=13], topVer=AffinityTopologyVersion
[topVer=1980, minorTopVer=34], threadId=83,
futId=ee848215b51-be4c49fc-3ecf-43d8-a667-8bbe34fa045d,
lockVer=GridCacheVersion [topVer=103141927, time=1492107359742,
order=1492027414057, nodeOrder=17], read=true, err=null, timedOut=true,
timeout=10000, tx=GridDhtTxLocal
[nearNodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18,
nearFutId=e528e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632,
nearMiniId=0628e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632,
nearFinFutId=d088e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632,
nearFinMiniId=e088e8f4b51-2d0a76c5-854f-4909-90ed-b12db61a1632,
nearXidVer=GridCacheVersion [topVer=103141927, time=1492107359249,
order=1492027414045, nodeOrder=13], super=GridDhtTxLocalAdapter
[nearOnOriginatingNode=false, nearNodes=[], dhtNodes=[], explicitLock=false,
super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=GridLongList
[idx=1, arr=[812449097]], txMap={IgniteTxKey [key=KeyCacheObjectImpl
[val=PositionId [fundAbbrev=BVI, clearBrokerId=12718, insIid=679675,
strategy=AFI, traderId=6531, valueDate=19000101], hasValBytes=true],
cacheId=812449097]=IgniteTxEntry [key=KeyCacheObjectImpl [val=PositionId
[fundAbbrev=BVI, clearBrokerId=12718, insIid=679675, strategy=AFI,
traderId=6531, valueDate=19000101], hasValBytes=true], cacheId=812449097,
partId=-1, txKey=IgniteTxKey [key=KeyCacheObjectImpl [val=PositionId
[fundAbbrev=BVI, clearBrokerId=12718, insIid=679675, strategy=AFI,
traderId=6531, valueDate=19000101], hasValBytes=true], cacheId=812449097],
val=[op=NOOP, val=null], prevVal=[op=NOOP, val=null],
entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
explicitVer=null, dhtVer=null, filters=[], filtersPassed=false,
filtersSet=false, entry=GridDhtColocatedCacheEntry [super=GridDhtCacheEntry
[rdrs=[], locPart=GridDhtLocalPartition [id=950,
map=o.a.i.i.processors.cache.GridCacheConcurrentMapImpl@40e69256,
rmvQueue=GridCircularBuffer [sizeMask=127, idxGen=0], cntr=956,
state=OWNING, reservations=0, empty=false, createTime=04/08/2017 09:59:13],
super=GridDistributedCacheEntry [super=GridCacheMapEntry
[key=KeyCacheObjectImpl [val=PositionId [fundAbbrev=BVI,
clearBrokerId=12718, insIid=679675, strategy=AFI, traderId=6531,
valueDate=19000101], hasValBytes=true], val=CacheObjectImpl [val=Position
[positionId=PositionId [fundAbbrev=BVI, clearBrokerId=12718, insIid=679675,
strategy=AFI, traderId=6531, valueDate=19000101], quantity=55846.0],
hasValBytes=true], startVer=1491660018438, ver=GridCacheVersion
[topVer=103141923, time=1492107302157, order=1492027411428, nodeOrder=17],
hash=-1282641846, extras=GridCacheMvccEntryExtras [mvcc=GridCacheMvcc
[locs=[GridCacheMvccCandidate [nodeId=63e3e087-15c5-45e8-9420-9ee657a5a871,
ver=GridCacheVersion [topVer=103141926, time=1492107359128,
order=1492027414021, nodeOrder=17], timeout=9980, ts=1492107359121,
threadId=83, id=2617730, topVer=AffinityTopologyVersion [topVer=1979,
minorTopVer=34], reentry=null,
otherNodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18, otherVer=GridCacheVersion
[topVer=103141926, time=1492107344341, order=1492027414014, nodeOrder=13],
mappedDhtNodes=null, mappedNearNodes=null, ownerVer=null, serOrder=null,
key=KeyCacheObjectImpl [val=PositionId [fundAbbrev=BVI, clearBrokerId=12718,
insIid=679675, strategy=AFI, traderId=6531, valueDate=19000101],
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,
prevVer=null, nextVer=null], GridCacheMvccCandidate
[nodeId=63e3e087-15c5-45e8-9420-9ee657a5a871, ver=GridCacheVersion
[topVer=103141927, time=1492107369295, order=1492027414501, nodeOrder=17],
timeout=10000, ts=1492107369289, threadId=83, id=2617925,
topVer=AffinityTopologyVersion [topVer=1980, minorTopVer=34], reentry=null,
otherNodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18, otherVer=GridCacheVersion
[topVer=103141927, time=1492107369294, order=1492027414500, nodeOrder=13],
mappedDhtNodes=null, mappedNearNodes=null, ownerVer=GridCacheVersion
[topVer=103141926, time=1492107359128, order=1492027414021, nodeOrder=17],
serOrder=null, key=KeyCacheObjectImpl [val=PositionId [fundAbbrev=BVI,
clearBrokerId=12718, insIid=679675, strategy=AFI, traderId=6531,
valueDate=19000101], hasValBytes=true],
masks=local=1|owner=0|ready=1|reentry=0|used=0|tx=1|single_implicit=0|dht_local=1|near_local=0|removed=0,
prevVer=null, nextVer=null]], rmts=null]], flags=0]]]], prepared=0,
locked=false, nodeId=null, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null,
xidVer=GridCacheVersion [topVer=103141927, time=1492107359742,
order=1492027414057, nodeOrder=17]]}], super=IgniteTxAdapter
[xidVer=GridCacheVersion [topVer=103141927, time=1492107359742,
order=1492027414057, nodeOrder=17], writeVer=null, implicit=false, loc=true,
threadId=83, startTime=1492107359735,
nodeId=63e3e087-15c5-45e8-9420-9ee657a5a871, startVer=GridCacheVersion
[topVer=103141927, time=1492107359742, order=1492027414057, nodeOrder=17],
endVer=null, isolation=REPEATABLE_READ, concurrency=PESSIMISTIC,
timeout=10000, sysInvalidate=false, sys=false, plc=2, commitVer=null,
finalizing=NONE, preparing=false, invalidParts=null, state=ROLLED_BACK,
timedOut=false, topVer=AffinityTopologyVersion [topVer=1980,
minorTopVer=34], duration=10007ms, onePhaseCommit=false], size=1]]],
mapped=false, trackable=true, accessTtl=-1, needReturnVal=true,
skipStore=false, keepBinary=false, innerFuts=[],
pendingLocks=[KeyCacheObjectImpl [val=PositionId [fundAbbrev=BVI,
clearBrokerId=12718, insIid=679675, strategy=AFI, traderId=6531,
valueDate=19000101], hasValBytes=true]], super=GridCompoundIdentityFuture
[super=GridCompoundFuture [rdc=Bool reducer: true, initFlag=0, lsnrCalls=0,
done=true, cancelled=false, err=null, futs=[]]]]]]]
class
org.apache.ignite.internal.transactions.IgniteTxTimeoutCheckedException:
Failed to acquire lock within provided timeout for transaction
[timeout=10000,
tx=org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxLocalAdapter$1@7597f862]
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:3924)
at
org.apache.ignite.internal.processors.cache.transactions.IgniteTxLocalAdapter$PostLockClosure1.apply(IgniteTxLocalAdapter.java:3874)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$2.applyx(GridEmbeddedFuture.java:91)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:297)
at
org.apache.ignite.internal.util.future.GridEmbeddedFuture$AsyncListener1.apply(GridEmbeddedFuture.java:290)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:263)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListeners(GridFutureAdapter.java:251)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:381)
at
org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:347)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:752)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.access$600(GridDhtLockFuture.java:79)
at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture$LockTimeoutObject.onTimeout(GridDhtLockFuture.java:1116)
at
org.apache.ignite.internal.processors.timeout.GridTimeoutProcessor$TimeoutWorker.body(GridTimeoutProcessor.java:159)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
at java.lang.Thread.run(Thread.java:745)
--
View this message in context:
http://apache-ignite-users.70518.x6.nabble.com/Pessimistic-TXN-did-not-release-lock-on-a-key-all-subsequent-txns-failed-tp10536p11967.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.
