Hi All,
I recently upgraded from Ignite 2.10 to Ignite 2.16 and faced a problem
with one server now, which was not responding.Its working fine after
restarting the server node.
[07:28:59,440][INFO][tcp-disco-srvr-[:59500]-#3%Commondynamic%-#43%Commondynamic%][TcpDiscoverySpi]
TCP discovery spawning a new thread for connection [rmtAddr=/127.0.1.1,
rmtPort=52445]
[07:28:59,443][INFO][tcp-disco-sock-reader-[]-#8%Commondynamic%-#530%Commondynamic%][TcpDiscoverySpi]
Started serving remote node connection [rmtAddr=/127.0.1.1:52445,
rmtPort=52445]
[07:28:59,447][INFO][tcp-disco-sock-reader-[acbfc28a 127.0.1.1:52445
client]-#8%Commondynamic%-#530%Commondynamic%][TcpDiscoverySpi] Initialized
connection with remote client node
[nodeId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, rmtAddr=/127.0.1.1:52445]
[07:28:59,601][INFO][disco-event-worker-#49%Commondynamic%][GridDiscoveryManager]
Added new node to topology: TcpDiscoveryNode
[id=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
consistentId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, addrs=ArrayList
[127.0.1.1], sockAddrs=null, discPort=0, order=4, intOrder=4,
lastExchangeTime=1730705339569, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=true]
[07:28:59,605][INFO][disco-event-worker-#49%Commondynamic%][GridDiscoveryManager]
Topology snapshot [ver=4, locNode=686fe4c5, servers=2, clients=2,
state=ACTIVE, CPUs=36, offheap=20.0GB, heap=22.0GB,
aliveNodes=[TcpDiscoveryNode [id=b7775887-3832-4cc1-8129-daa364404fdc,
consistentId=127.0.0.1:59500, isClient=false,
ver=2.16.0#20231215-sha1:7bde6a42], TcpDiscoveryNode
[id=686fe4c5-9d34-4063-99a3-1b8e4624cd0f, consistentId=127.0.0.2:59500,
isClient=false, ver=2.16.0#20231215-sha1:7bde6a42], TcpDiscoveryNode
[id=e8a0f6fd-c6f9-410c-b1a9-17ec45c5d38f,
consistentId=e8a0f6fd-c6f9-410c-b1a9-17ec45c5d38f, isClient=true,
ver=2.16.0#20231215-sha1:7bde6a42], TcpDiscoveryNode
[id=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
consistentId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, isClient=true,
ver=2.16.0#20231215-sha1:7bde6a42]]]
[07:28:59,605][INFO][disco-event-worker-#49%Commondynamic%][GridDiscoveryManager]
^-- Baseline [id=0, size=2, online=2, offline=0]
[07:28:59,609][INFO][exchange-worker-#50%Commondynamic%][time] Started
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=0],
crd=false, evt=NODE_JOINED, evtNode=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
customEvt=null, allowMerge=true, exchangeFreeSwitch=false]
[07:28:59,613][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=0],
err=null, rebalanced=true, wasRebalanced=true]
[07:28:59,630][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Completed partition exchange
[localNode=686fe4c5-9d34-4063-99a3-1b8e4624cd0f,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=4, minorTopVer=0], evt=NODE_JOINED, evtNode=TcpDiscoveryNode
[id=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
consistentId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, addrs=ArrayList
[127.0.1.1], sockAddrs=null, discPort=0, order=4, intOrder=4,
lastExchangeTime=1730705339569, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=true], rebalanced=true,
done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=4,
minorTopVer=0]]
[07:28:59,631][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange timings [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=0],
stage="Waiting in exchange queue" (2 ms), stage="Exchange parameters
initialization" (0 ms), stage="Determine exchange type" (3 ms),
stage="Exchange done" (18 ms), stage="Total time" (23 ms)]
[07:28:59,631][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=0]]
[07:28:59,631][INFO][exchange-worker-#50%Commondynamic%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=0],
crd=false]
[07:28:59,665][INFO][exchange-worker-#50%Commondynamic%][GridCachePartitionExchangeManager]
AffinityTopologyVersion [topVer=4, minorTopVer=0], evt=NODE_JOINED,
evtNode=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, client=false]
[07:29:30,858][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:01:00.305]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.88%, GC=0%]
^-- Heap [used=468MB, free=93.41%, comm=577MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=8, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:30:30,864][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:02:00.309]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.88%, GC=0%]
^-- Heap [used=214MB, free=96.98%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:31:30,868][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:03:00.311]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.17%, avgLoad=0.88%, GC=0%]
^-- Heap [used=222MB, free=96.88%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:32:30,870][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:04:00.318]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.4%, avgLoad=0.87%, GC=0%]
^-- Heap [used=228MB, free=96.78%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:33:30,870][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:05:00.318]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.86%, GC=0%]
^-- Heap [used=236MB, free=96.68%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:34:30,877][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:06:00.322]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.86%, GC=0%]
^-- Heap [used=243MB, free=96.58%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:35:30,879][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:07:00.328]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.85%, GC=0%]
^-- Heap [used=250MB, free=96.48%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:36:30,881][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:08:00.329]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.85%, GC=0%]
^-- Heap [used=257MB, free=96.38%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:37:30,888][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:09:00.333]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.43%, avgLoad=0.85%, GC=0%]
^-- Heap [used=264MB, free=96.28%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:38:30,890][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:10:00.337]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.84%, GC=0%]
^-- Heap [used=271MB, free=96.18%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:39:30,892][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:11:00.339]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.84%, GC=0%]
^-- Heap [used=278MB, free=96.08%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:40:30,890][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:12:00.339]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.83%, GC=0%]
^-- Heap [used=285MB, free=95.98%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:41:30,898][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:13:00.347]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.77%, avgLoad=0.83%, GC=0%]
^-- Heap [used=292MB, free=95.88%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:42:30,899][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:14:00.347]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.82%, GC=0%]
^-- Heap [used=299MB, free=95.78%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:43:30,907][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:15:00.355]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.4%, avgLoad=0.82%, GC=0%]
^-- Heap [used=306MB, free=95.68%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:44:30,913][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:16:00.362]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.5%, avgLoad=0.81%, GC=0%]
^-- Heap [used=313MB, free=95.59%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:45:30,921][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=686fe4c5, name=Commondynamic, uptime=01:17:00.370]
^-- Cluster [hosts=4, CPUs=36, servers=2, clients=2, topVer=4,
minorTopVer=0]
^-- Network [addrs=[127.0.0.2], localHost=127.0.0.2, discoPort=59500,
commPort=59605]
^-- CPU [CPUs=4, curLoad=0.4%, avgLoad=0.81%, GC=0%]
^-- Heap [used=320MB, free=95.49%, comm=582MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=7, qSize=0]
^-- Striped thread pool [active=0, idle=8, qSize=0]
[07:45:59,178][INFO][exchange-worker-#50%Commondynamic%][time] Started
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
crd=false, evt=DISCOVERY_CUSTOM_EVT,
evtNode=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
customEvt=DynamicCacheChangeBatch
[id=dc1c016f291-5febccea-eecb-41e5-82ce-f107332328f5, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=ListResultModel, hasCfg=false,
nodeId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, clientStartOnly=false,
stop=true, destroy=true, disabledAfterStart=false]],
exchangeActions=ExchangeActions [startCaches=null,
stopCaches=[ListResultModel], startGrps=[], stopGrps=[ListResultModel,
destroy=true], resetParts=null, finalizePartitionCounters=false,
stateChangeRequest=null], startCaches=false], allowMerge=false,
exchangeFreeSwitch=false]
[07:45:59,181][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
[07:45:59,185][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=b7775887-3832-4cc1-8129-daa364404fdc,
consistentId=127.0.0.1:59500, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:59500], discPort=59500, order=1, intOrder=1,
lastExchangeTime=1730701694349, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=false], ackSent=true,
super=CompletableLatch [id=CompletableLatchUid [id=exchange,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]]]
[07:45:59,185][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1], waitTime=0ms,
futInfo=NA, mode=LOCAL]
[07:45:59,313][INFO][exchange-worker-#50%Commondynamic%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
crd=false]
[07:45:59,413][INFO][sys-#664%Commondynamic%][GridDhtPartitionsExchangeFuture]
Received full message, will finish exchange
[node=b7775887-3832-4cc1-8129-daa364404fdc, resVer=AffinityTopologyVersion
[topVer=4, minorTopVer=1]]
[07:45:59,421][INFO][sys-#664%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
err=null, rebalanced=true, wasRebalanced=true]
[07:45:59,571][INFO][sys-#664%Commondynamic%][DurableBackgroundTasksProcessor]
Executing durable background task:
drop-sql-index-ListResultModel-LISTRESULTMODEL_SEARCHID_ASC_IDX-cd7dd777-7e79-443e-9302-e49603fd07e2
[07:45:59,577][INFO][async-worker-drop-sql-index-ListResultModel-LISTRESULTMODEL_SEARCHID_ASC_IDX-cd7dd777-7e79-443e-9302-e49603fd07e2-#670%Commondynamic%][DurableBackgroundTasksProcessor]
Execution of durable background task completed:
drop-sql-index-ListResultModel-LISTRESULTMODEL_SEARCHID_ASC_IDX-cd7dd777-7e79-443e-9302-e49603fd07e2
[07:45:59,581][INFO][sys-#664%Commondynamic%][DurableBackgroundTasksProcessor]
Executing durable background task:
drop-sql-index-ListResultModel-_key_PK-c810613b-8ab4-4469-acf1-89d898ae2089
[07:45:59,582][INFO][sys-#664%Commondynamic%][DurableBackgroundTasksProcessor]
Executing durable background task:
drop-sql-index-ListResultModel-LISTRESULTMODEL_CODE_ASC_IDX-2858655b-245e-49ef-9a68-c100bf8f0b28
[07:45:59,582][INFO][async-worker-drop-sql-index-ListResultModel-_key_PK-c810613b-8ab4-4469-acf1-89d898ae2089-#671%Commondynamic%][DurableBackgroundTasksProcessor]
Execution of durable background task completed:
drop-sql-index-ListResultModel-_key_PK-c810613b-8ab4-4469-acf1-89d898ae2089
[07:45:59,583][INFO][async-worker-drop-sql-index-ListResultModel-LISTRESULTMODEL_CODE_ASC_IDX-2858655b-245e-49ef-9a68-c100bf8f0b28-#672%Commondynamic%][DurableBackgroundTasksProcessor]
Execution of durable background task completed:
drop-sql-index-ListResultModel-LISTRESULTMODEL_CODE_ASC_IDX-2858655b-245e-49ef-9a68-c100bf8f0b28
[07:45:59,587][INFO][sys-#664%Commondynamic%][DurableBackgroundTasksProcessor]
Executing durable background task:
drop-sql-index-ListResultModel-LISTRESULTMODEL_ECHOTOKEN_ASC_IDX-c8d06174-fede-4248-be4c-95e2fdd4aae7
[07:45:59,588][INFO][async-worker-drop-sql-index-ListResultModel-LISTRESULTMODEL_ECHOTOKEN_ASC_IDX-c8d06174-fede-4248-be4c-95e2fdd4aae7-#673%Commondynamic%][DurableBackgroundTasksProcessor]
Execution of durable background task completed:
drop-sql-index-ListResultModel-LISTRESULTMODEL_ECHOTOKEN_ASC_IDX-c8d06174-fede-4248-be4c-95e2fdd4aae7
[07:45:59,612][INFO][sys-#664%Commondynamic%][GridCacheProcessor] Stopped
cache [cacheName=ListResultModel]
[07:45:59,697][INFO][sys-#664%Commondynamic%][GridDhtPartitionsExchangeFuture]
Completed partition exchange
[localNode=686fe4c5-9d34-4063-99a3-1b8e4624cd0f,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=4, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
evtNode=TcpDiscoveryNode [id=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
consistentId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, addrs=ArrayList
[127.0.1.1], sockAddrs=null, discPort=0, order=4, intOrder=4,
lastExchangeTime=1730705339569, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=true], rebalanced=true,
done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1]]
[07:45:59,699][INFO][sys-#664%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange timings [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (0 ms), stage="Update caches registry" (1 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="Wait partitions release [latch=exchange]" (0
ms), stage="Wait partitions release latch [latch=exchange]" (4 ms),
stage="Wait partitions release [latch=exchange]" (0 ms), stage="After
states restored callback" (77 ms), stage="WAL history reservation" (0 ms),
stage="Waiting for Full message" (150 ms), stage="Affinity recalculation"
(0 ms), stage="Full map updating" (7 ms), stage="Exchange done" (276 ms),
stage="Total time" (515 ms)]
[07:45:59,699][INFO][sys-#664%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=1]]
[07:45:59,767][INFO][exchange-worker-#50%Commondynamic%][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=4, minorTopVer=1], force=false, evt=DISCOVERY_CUSTOM_EVT,
node=acbfc28a-8ff0-4a11-88f7-e882c023fd2e]
[07:45:59,827][INFO][exchange-worker-#50%Commondynamic%][time] Started
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=2],
crd=false, evt=DISCOVERY_CUSTOM_EVT,
evtNode=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
customEvt=DynamicCacheChangeBatch
[id=072c016f291-5febccea-eecb-41e5-82ce-f107332328f5, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=ListResultModel, hasCfg=true,
nodeId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStart=false]],
exchangeActions=ExchangeActions [startCaches=[ListResultModel],
stopCaches=null, startGrps=[ListResultModel], stopGrps=[], resetParts=null,
finalizePartitionCounters=false, stateChangeRequest=null],
startCaches=false], allowMerge=false, exchangeFreeSwitch=false]
[07:45:59,836][INFO][exchange-worker-#50%Commondynamic%][GridCacheProcessor]
Started cache [name=ListResultModel, id=-1779834534,
dataRegionName=Common_Dynamic_Data_Region, mode=PARTITIONED,
atomicity=ATOMIC, backups=1]
[07:45:59,839][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
[07:45:59,851][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=b7775887-3832-4cc1-8129-daa364404fdc,
consistentId=127.0.0.1:59500, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:59500], discPort=59500, order=1, intOrder=1,
lastExchangeTime=1730701694349, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=false], ackSent=true,
super=CompletableLatch [id=CompletableLatchUid [id=exchange,
topVer=AffinityTopologyVersion [topVer=4, minorTopVer=2]]]]
[07:45:59,851][INFO][exchange-worker-#50%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=4, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=LOCAL]
[07:46:00,081][INFO][exchange-worker-#50%Commondynamic%][time] Finished
exchange init [topVer=AffinityTopologyVersion [topVer=4, minorTopVer=2],
crd=false]
[07:46:00,187][INFO][sys-#662%Commondynamic%][GridDhtPartitionsExchangeFuture]
Received full message, will finish exchange
[node=b7775887-3832-4cc1-8129-daa364404fdc, resVer=AffinityTopologyVersion
[topVer=4, minorTopVer=2]]
[07:46:00,204][INFO][sys-#662%Commondynamic%][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=2],
err=null, rebalanced=true, wasRebalanced=true]
[07:46:00,233][INFO][sys-#662%Commondynamic%][GridCacheProcessor] Finish
proxy initialization, cacheName=ListResultModel,
localNodeId=686fe4c5-9d34-4063-99a3-1b8e4624cd0f
[07:46:00,234][INFO][sys-#662%Commondynamic%][GridDhtPartitionsExchangeFuture]
Completed partition exchange
[localNode=686fe4c5-9d34-4063-99a3-1b8e4624cd0f,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=4, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT,
evtNode=TcpDiscoveryNode [id=acbfc28a-8ff0-4a11-88f7-e882c023fd2e,
consistentId=acbfc28a-8ff0-4a11-88f7-e882c023fd2e, addrs=ArrayList
[127.0.1.1], sockAddrs=null, discPort=0, order=4, intOrder=4,
lastExchangeTime=1730705339569, loc=false,
ver=2.16.0#20231215-sha1:7bde6a42, isClient=true], rebalanced=true,
done=true, newCrdFut=null], topVer=AffinityTopologyVersion [topVer=4,
minorTopVer=2]]
[07:46:00,234][INFO][sys-#662%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange timings [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=2],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (0 ms), stage="Update caches registry" (0 ms), stage="Start
caches" (9 ms), stage="Affinity initialization on cache group start" (1
ms), stage="Determine exchange type" (0 ms), stage="Preloading
notification" (0 ms), stage="Wait partitions release [latch=exchange]" (0
ms), stage="Wait partitions release latch [latch=exchange]" (11 ms),
stage="Wait partitions release [latch=exchange]" (0 ms), stage="After
states restored callback" (184 ms), stage="WAL history reservation" (0 ms),
stage="Waiting for Full message" (151 ms), stage="Affinity recalculation"
(0 ms), stage="Full map updating" (16 ms), stage="Exchange done" (29 ms),
stage="Total time" (401 ms)]
[07:46:00,234][INFO][sys-#662%Commondynamic%][GridDhtPartitionsExchangeFuture]
Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=4,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=4, minorTopVer=2],
stage="Affinity initialization on cache group start [grp=ListResultModel]"
(1 ms) (parent=Affinity initialization on cache group start)]
[07:46:00,301][INFO][exchange-worker-#50%Commondynamic%][GridCachePartitionExchangeManager]
Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=4, minorTopVer=2], force=false, evt=DISCOVERY_CUSTOM_EVT,
node=acbfc28a-8ff0-4a11-88f7-e882c023fd2e]
[07:46:30,929][INFO][grid-timeout-worker-#22%Commondynamic%][IgniteKernal%Commondynamic]
Thanks,
Charlin
