crd=true
|
YYYY-MM-DD 17:37:16.901 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=1, minorTopVer=0], crd=true]
|
Успешное завершение обмена топологиями с узлом-координатором |
Added new node to topology |
YYYY-MM-DD 17:43:43.595 [INFO ][disco-event-worker-#56][org.apache.ignite.internal.managers.discovery.GridDiscoveryManager] Added new node to topology: TcpDiscoveryNode [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, consistentId=yy.yy.yyy.yyy,xxx.x.x.x:47500, addrs=ArrayList [yy.yy.yyy.yyy, xxx.x.x.x], sockAddrs=HashSet [<hostname>, /xxx.x.x.x:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1601995423434, loc=false, ver=2.8.1#20200914-sha1:602ccc45, isClient=false]
|
В топологию добавлен новый узел |
Node left topology |
YYYY-MM-DD 17:48:00.828 [INFO ][disco-event-worker-#56][org.apache.ignite.internal.managers.discovery.GridDiscoveryManager] Node left topology: TcpDiscoveryNode [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, consistentId=yy.yy.yyy.yyy,xxx.x.x.x:47500, addrs=ArrayList [yy.yy.yyy.yyy, xxx.x.x.x], sockAddrs=HashSet [<hostname>, /xxx.x.x.x:47500], discPort=47500, order=2, intOrder=2, lastExchangeTime=1601995423434, loc=false, ver=2.8.1#20200914-sha1:602ccc45, isClient=false]
|
Узел покинул топологию |
Sending activate request |
YYYY-MM-DD 17:54:27.906 [INFO ][rest-#171][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Sending activate request with BaselineTopology BaselineTopology [id=x, branchingHash=533127586, branchingType='Cluster activation', baselineNodes=[xx.xx.xxx.xx,xxx.x.x.x:47500]]
YYYY-MM-DD 17:54:27.908 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Received activate request with BaselineTopology[id=x]
YYYY-MM-DD 17:54:27.908 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Started state transition: true
YYYY-MM-DD 17:54:27.909 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Started exchange init [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], crd=true, evt=DISCOVERY_CUSTOM_EVT, evtNode=0d1f5011-4540-473b-aced-8c7c911f86a3, customEvt=ChangeGlobalStateMessage [id=45a585ef471-773de86e-722e-45e4-9228-38bbf24f0d82, reqId=64cea40a-356d-4c84-b651-fd0b50c5f3a7, initiatingNodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, secSubjId=null, activate=true, baselineTopology=BaselineTopology [id=x, branchingHash=533127586, branchingType='Cluster activation', baselineNodes=[xx.xx.xxx.xx,xxx.x.x.x:47500]], forceChangeBaselineTopology=false, timestamp=1601996067906], allowMerge=false, exchangeFreeSwitch=false]
YYYY-MM-DD 17:54:27.909 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Start activation process [nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, client=false, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2]]
YYYY-MM-DD 17:54:27.910 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager] Configured data regions initialized successfully [total=3]
YYYY-MM-DD 17:54:27.912 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.persistence.IgniteCacheDatabaseSharedManager] Configured data regions started successfully [total=3]
YYYY-MM-DD 17:54:27.912 [INFO ][exchange-worker-#58][org.apache.ignite.cache.msg] Components activation performed in 3 ms.
YYYY-MM-DD 17:54:27.915 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCacheProcessor] Started cache [name=ignite-sys-cache, id=xxxxxxxxxxx, dataRegionName=sysMemPlc, mode=REPLICATED, atomicity=TRANSACTIONAL, backups=2147483647, mvcc=false]
YYYY-MM-DD 17:54:27.916 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Successfully activated caches [nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, client=false, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2]]
YYYY-MM-DD 17:54:27.917 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
YYYY-MM-DD 17:54:27.964 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=2]]
YYYY-MM-DD 17:54:27.967 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finish exchange future [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], err=null, rebalanced=true, wasRebalanced=false]
YYYY-MM-DD 17:54:27.968 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCacheProcessor] Finish proxy initialization, cacheName=ignite-sys-cache, localNodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx
YYYY-MM-DD 17:54:27.969 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Received state change finish message: true
YYYY-MM-DD 17:54:27.982 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Completed partition exchange [localNode=0d1f5011-4540-473b-aced-8c7c911f86a3, exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx3, consistentId=xx.xx.xxx.xx,xxx.x.x.x:47500, addrs=ArrayList [xx.xx.xxx.xx, xxx.x.x.x], sockAddrs=HashSet [/xxx.x.x.x:47500, <hostname>], discPort=47500, order=1, intOrder=1, lastExchangeTime=1601995680820, loc=true, ver=2.8.1#20200914-sha1:602ccc45, isClient=false], done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2]]
YYYY-MM-DD 17:54:27.982 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange timings [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 ms), stage="Update caches registry" (3 ms), stage="Start caches" (3 ms), stage="Affinity initialization on cache group start" (0 ms), stage="Determine exchange type" (0 ms), stage="Preloading notification" (0 ms), stage="WAL history reservation" (0 ms), stage="Wait partitions release" (0 ms), stage="After states restored callback" (47 ms), stage="Waiting for all single messages" (0 ms), stage="Affinity recalculation (crd)" (0 ms), stage="Collect update counters and create affinity messages" (0 ms), stage="Validate partitions states" (0 ms), stage="Assign partitions states" (0 ms), stage="Ideal affinity diff calculation (enforced)" (0 ms), stage="Apply update counters" (0 ms), stage="Full message preparing" (1 ms), stage="Full message sending" (0 ms), stage="State finish message sending" (0 ms), stage="Exchange done" (14 ms), stage="Total time" (68 ms)]
YYYY-MM-DD 17:54:27.982 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], stage="Affinity initialization on cache group start [grp=ignite-sys-cache]" (0 ms) (parent=Affinity initialization on cache group start), stage="Affinity centralized initialization (crd) [grp=ignite-sys-cache, crd=true]" (0 ms) (parent=Determine exchange type), stage="Affinity recalculation (partitions availability) [grp=ignite-sys-cache]" (0 ms) (parent=Ideal affinity diff calculation (enforced))]
YYYY-MM-DD 17:54:27.983 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2], crd=true]
YYYY-MM-DD 17:54:27.983 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=3, minorTopVer=2], force=false, evt=DISCOVERY_CUSTOM_EVT, node=0d1f5011-4540-473b-aced-8c7c911f86a3]
YYYY-MM-DD 17:54:27.997 [INFO ][sys-#169][org.apache.ignite.internal.cluster.DistributedBaselineConfiguration] Baseline auto-adjust is 'enabled' with timeout='0' ms
YYYY-MM-DD 17:54:27.997 [INFO ][sys-#169][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Successfully performed final activation steps [nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, client=false, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=2]]
|
Запрос на активацию кластера |
Sending deactivate request |
YYYY-MM-DD 17:56:59.425 [INFO ][rest-#185][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Sending deactivate request with BaselineTopology null
YYYY-MM-DD 17:56:59.426 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Received deactivate request with BaselineTopology: null
YYYY-MM-DD 17:56:59.426 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Started state transition: false
YYYY-MM-DD 17:56:59.427 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Started exchange init [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], crd=true, evt=DISCOVERY_CUSTOM_EVT, evtNode=0d1f5011-4540-473b-aced-8c7c911f86a3, customEvt=ChangeGlobalStateMessage [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, reqId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, initiatingNodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, secSubjId=null, activate=false, baselineTopology=null, forceChangeBaselineTopology=false, timestamp=1601996219425], allowMerge=false, exchangeFreeSwitch=false]
YYYY-MM-DD 17:56:59.427 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Start deactivation process [nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, client=false, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]
YYYY-MM-DD 17:56:59.428 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Successfully deactivated data structures, services and caches [nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, client=false, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]
YYYY-MM-DD 17:56:59.428 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
YYYY-MM-DD 17:56:59.429 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partitions release latch: ServerLatch [permits=0, pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid [id=exchange, topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]]]
YYYY-MM-DD 17:56:59.429 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], waitTime=0ms, futInfo=NA, mode=LOCAL]
YYYY-MM-DD 17:56:59.429 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]
YYYY-MM-DD 17:56:59.432 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finish exchange future [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], err=null, rebalanced=false, wasRebalanced=true]
YYYY-MM-DD 17:56:59.433 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCacheProcessor] Stopped cache [cacheName=ignite-sys-cache]
YYYY-MM-DD 17:56:59.434 [INFO ][disco-notifier-worker-#55][org.apache.ignite.internal.processors.cluster.GridClusterStateProcessor] Received state change finish message: false
YYYY-MM-DD 17:56:59.437 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Completed partition exchange [localNode=0d1f5011-4540-473b-aced-8c7c911f86a3, exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, consistentId=xx.xx.xxx.xx,xxx.x.x.x:47500, addrs=ArrayList [xx.xx.xxx.xx, xxx.x.x.x], sockAddrs=HashSet [/xxx.x.x.x:47500, <hostname>], discPort=47500, order=1, intOrder=1, lastExchangeTime=1601995680820, loc=true, ver=2.8.1#20200914-sha1:602ccc45, isClient=false], done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]
YYYY-MM-DD 17:56:59.438 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange timings [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 ms), stage="Update caches registry" (0 ms), stage="Start caches" (0 ms), stage="Affinity initialization on cache group start" (0 ms), stage="Determine exchange type" (0 ms), stage="Preloading notification" (0 ms), stage="WAL history reservation" (0 ms), stage="Wait partitions release" (0 ms), stage="Wait partitions release latch" (0 ms), stage="Wait partitions release" (0 ms), stage="After states restored callback" (0 ms), stage="Waiting for all single messages" (0 ms), stage="Affinity recalculation (crd)" (0 ms), stage="Collect update counters and create affinity messages" (0 ms), stage="Validate partitions states" (0 ms), stage="Apply update counters" (0 ms), stage="Full message preparing" (2 ms), stage="Full message sending" (0 ms), stage="State finish message sending" (0 ms), stage="Exchange done" (6 ms), stage="Total time" (8 ms)]
YYYY-MM-DD 17:56:59.438 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], resVer=AffinityTopologyVersion [topVer=3, minorTopVer=3]]]
YYYY-MM-DD 17:56:59.438 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=3, minorTopVer=3], crd=true]
YYYY-MM-DD 17:56:59.439 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=3, minorTopVer=3], force=false, evt=DISCOVERY_CUSTOM_EVT, node=0d1f5011-4540-473b-aced-8c7c911f86a3]
|
Запрос на деактивацию кластера |
Partition Map Exchange crd node |
YYYY-MM-DD 11:58:53.255 [INFO ][grid-timeout-worker-#23][org.apache.ignite.internal.IgniteKernal] FreeList [name=default##FreeList, buckets=256, dataPages=1, reusePages=1367]
YYYY-MM-DD 11:59:19.889 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Started exchange init [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], crd=true, evt=DISCOVERY_CUSTOM_EVT, evtNode=0aa67196-7cd2-4121-ad59-86a125c791db, customEvt=DynamicCacheChangeBatch [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, reqs=ArrayList [DynamicCacheChangeRequest [cacheName=Cache2, hasCfg=true, nodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, clientStartOnly=false, stop=false, destroy=false, disabledAfterStartfalse]], exchangeActions=ExchangeActions [startCaches=[Cache2], stopCaches=null, startGrps=[Cache2], stopGrps=[], resetParts=null, stateChangeRequest=null], startCaches=false, secSubjId=null], allowMerge=false, exchangeFreeSwitch=false]
YYYY-MM-DD 11:59:19.897 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCacheProcessor] Started cache [name=Cache2, id=2010787088, dataRegionName=default, mode=PARTITIONED, atomicity=ATOMIC, backups=0, mvcc=false]
YYYY-MM-DD 11:59:19.903 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]``YYYY-MM-DD 11:59:19.929 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partitions release latch: ServerLatch [permits=0, pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid [id=exchange, topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2]]]]
YYYY-MM-DD 11:59:19.932 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], waitTime=0ms, futInfo=NA, mode=LOCAL]
YYYY-MM-DD 11:59:20.054 [INFO ][exchange-worker-#58][org.apache.ignite.internal.exchange.time] Finished exchange init [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], crd=true]
YYYY-MM-DD 11:59:20.064 [INFO ][sys-#5847][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Coordinator received single message [ver=AffinityTopologyVersion [topVer=7, minorTopVer=2], node=4e9f9dee-9735-47d0-814d-e008f85a1889, remainingNodes=1, allReceived=false]
YYYY-MM-DD 11:59:20.068 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Coordinator received single message [ver=AffinityTopologyVersion [topVer=7, minorTopVer=2], node=b073551f-6755-4ff8-a161-91eeb403d0a3, allReceived=true]
YYYY-MM-DD 11:59:20.069 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=2]]
YYYY-MM-DD 11:59:20.076 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Finish exchange future [startVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], err=null, rebalanced=true, wasRebalanced=true]
YYYY-MM-DD 11:59:20.080 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.GridCacheProcessor] Finish proxy initialization, cacheName=Cache2, localNodeid=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx
YYYY-MM-DD 11:59:20.080 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Completed partition exchange [localNode=0aa67196-7cd2-4121-ad59-86a125c791db, exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT, evtNode=TcpDiscoveryNode [id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, consistentId=xx.xx.xxx.xx,xxx.x.x.x:47500, addrs=ArrayList [xx.xx.xxx.xx, xxx.x.x.x], sockAddrs=HashSet [/xxx.x.x.x:47500, <hostna,e>], discPort=47500, order=2, intOrder=2, lastExchangeTime=1602233959892, loc=true, ver=2.8.1#20200914-sha1:602ccc45, isClient=false], done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=7, minorTopVer=2]]
YYYY-MM-DD 11:59:20.080 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange timings [startVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters initialization" (0 ms), stage="Update caches registry" (0 ms), stage="Start caches" (7 ms), stage="Affinity initialization on cache group start" (5 ms), stage="Determine exchange type" (0 ms), stage="Preloading notification" (0 ms), stage="WAL history reservation" (0 ms), stage="Wait partitions release" (0 ms), stage="Wait partitions release latch" (25 ms), stage="Wait partitions release" (2 ms), stage="After states restored callback" (122 ms), stage="Waiting for all single messages" (14 ms), stage="Affinity recalculation (crd)" (0 ms), stage="Collect update counters and create affinity messages" (0 ms), stage="Validate partitions states" (0 ms), stage="Assign partitions states" (1 ms), stage="Apply update counters" (0 ms), stage="Full message preparing" (4 ms), stage="Full message sending" (0 ms), stage="Exchange done" (3 ms), stage="Total time" (183 ms), Discovery lag=1385956 ms, Latest started node id=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx]
YYYY-MM-DD 11:59:20.080 [INFO ][sys-#5848][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture] Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=7, minorTopVer=2], stage="Affinity initialization on cache group start [grp=Cache2]" (5 ms) (parent=Affinity initialization on cache group start)]
YYYY-MM-DD 11:59:20.082 [INFO ][exchange-worker-#58][org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager] Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion [topVer=7, minorTopVer=2], force=false, evt=DISCOVERY_CUSTOM_EVT, node=0aa67196-7cd2-4121-ad59-86a125c791db]
|
PME. Журнал узла-координатора |
Starting rebalance routine |
YYYY-MM-DD 19:58:07.049 [INFO ][sys-#64][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemander] Starting rebalance routine [ignite-sys-cache, topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], supplier=0aa67196-7cd2-4121-ad59-86a125c791db, fullPartitions=[0-99], histPartitions=[]]
|
Начало процесса ребалансировки |
Completed rebalance future |
YYYY-MM-DD 19:58:07.074 [INFO ][rebalance-#69][org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionDemander] Completed rebalance future: RebalanceFuture [grp=CacheGroupContext [grp=ignite-sys-cache], topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], rebalanceId=x, routines=1, receivedBytes=1200, receivedKeys=0, partitionsLeft=0, startTime=1602176287046, endTime=-1, lastCancelledTime=-1]
|
RebalanceFuture завершен
|
>>>Transaction |
YYYY-MM-DD 23:31:15.474[WARN ][grid-timeout-worker-#119%DPL_GRID%DplGridNodeName%][o.apache.ignite.internal.diagnostic] >>> Transaction [startTime=23:30:08.115, curTime=23:31:15.471, systemTime=67347, userTime=9, tx=GridNearTxLocal [mappings=IgniteTxMappingsSingleImpl [mapping=GridDistributedTxMapping [entries=LinkedHashSet [IgniteTxEntry [txKey=IgniteTxKey [cacheId=xxxxxxxxxx], val=TxEntryValueHolder [op=TRANSFORM], prevVal=TxEntryValueHolder [op=NOOP], oldVal=TxEntryValueHolder [op=NOOP], entryProcessorsCol=LinkedList [T2 {org.gridgain.grid.internal.processors.security.GridEntSecurityProcessor$AddSubjectNode@b205f19=Object[] []}], ttl=-1, conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null, filters=CacheEntryPredicate[] [], filtersPassed=false, filtersSet=true, entry=GridCacheMapEntry [ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0], hash=278770679, extras=null, flags=0]GridDistributedCacheEntry [super=]GridDhtDetachedCacheEntry [super=], prepared=0, locked=false, nodeId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, locMapped=false, expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null, xidVer=GridCacheVersion [topVer=199920424, order=1592052840768, nodeOrder=40]]], explicitLock=false, dhtVer=null, last=false, nearEntries=0, clientFirst=false, node=4d40a649-681c-42f8-8f11-85f471ec21da]], nearLocallyMapped=false, colocatedLocallyMapped=false, needCheckBackup=null, hasRemoteLocks=false, trackTimeout=false, systemTime=0, systemStartTime=10318651595673684, prepareStartTime=10318651595673938, prepareTime=0, commitOrRollbackStartTime=0, commitOrRollbackTime=0, txDumpsThrottling=o.a.i.i.processors.cache.transactions.IgniteTxManager$TxDumpsThrottling@54e45a49, lb=null, thread=<failed to find active thread 19506012>, mappings=IgniteTxMappingsSingleImpl [mapping=GridDistributedTxMapping [entries=LinkedHashSet [IgniteTxEntry [txKey=IgniteTxKey [cacheId=xxxxxxxxxxx], val=TxEntryValueHolder [op=TRANSFORM], prevVal=TxEntryValueHolder [op=NOOP], oldVal=TxEntryValueHolder [op=NOOP], entryProcessorsCol=LinkedList [T2 {org.gridgain.grid.internal.processors.security.GridEntSecurityProcessor$AddSubjectNode@b205f19=Object[] []}], ttl=-1, conflictExpireTime=-1, conflictVer=null, explicitVer=null, dhtVer=null, filters=CacheEntryPredicate[] [], filtersPassed=false, filtersSet=true, entry=GridCacheMapEntry [ver=GridCacheVersion [topVer=0, order=0, nodeOrder=0], hash=278770679, extras=null, flags=0]GridDistributedCacheEntry [super=]GridDhtDetachedCacheEntry [super=], prepared=0, locked=false, nodeId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, locMapped=false, expiryPlc=null, transferExpiryPlc=false, flags=0, partUpdateCntr=0, serReadVer=null, xidVer=GridCacheVersion [topVer=199920424, order=1592052840768, nodeOrder=40]]], explicitLock=false, dhtVer=null, last=false, nearEntries=0, clientFirst=false, node=4d40a649-681c-42f8-8f11-85f471ec21da]], super=GridDhtTxLocalAdapter [nearOnOriginatingNode=false, nearNodes=KeySetView [], dhtNodes=KeySetView [], explicitLock=false, super=IgniteTxLocalAdapter [completedBase=null, sndTransformedVals=false, depEnabled=false, txState=IgniteTxImplicitSingleStateImpl [init=true, recovery=false], super=IgniteTxAdapter [xidVer=GridCacheVersion [topVer=199920424, order=1592052840768, nodeOrder=40], writeVer=null, implicit=true, loc=true, threadId=19506012, startTime=1592080208115, nodeId=48cf019e-0798-48ac-8c88-4f43e5908388, startVer=GridCacheVersion [topVer=199920424, order=1592052840768, nodeOrder=40], endVer=null, isolation=READ_COMMITTED, concurrency=OPTIMISTIC, timeout=0, sysInvalidate=false, sys=true, plc=5, commitVer=GridCacheVersion [topVer=199920424, order=1592052840768, nodeOrder=40], finalizing=NONE, invalidParts=null, state=PREPARING, timedOut=false, topVer=AffinityTopologyVersion [topVer=592, minorTopVer=0], skipCompletedVers=false, duration=67356ms, onePhaseCommit=false], size=1]]]]
|
LRT |
deadlock |
Deadlock: true
Completed: 298100
Thread [name=""sys-stripe-3-#4"", id=xx, state=WAITING, blockCnt=579, waitCnt=234477]
Lock [object=java.util.concurrent.locks.ReentrantLock$NonfairSync@6a5e882b, ownerName=sys-stripe-6-#7, ownerId=xx]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at o.a.i.i.processors.cache.GridCacheMapEntry.lockEntry(GridCacheMapEntry.java:5033)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.lockEntries(GridDhtAtomicCache.java:3093)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.updateAllAsyncInternal0(GridDhtAtomicCache.java:1806)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.updateAllAsyncInternal(GridDhtAtomicCache.java:1714)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.processNearAtomicUpdateRequest(GridDhtAtomicCache.java:3301)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache.access$400(GridDhtAtomicCache.java:141)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache$5.apply(GridDhtAtomicCache.java:273)
at o.a.i.i.processors.cache.distributed.dht.atomic.GridDhtAtomicCache$5.apply(GridDhtAtomicCache.java:268)
at o.a.i.i.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
at o.a.i.i.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
at o.a.i.i.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
at o.a.i.i.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
at o.a.i.i.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
at o.a.i.i.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
at o.a.i.i.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1843)
at o.a.i.i.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1468)
at o.a.i.i.managers.communication.GridIoManager.access$5200(GridIoManager.java:229)
at o.a.i.i.managers.communication.GridIoManager$9.run(GridIoManager.java:1365)
at o.a.i.i.util.StripedExecutor$Stripe.body(StripedExecutor.java:555)
at o.a.i.i.util.worker.GridWorker.run(GridWorker.java:120) <br> at java.lang.Thread.run(Thread.java:748)
|
Взаимная блокировка |
Cluster-wide snapshot operation started |
[IgniteSnapshotManager] Cluster-wide snapshot operation started [snpName=MySnapshot, grps=[1794698200]]
|
Запуск операции создания снепшота |
Cluster-wide snapshot operation finished successfully |
[IgniteSnapshotManager] Cluster-wide snapshot operation finished successfully: SnapshotOperationRequest [rqId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, srcNodeId=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxx, snpName=MySnapshot, grpIds=ArrayList [1794698200], bltNodes=HashSet [b7b71afb-32c5-4730-b0dc-5090920cf4f0], err=null]
|
Завершение операции создания снепшота |