[
https://issues.apache.org/jira/browse/IGNITE-12165?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Denis Chudov updated IGNITE-12165:
----------------------------------
Description:
After implementing ticket IGNITE-12063 we have transaction dumps in the logs.
there are some issues with information in these dumps:
{code:java}
[11:53:36,154][INFO][snapshot-scheduler-restats-#69][GridNearTxLocal]
Transaction time dump [startTime=11:53:36.081, totalTime=65, systemTime=3,
userTime=62, cacheOperationsTime=-41943785508, rollbackTime=41943785512,
tx=GridNearTxLocal [mappings=IgniteTxMappingsImpl [], nearLocallyMapped=false,
colocatedLocallyMapped=false, needCheckBackup=null, hasRemoteLocks=true,
trackTimeout=false, systemTime=3953576, systemStartTime=0, prepareStartTime=0,
prepareTime=0, commitOrRollbackStartTime=0,
commitOrRollbackTime=41943785512318555,
txDumpsThrottling=org.apache.ignite.internal.processors.cache.transactions.IgniteTxManager$TxDumpsThrottling@760d8025,
lb=null, thread=snapshot-scheduler-restats-#69, mappings=IgniteTxMappingsImpl
[], super=GridDhtTxLocalAdapter [nearOnOriginatingNode=false,
nearNodes=KeySetView [], dhtNodes=KeySetView [], explicitLock=false,
super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=[-2100569601],
recovery=false, txMap=HashSet [IgniteTxEntry [key=KeyCacheObjectImpl [part=2,
val=SnapshotScheduleKey [id=_SCHEDULES_], hasValBytes=true],
cacheId=-2100569601, txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=2,
val=SnapshotScheduleKey [id=_SCHEDULES_], hasValBytes=true],
cacheId=-2100569601], val=[op=READ, val=null], prevVal=[op=NOOP, val=null],
oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null,
filters=null, filtersPassed=false, filtersSet=true, entry=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=2, val=SnapshotScheduleKey [id=_SCHEDULES_],
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=0, order=0,
nodeOrder=0], hash=886348002, extras=null, flags=0]GridDistributedCacheEntry
[super=]GridDhtDetachedCacheEntry [super=], prepared=0, locked=true,
nodeId=1adbae78-40fe-480d-803d-4d498919ae63, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null,
xidVer=GridCacheVersion [topVer=179672005, order=1568192005565,
nodeOrder=1]]]], super=IgniteTxAdapter [xidVer=GridCacheVersion
[topVer=179672005, order=1568192005565, nodeOrder=1], writeVer=null,
implicit=false, loc=true, threadId=125, startTime=1568192016081,
nodeId=9e00ae45-4084-4f29-949f-c19c933f4299, startVer=GridCacheVersion
[topVer=179672005, order=1568192005565, nodeOrder=1], endVer=null,
isolation=REPEATABLE_READ, concurrency=PESSIMISTIC, timeout=0,
sysInvalidate=false, sys=true, plc=5, commitVer=null, finalizing=NONE,
invalidParts=null, state=ROLLED_BACK, timedOut=false,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], duration=60ms,
onePhaseCommit=false], size=1]]]]
{code}
For example:
# Negative time: cacheOperationsTime=-41943785508,
# Huge times: rollbackTime=41943785512
was:
After implementing ticket https://ggsystems.atlassian.net/browse/GG-21272 we
have transaction dumps in the logs.
there are some issues with information in these dumps:
{code:java}
[11:53:36,154][INFO][snapshot-scheduler-restats-#69][GridNearTxLocal]
Transaction time dump [startTime=11:53:36.081, totalTime=65, systemTime=3,
userTime=62, cacheOperationsTime=-41943785508, rollbackTime=41943785512,
tx=GridNearTxLocal [mappings=IgniteTxMappingsImpl [], nearLocallyMapped=false,
colocatedLocallyMapped=false, needCheckBackup=null, hasRemoteLocks=true,
trackTimeout=false, systemTime=3953576, systemStartTime=0, prepareStartTime=0,
prepareTime=0, commitOrRollbackStartTime=0,
commitOrRollbackTime=41943785512318555,
txDumpsThrottling=org.apache.ignite.internal.processors.cache.transactions.IgniteTxManager$TxDumpsThrottling@760d8025,
lb=null, thread=snapshot-scheduler-restats-#69, mappings=IgniteTxMappingsImpl
[], super=GridDhtTxLocalAdapter [nearOnOriginatingNode=false,
nearNodes=KeySetView [], dhtNodes=KeySetView [], explicitLock=false,
super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false,
depEnabled=false, txState=IgniteTxStateImpl [activeCacheIds=[-2100569601],
recovery=false, txMap=HashSet [IgniteTxEntry [key=KeyCacheObjectImpl [part=2,
val=SnapshotScheduleKey [id=_SCHEDULES_], hasValBytes=true],
cacheId=-2100569601, txKey=IgniteTxKey [key=KeyCacheObjectImpl [part=2,
val=SnapshotScheduleKey [id=_SCHEDULES_], hasValBytes=true],
cacheId=-2100569601], val=[op=READ, val=null], prevVal=[op=NOOP, val=null],
oldVal=[op=NOOP, val=null], entryProcessorsCol=null, ttl=-1,
conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null,
filters=null, filtersPassed=false, filtersSet=true, entry=GridCacheMapEntry
[key=KeyCacheObjectImpl [part=2, val=SnapshotScheduleKey [id=_SCHEDULES_],
hasValBytes=true], val=null, ver=GridCacheVersion [topVer=0, order=0,
nodeOrder=0], hash=886348002, extras=null, flags=0]GridDistributedCacheEntry
[super=]GridDhtDetachedCacheEntry [super=], prepared=0, locked=true,
nodeId=1adbae78-40fe-480d-803d-4d498919ae63, locMapped=false, expiryPlc=null,
transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null,
xidVer=GridCacheVersion [topVer=179672005, order=1568192005565,
nodeOrder=1]]]], super=IgniteTxAdapter [xidVer=GridCacheVersion
[topVer=179672005, order=1568192005565, nodeOrder=1], writeVer=null,
implicit=false, loc=true, threadId=125, startTime=1568192016081,
nodeId=9e00ae45-4084-4f29-949f-c19c933f4299, startVer=GridCacheVersion
[topVer=179672005, order=1568192005565, nodeOrder=1], endVer=null,
isolation=REPEATABLE_READ, concurrency=PESSIMISTIC, timeout=0,
sysInvalidate=false, sys=true, plc=5, commitVer=null, finalizing=NONE,
invalidParts=null, state=ROLLED_BACK, timedOut=false,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], duration=60ms,
onePhaseCommit=false], size=1]]]]
{code}
For example:
# Negative time: cacheOperationsTime=-41943785508,
# Huge times: rollbackTime=41943785512
> Negative time in Transaction time dump
> --------------------------------------
>
> Key: IGNITE-12165
> URL: https://issues.apache.org/jira/browse/IGNITE-12165
> Project: Ignite
> Issue Type: Improvement
> Reporter: Denis Chudov
> Assignee: Denis Chudov
> Priority: Major
>
> After implementing ticket IGNITE-12063 we have transaction dumps in the logs.
> there are some issues with information in these dumps:
> {code:java}
> [11:53:36,154][INFO][snapshot-scheduler-restats-#69][GridNearTxLocal]
> Transaction time dump [startTime=11:53:36.081, totalTime=65, systemTime=3,
> userTime=62, cacheOperationsTime=-41943785508, rollbackTime=41943785512,
> tx=GridNearTxLocal [mappings=IgniteTxMappingsImpl [],
> nearLocallyMapped=false, colocatedLocallyMapped=false, needCheckBackup=null,
> hasRemoteLocks=true, trackTimeout=false, systemTime=3953576,
> systemStartTime=0, prepareStartTime=0, prepareTime=0,
> commitOrRollbackStartTime=0, commitOrRollbackTime=41943785512318555,
> txDumpsThrottling=org.apache.ignite.internal.processors.cache.transactions.IgniteTxManager$TxDumpsThrottling@760d8025,
> lb=null, thread=snapshot-scheduler-restats-#69,
> mappings=IgniteTxMappingsImpl [], super=GridDhtTxLocalAdapter
> [nearOnOriginatingNode=false, nearNodes=KeySetView [], dhtNodes=KeySetView
> [], explicitLock=false, super=IgniteTxLocalAdapter [completedBase=null,
> sndTransformedVals=false, depEnabled=false, txState=IgniteTxStateImpl
> [activeCacheIds=[-2100569601], recovery=false, txMap=HashSet [IgniteTxEntry
> [key=KeyCacheObjectImpl [part=2, val=SnapshotScheduleKey [id=_SCHEDULES_],
> hasValBytes=true], cacheId=-2100569601, txKey=IgniteTxKey
> [key=KeyCacheObjectImpl [part=2, val=SnapshotScheduleKey [id=_SCHEDULES_],
> hasValBytes=true], cacheId=-2100569601], val=[op=READ, val=null],
> prevVal=[op=NOOP, val=null], oldVal=[op=NOOP, val=null],
> entryProcessorsCol=null, ttl=-1, conflictExpireTime=-1, conflictVer=null,
> explicitVer=null, dhtVer=null, filters=null, filtersPassed=false,
> filtersSet=true, entry=GridCacheMapEntry [key=KeyCacheObjectImpl [part=2,
> val=SnapshotScheduleKey [id=_SCHEDULES_], hasValBytes=true], val=null,
> ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0], hash=886348002,
> extras=null, flags=0]GridDistributedCacheEntry
> [super=]GridDhtDetachedCacheEntry [super=], prepared=0, locked=true,
> nodeId=1adbae78-40fe-480d-803d-4d498919ae63, locMapped=false, expiryPlc=null,
> transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null,
> xidVer=GridCacheVersion [topVer=179672005, order=1568192005565,
> nodeOrder=1]]]], super=IgniteTxAdapter [xidVer=GridCacheVersion
> [topVer=179672005, order=1568192005565, nodeOrder=1], writeVer=null,
> implicit=false, loc=true, threadId=125, startTime=1568192016081,
> nodeId=9e00ae45-4084-4f29-949f-c19c933f4299, startVer=GridCacheVersion
> [topVer=179672005, order=1568192005565, nodeOrder=1], endVer=null,
> isolation=REPEATABLE_READ, concurrency=PESSIMISTIC, timeout=0,
> sysInvalidate=false, sys=true, plc=5, commitVer=null, finalizing=NONE,
> invalidParts=null, state=ROLLED_BACK, timedOut=false,
> topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], duration=60ms,
> onePhaseCommit=false], size=1]]]]
> {code}
> For example:
> # Negative time: cacheOperationsTime=-41943785508,
> # Huge times: rollbackTime=41943785512
--
This message was sent by Atlassian Jira
(v8.3.2#803003)
