Hi,
I've reproduced the problem and have exatly the same stack traces for
NullPointerException and IgniteTxTimeoutCheckedException that you
mentioned early.
But my case looks too complex. I started three nodes and cache1 on
nodes N1, N2 and N3, and cache2 on nodes N1 and N2. After it deadlock
was created between nodes N1 and N2 where both caches are
participiants (without transaction timeout). And finally I try to
update key (that participiates in deadlock) for cache2 from N3 in
transaction with timeout. As result deadlock detection receives
message from nodes N1 or/and N2 that contains information about cache1
that isn't started on N3. This leads to NPE and timeout.
I think that similar situation can happen in case of deadlock between
two caches on server nodes and attempt to update key from client node.
Will try this idea tomorrow hopefully.
This problem should exist on any Ignite version starting from 1.7.
On Mon, Apr 17, 2017 at 11:46 PM, bintisepaha <binti.sep...@tudor.com> wrote:
> Looking further, I see this in the failed exception stack trace. The topology
> did change but it is only a client that joined, do you think that has any
> correlation to the key being locked?
>
> [INFO ] 2017-04-13 14:15:44.360 [pub-#44%DataGridServer-Production%]
> OrderHolderSaveRunnable - Updating PositionKey: PositionId [fundAbbrev=BVI,
> clearBrokerId=12718, insIid=679675, strategy=AFI, traderId=6531,
> valueDate=19000101]
> [14:15:46] Topology snapshot [ver=1980, servers=16, clients=82, CPUs=273,
> heap=850.0GB]
> [ERROR] 2017-04-13 14:15:54.348 [pub-#44%DataGridServer-Production%]
> OrderHolderSaveRunnable - Received Exception - printing on Entry
> javax.cache.CacheException: class
> org.apache.ignite.transactions.TransactionTimeoutException: Failed to
> acquire lock within provided timeout for transaction [timeout=10000,
> tx=GridNearTxLocal [mappings=IgniteTxMappingsImpl [],
> nearLocallyMapped=false, colocatedLocallyMapped=false, needCheckBackup=null,
> hasRemoteLocks=true, thread=pub-#44%DataGridServer-Production%,
> mappings=IgniteTxMappingsImpl [], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=[], dhtNodes=[], explicitLock=false,
> super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
> depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=GridLongList
> [idx=2, arr=[2062286236,812449097]], txMap={IgniteTxKey
> [key=KeyCacheObjectImpl [val=OrderKey [traderId=6531, orderId=12382604],
> hasValBytes=true], cacheId=2062286236]=IgniteTxEntry [key=KeyCacheObjectImpl
> [val=OrderKey [traderId=6531, orderId=12382604], hasValBytes=true],
> cacheId=2062286236, partId=-1, txKey=IgniteTxKey [key=KeyCacheObjectImpl
> [val=OrderKey [traderId=6531, orderId=12382604], hasValBytes=true],
> cacheId=2062286236], val=[op=READ, val=CacheObjectImpl [val=TradeOrder
> [orderKey=OrderKey [traderId=6531, orderId=12382604], insIid=679675,
> clearBrokerId=12718, strategy=AFI, time=2017-04-13 13:30:00.0,
> settlement=2017-04-19 00:00:00.0, quantity=-6800.0, insType=STK, version=1,
> userId=3081, created=2017-04-13 13:29:47.831, status=open, allocFund=STD,
> isAlloc=Y, clearAgent=MSCOEPB, execBroker=DBKSE, initiate=L,
> notes=ClOrdId[20170413-Y47D580RHH99], allocRule=H2L, comType=T, comTurn=N,
> comImplied=N, trdCur=USD, trdFreeze=N, kindFlag=, lastRepo=, exCpn=,
> generatedTime=Thu Apr 13 14:15:02 EDT 2017, batchMatchFlag=N,
> commission=0.003, trdRate=1.0, gross=, delivInstruct=null, startflys=3,
> parentId=null, linkId=null, repo=N, repoRate=null, repoCalendar=null,
> repoStartDate=null, repoEndDate=null, xiid=null, quantityCurr=null,
> masterOrderId=null, unfilledQty=800.0, avgFillPrice=18.0021324, psRuleId=6,
> origDate=2017-04-13 00:00:00.0, postingId=2, executingUserId=5647,
> repoCloseDate=1900-01-01 00:00:00.0, repoPrice=0.0, directFxFlag=N, tax=0.0,
> fixStatusId=58, txnTypeId=0, yield=null, valueDate=null,
> interestOnlyRepoFlag=null, orderGroupId=0, fundingDate=2017-04-19
> 00:00:00.0, execBrokerId=12038, branchBrokerId=7511, fillOrigUserId=3081,
> initialMargin=null, cmmsnChgUserId=0, cmmsnChgReasonId=0, fixingSourceId=0,
> orderDesignationId=0, riskRewardId=0, placementTime=2017-04-13 13:29:47.657,
> initialInvestment=0.0, equityFxBrokerTypeId=0, execBranchBrokerId=0,
> createUserId=3081, targetAllocFlag=N, pvDate=null, pvFactor=null, pvId=0,
> executionTypeId=0, borrowScheduleId=0, borrowScheduleTypeId=0,
> marketPrice=null, interestAccrualDate=null, sourceAppId=103,
> initiatingUserId=6531, isDiscretionary=Y, traderBsssc=S, clearingBsssc=S,
> executingBsssc=S, shortsellBanApproverUserId=null, intendedQuantity=-7600.0,
> lastUpdated=2017-04-13 14:15:02.147, traderStrategyId=24686,
> businessDate=2017-04-13 00:00:00.0, firstExecutionTime=2017-04-13
> 13:29:47.657, doNotBulkFlag=null, trimDb=trim_grn, trades=[Trade
> [tradeKey=TradeKey [tradeId=263603637, tradeId64=789971421, traderId=6531],
> orderId=12382604, ftbId=2023850, quantity=-985.0, fundAbbrev=TRCP,
> subfundAbbrev=TRCP_EDAB, date=Thu Apr 13 00:00:00 EDT 2017,
> commission=0.003, fillId=1, flyallocNumber=1, pnlTime=Tue Jan 01 00:00:00
> EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan
> 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0,
> splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey [tradeId=888175445,
> tradeId64=182624390, traderId=6531], orderId=12382604, ftbId=2022525,
> quantity=-4141.0, fundAbbrev=BVI, subfundAbbrev=BVI_EDAB, date=Thu Apr 13
> 00:00:00 EDT 2017, commission=0.003, fillId=1, flyallocNumber=2, pnlTime=Tue
> Jan 01 00:00:00 EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I,
> psSettle=Tue Jan 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036,
> splitTradeId=0, splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey
> [tradeId=938093803, tradeId64=953318988, traderId=6531], orderId=12382604,
> ftbId=2022524, quantity=-1674.0, fundAbbrev=TGF, subfundAbbrev=TGF_EDAB,
> date=Thu Apr 13 00:00:00 EDT 2017, commission=0.003, fillId=1,
> flyallocNumber=3, pnlTime=Tue Jan 01 00:00:00 EST 2036, price=18.0021324,
> psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan 01 00:00:00 EST 2036,
> psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0, splitTradeId64=0,
> trimDb=]]], hasValBytes=true]], prevVal=[op=READ, val=CacheObjectImpl
> [val=TradeOrder [orderKey=OrderKey [traderId=6531, orderId=12382604],
> insIid=679675, clearBrokerId=12718, strategy=AFI, time=2017-04-13
> 13:30:00.0, settlement=2017-04-19 00:00:00.0, quantity=-6800.0, insType=STK,
> version=1, userId=3081, created=2017-04-13 13:29:47.831, status=open,
> allocFund=STD, isAlloc=Y, clearAgent=MSCOEPB, execBroker=DBKSE, initiate=L,
> notes=ClOrdId[20170413-Y47D580RHH99], allocRule=H2L, comType=T, comTurn=N,
> comImplied=N, trdCur=USD, trdFreeze=N, kindFlag=, lastRepo=, exCpn=,
> generatedTime=Thu Apr 13 14:15:02 EDT 2017, batchMatchFlag=N,
> commission=0.003, trdRate=1.0, gross=, delivInstruct=null, startflys=3,
> parentId=null, linkId=null, repo=N, repoRate=null, repoCalendar=null,
> repoStartDate=null, repoEndDate=null, xiid=null, quantityCurr=null,
> masterOrderId=null, unfilledQty=800.0, avgFillPrice=18.0021324, psRuleId=6,
> origDate=2017-04-13 00:00:00.0, postingId=2, executingUserId=5647,
> repoCloseDate=1900-01-01 00:00:00.0, repoPrice=0.0, directFxFlag=N, tax=0.0,
> fixStatusId=58, txnTypeId=0, yield=null, valueDate=null,
> interestOnlyRepoFlag=null, orderGroupId=0, fundingDate=2017-04-19
> 00:00:00.0, execBrokerId=12038, branchBrokerId=7511, fillOrigUserId=3081,
> initialMargin=null, cmmsnChgUserId=0, cmmsnChgReasonId=0, fixingSourceId=0,
> orderDesignationId=0, riskRewardId=0, placementTime=2017-04-13 13:29:47.657,
> initialInvestment=0.0, equityFxBrokerTypeId=0, execBranchBrokerId=0,
> createUserId=3081, targetAllocFlag=N, pvDate=null, pvFactor=null, pvId=0,
> executionTypeId=0, borrowScheduleId=0, borrowScheduleTypeId=0,
> marketPrice=null, interestAccrualDate=null, sourceAppId=103,
> initiatingUserId=6531, isDiscretionary=Y, traderBsssc=S, clearingBsssc=S,
> executingBsssc=S, shortsellBanApproverUserId=null, intendedQuantity=-7600.0,
> lastUpdated=2017-04-13 14:15:02.147, traderStrategyId=24686,
> businessDate=2017-04-13 00:00:00.0, firstExecutionTime=2017-04-13
> 13:29:47.657, doNotBulkFlag=null, trimDb=trim_grn, trades=[Trade
> [tradeKey=TradeKey [tradeId=263603637, tradeId64=789971421, traderId=6531],
> orderId=12382604, ftbId=2023850, quantity=-985.0, fundAbbrev=TRCP,
> subfundAbbrev=TRCP_EDAB, date=Thu Apr 13 00:00:00 EDT 2017,
> commission=0.003, fillId=1, flyallocNumber=1, pnlTime=Tue Jan 01 00:00:00
> EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan
> 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0,
> splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey [tradeId=888175445,
> tradeId64=182624390, traderId=6531], orderId=12382604, ftbId=2022525,
> quantity=-4141.0, fundAbbrev=BVI, subfundAbbrev=BVI_EDAB, date=Thu Apr 13
> 00:00:00 EDT 2017, commission=0.003, fillId=1, flyallocNumber=2, pnlTime=Tue
> Jan 01 00:00:00 EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I,
> psSettle=Tue Jan 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036,
> splitTradeId=0, splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey
> [tradeId=938093803, tradeId64=953318988, traderId=6531], orderId=12382604,
> ftbId=2022524, quantity=-1674.0, fundAbbrev=TGF, subfundAbbrev=TGF_EDAB,
> date=Thu Apr 13 00:00:00 EDT 2017, commission=0.003, fillId=1,
> flyallocNumber=3, pnlTime=Tue Jan 01 00:00:00 EST 2036, price=18.0021324,
> psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan 01 00:00:00 EST 2036,
> psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0, splitTradeId64=0,
> trimDb=]]], hasValBytes=true]], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null,
> filters=null, filtersPassed=false, filtersSet=true,
> entry=GridDhtDetachedCacheEntry [super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [val=OrderKey
> [traderId=6531, orderId=12382604], hasValBytes=true], val=CacheObjectImpl
> [val=TradeOrder [orderKey=OrderKey [traderId=6531, orderId=12382604],
> insIid=679675, clearBrokerId=12718, strategy=AFI, time=2017-04-13
> 13:30:00.0, settlement=2017-04-19 00:00:00.0, quantity=-6800.0, insType=STK,
> version=1, userId=3081, created=2017-04-13 13:29:47.831, status=open,
> allocFund=STD, isAlloc=Y, clearAgent=MSCOEPB, execBroker=DBKSE, initiate=L,
> notes=ClOrdId[20170413-Y47D580RHH99], allocRule=H2L, comType=T, comTurn=N,
> comImplied=N, trdCur=USD, trdFreeze=N, kindFlag=, lastRepo=, exCpn=,
> generatedTime=Thu Apr 13 14:15:02 EDT 2017, batchMatchFlag=N,
> commission=0.003, trdRate=1.0, gross=, delivInstruct=null, startflys=3,
> parentId=null, linkId=null, repo=N, repoRate=null, repoCalendar=null,
> repoStartDate=null, repoEndDate=null, xiid=null, quantityCurr=null,
> masterOrderId=null, unfilledQty=800.0, avgFillPrice=18.0021324, psRuleId=6,
> origDate=2017-04-13 00:00:00.0, postingId=2, executingUserId=5647,
> repoCloseDate=1900-01-01 00:00:00.0, repoPrice=0.0, directFxFlag=N, tax=0.0,
> fixStatusId=58, txnTypeId=0, yield=null, valueDate=null,
> interestOnlyRepoFlag=null, orderGroupId=0, fundingDate=2017-04-19
> 00:00:00.0, execBrokerId=12038, branchBrokerId=7511, fillOrigUserId=3081,
> initialMargin=null, cmmsnChgUserId=0, cmmsnChgReasonId=0, fixingSourceId=0,
> orderDesignationId=0, riskRewardId=0, placementTime=2017-04-13 13:29:47.657,
> initialInvestment=0.0, equityFxBrokerTypeId=0, execBranchBrokerId=0,
> createUserId=3081, targetAllocFlag=N, pvDate=null, pvFactor=null, pvId=0,
> executionTypeId=0, borrowScheduleId=0, borrowScheduleTypeId=0,
> marketPrice=null, interestAccrualDate=null, sourceAppId=103,
> initiatingUserId=6531, isDiscretionary=Y, traderBsssc=S, clearingBsssc=S,
> executingBsssc=S, shortsellBanApproverUserId=null, intendedQuantity=-7600.0,
> lastUpdated=2017-04-13 14:15:02.147, traderStrategyId=24686,
> businessDate=2017-04-13 00:00:00.0, firstExecutionTime=2017-04-13
> 13:29:47.657, doNotBulkFlag=null, trimDb=trim_grn, trades=[Trade
> [tradeKey=TradeKey [tradeId=263603637, tradeId64=789971421, traderId=6531],
> orderId=12382604, ftbId=2023850, quantity=-985.0, fundAbbrev=TRCP,
> subfundAbbrev=TRCP_EDAB, date=Thu Apr 13 00:00:00 EDT 2017,
> commission=0.003, fillId=1, flyallocNumber=1, pnlTime=Tue Jan 01 00:00:00
> EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan
> 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0,
> splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey [tradeId=888175445,
> tradeId64=182624390, traderId=6531], orderId=12382604, ftbId=2022525,
> quantity=-4141.0, fundAbbrev=BVI, subfundAbbrev=BVI_EDAB, date=Thu Apr 13
> 00:00:00 EDT 2017, commission=0.003, fillId=1, flyallocNumber=2, pnlTime=Tue
> Jan 01 00:00:00 EST 2036, price=18.0021324, psId=0, psId64=0, psLiquid=I,
> psSettle=Tue Jan 01 00:00:00 EST 2036, psTime=Tue Jan 01 00:00:00 EST 2036,
> splitTradeId=0, splitTradeId64=0, trimDb=], Trade [tradeKey=TradeKey
> [tradeId=938093803, tradeId64=953318988, traderId=6531], orderId=12382604,
> ftbId=2022524, quantity=-1674.0, fundAbbrev=TGF, subfundAbbrev=TGF_EDAB,
> date=Thu Apr 13 00:00:00 EDT 2017, commission=0.003, fillId=1,
> flyallocNumber=3, pnlTime=Tue Jan 01 00:00:00 EST 2036, price=18.0021324,
> psId=0, psId64=0, psLiquid=I, psSettle=Tue Jan 01 00:00:00 EST 2036,
> psTime=Tue Jan 01 00:00:00 EST 2036, splitTradeId=0, splitTradeId64=0,
> trimDb=]]], hasValBytes=true], startVer=1492027414017, ver=GridCacheVersion
> [topVer=103141923, time=1492107302158, order=1492027411508, nodeOrder=14],
> hash=383868216, extras=null, flags=0]]], prepared=0, locked=true,
> nodeId=89f19ec9-462e-4d99-a267-1189457c124b, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=null, xidVer=GridCacheVersion [topVer=103141926,
> time=1492107344341, order=1492027414014, nodeOrder=13]], 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=READ,
> val=null], prevVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
> conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null,
> filters=null, filtersPassed=false, filtersSet=true,
> entry=GridDhtDetachedCacheEntry [super=GridDistributedCacheEntry
> [super=GridCacheMapEntry [key=KeyCacheObjectImpl [val=PositionId
> [fundAbbrev=BVI, clearBrokerId=12718, insIid=679675, strategy=AFI,
> traderId=6531, valueDate=19000101], hasValBytes=true], val=null,
> startVer=1492027414018, ver=GridCacheVersion [topVer=103141926,
> time=1492107344360, order=1492027414018, nodeOrder=13], hash=-1282641846,
> extras=null, flags=0]]], prepared=0, locked=false,
> nodeId=63e3e087-15c5-45e8-9420-9ee657a5a871, locMapped=false,
> expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0,
> serReadVer=null, xidVer=GridCacheVersion [topVer=103141926,
> time=1492107344341, order=1492027414014, nodeOrder=13]]}],
> super=IgniteTxAdapter [xidVer=GridCacheVersion [topVer=103141926,
> time=1492107344341, order=1492027414014, nodeOrder=13], writeVer=null,
> implicit=false, loc=true, threadId=83, startTime=1492107344336,
> nodeId=bdd5e4ed-aac9-4769-b241-a2e6f21f7e18, startVer=GridCacheVersion
> [topVer=103141926, time=1492107344341, order=1492027414014, nodeOrder=13],
> endVer=null, isolation=REPEATABLE_READ, concurrency=PESSIMISTIC,
> timeout=10000, sysInvalidate=false, sys=false, plc=2, commitVer=null,
> finalizing=NONE, preparing=false, invalidParts=null, state=MARKED_ROLLBACK,
> timedOut=false, topVer=AffinityTopologyVersion [topVer=1979,
> minorTopVer=34], duration=10006ms, onePhaseCommit=false], size=2]]]]
>
>
>
>
> --
> 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-tp10536p12009.html
> Sent from the Apache Ignite Users mailing list archive at Nabble.com.
