This fails when the security plugin is enabled. When I remove the security
plugin, the query goes through.
With the security plugin enabled, it hangs at :
GridReduceQueryExecutor - on awaitallReplies method. Attached screenshot of
thread , when it hangs.
Steps I take :
1. Start my server with 2.8.0 and the security plugin enabled.
Also the logs are :
============================================================================================
Server 1 :
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: New next node [newNext=TcpDiscoveryNode
[id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47501, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47501, /127.0.0.1:47501,
machinename.companyname.LOCAL/x.x.x.y:47501], discPort=47501, order=0,
intOrder=2, lastExchangeTime=1584018173124, loc=false,
ver=2.8.0#20200226-sha1:341b01df, isClient=false]]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: TCP discovery accepted incoming connection [rmtAddr=/0:0:0:0:0:0:0:1,
rmtPort=63143]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: TCP discovery spawning a new thread for connection
[rmtAddr=/0:0:0:0:0:0:0:1, rmtPort=63143]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started serving remote node connection
[rmtAddr=/0:0:0:0:0:0:0:1:63143, rmtPort=63143]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Initialized connection with remote server node
[nodeId=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
rmtAddr=/0:0:0:0:0:0:0:1:63143]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Received activate request with BaselineTopology[id=0]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started state transition: true
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Received state change finish message: true
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Added new node to topology: TcpDiscoveryNode
[id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47501, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47501, /127.0.0.1:47501,
machinename.companyname.LOCAL/x.x.x.y:47501], discPort=47501, order=2,
intOrder=2, lastExchangeTime=1584018173124, loc=false,
ver=2.8.0#20200226-sha1:341b01df, isClient=false]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Topology snapshot [ver=2, locNode=96b07658, servers=2, clients=0,
state=ACTIVE, CPUs=32, offheap=13.0GB, heap=14.0GB]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: ^-- Baseline [id=0, size=2, online=2, offline=0]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], crd=true, evt=NODE_JOINED,
evtNode=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a, customEvt=null,
allowMerge=true, exchangeFreeSwitch=false]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partitions release latch: ServerLatch [permits=0,
pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0]]]]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0], waitTime=0ms,
futInfo=NA, mode=LOCAL]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], crd=true]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Accepted incoming communication connection [locAddr=/127.0.0.1:47100,
rmtAddr=/127.0.0.1:63144]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Coordinator received single message [ver=AffinityTopologyVersion
[topVer=2, minorTopVer=0], node=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
allReceived=true]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Coordinator received all messages, try merge
[ver=AffinityTopologyVersion [topVer=2, minorTopVer=0]]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=0]]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish exchange future [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=0],
err=null, rebalanced=false, wasRebalanced=true]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Completed partition exchange
[localNode=96b07658-525d-4230-92bc-4bb756c633c4,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=0], evt=NODE_JOINED, evtNode=TcpDiscoveryNode
[id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47501, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47501, /127.0.0.1:47501,
machinename.companyname.LOCAL/x.x.x.y:47501], discPort=47501, order=2,
intOrder=2, lastExchangeTime=1584018173124, loc=false,
ver=2.8.0#20200226-sha1:341b01df, isClient=false], done=true,
newCrdFut=null], topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0]]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange timings [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=0],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (0 ms), stage="Determine exchange type" (2 ms),
stage="Preloading notification" (0 ms), stage="WAL history reservation" (0
ms), stage="Wait partitions release" (12 ms), stage="Wait partitions release
latch" (7 ms), stage="Wait partitions release" (0 ms), stage="After states
restored callback" (0 ms), stage="Waiting for all single messages" (298 ms),
stage="Exchanges merge" (0 ms), stage="Affinity recalculation (crd)" (14
ms), stage="Collect update counters and create affinity messages" (2 ms),
stage="Validate partitions states" (0 ms), stage="Assign partitions states"
(0 ms), stage="Apply update counters" (0 ms), stage="Full message preparing"
(3 ms), stage="Full message sending" (6 ms), stage="State finish message
sending" (0 ms), stage="Exchange done" (1 ms), stage="Total time" (345 ms),
Discovery lag=53 ms, Latest started node
id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange longest local stages [startVer=AffinityTopologyVersion
[topVer=2, minorTopVer=0], resVer=AffinityTopologyVersion [topVer=2,
minorTopVer=0], stage="Affinity initialization (node join)
[grp=ignite-sys-cache, crd=true]" (9 ms) (parent=Affinity recalculation
(crd))]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=2, minorTopVer=0], force=false, evt=NODE_JOINED,
node=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a]
Mar 12, 2020 1:02:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished supplying rebalancing [grp=ignite-sys-cache,
demander=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0], topic=0]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], crd=true, evt=DISCOVERY_CUSTOM_EVT,
evtNode=96b07658-525d-4230-92bc-4bb756c633c4,
customEvt=CacheAffinityChangeMessage
[id=2c7d6dec071-87d6067d-1b6b-44b8-a596-18ff29dca0f4,
topVer=AffinityTopologyVersion [topVer=2, minorTopVer=0], exchId=null,
partsMsg=null, exchangeNeeded=true], allowMerge=false,
exchangeFreeSwitch=false]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=1], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partitions release latch: ServerLatch [permits=0,
pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=1]]]]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=1], waitTime=0ms,
futInfo=NA, mode=LOCAL]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], crd=true]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Coordinator received single message [ver=AffinityTopologyVersion
[topVer=2, minorTopVer=1], node=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
allReceived=true]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=1]]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish exchange future [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=1],
err=null, rebalanced=true, wasRebalanced=false]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Completed partition exchange
[localNode=96b07658-525d-4230-92bc-4bb756c633c4,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=1], evt=DISCOVERY_CUSTOM_EVT,
evtNode=TcpDiscoveryNode [id=96b07658-525d-4230-92bc-4bb756c633c4,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47500, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47500, /127.0.0.1:47500,
machinename.companyname.LOCAL/x.x.x.y:47500], discPort=47500, order=1,
intOrder=1, lastExchangeTime=1584018175368, loc=true,
ver=2.8.0#20200226-sha1:341b01df, isClient=false], done=true,
newCrdFut=null], topVer=AffinityTopologyVersion [topVer=2, minorTopVer=1]]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange timings [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=1],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (0 ms), stage="Determine exchange type" (2 ms),
stage="Preloading notification" (0 ms), stage="WAL history reservation" (0
ms), stage="Wait partitions release" (0 ms), stage="Wait partitions release
latch" (46 ms), stage="Wait partitions release" (0 ms), stage="After states
restored callback" (0 ms), stage="Waiting for all single messages" (11 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="Exchange done" (1 ms),
stage="Total time" (62 ms), Discovery lag=25 ms, Latest started node
id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=2, minorTopVer=1], force=false, evt=DISCOVERY_CUSTOM_EVT,
node=96b07658-525d-4230-92bc-4bb756c633c4]
Mar 12, 2020 1:02:55 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange longest local stages [startVer=AffinityTopologyVersion
[topVer=2, minorTopVer=1], resVer=AffinityTopologyVersion [topVer=2,
minorTopVer=1], stage="Affinity change by custom message
[grp=ignite-sys-cache]" (2 ms) (parent=Determine exchange type)]
Mar 12, 2020 1:03:31 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 3108 milliseconds.
2020-03-12 13:03:31,644 [client-connector-#140] DEBUG
com.companynamemarkets.prophet.configstore.common.plugin.security.SecurityLDAPProcessorPlugin
[] - IGNITE SECURITY : SecurityLDAPProcessorPlugin : Entered the
authenticate block 1921da96-1171-4a66-abbb-721958381659 Login vmithare
2020-03-12 13:03:31,786 [client-connector-#142] DEBUG
com.companynamemarkets.prophet.configstore.common.plugin.security.SecurityLDAPProcessorPlugin
[] - IGNITE SECURITY : SecurityLDAPProcessorPlugin : Entered the
authenticate block 79d90536-1589-46b1-b609-7e6692356787 Login vmithare
Mar 12, 2020 1:03:38 PM org.apache.ignite.logger.java.JavaLogger info
INFO:
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=96b07658, uptime=00:01:00.010]
^-- H/N/C [hosts=1, nodes=2, CPUs=32]
^-- CPU [cur=0.17%, avg=0.14%, GC=0%]
^-- PageMemory [pages=200]
^-- Heap [used=178MB, free=97.53%, comm=732MB]
^-- Off-heap [used=0MB, free=99.99%, comm=80MB]
^-- sysMemPlc region [used=0MB, free=99.21%, comm=40MB]
^-- default region [used=0MB, free=100%, comm=0MB]
^-- TxLog region [used=0MB, free=100%, comm=40MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=27, qSize=0]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], crd=true, evt=DISCOVERY_CUSTOM_EVT,
evtNode=96b07658-525d-4230-92bc-4bb756c633c4,
customEvt=DynamicCacheChangeBatch
[id=679d6dec071-87d6067d-1b6b-44b8-a596-18ff29dca0f4, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_DEF, hasCfg=true,
nodeId=96b07658-525d-4230-92bc-4bb756c633c4, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_DEF],
stopCaches=null, startGrps=[SQL_PUBLIC_DEF], stopGrps=[], resetParts=null,
stateChangeRequest=null], startCaches=false], allowMerge=false,
exchangeFreeSwitch=false]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started cache [name=SQL_PUBLIC_DEF, id=-897950656,
dataRegionName=default, mode=PARTITIONED, atomicity=ATOMIC, backups=0,
mvcc=false]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partitions release latch: ServerLatch [permits=0,
pendingAcks=HashSet [], super=CompletableLatch [id=CompletableLatchUid
[id=exchange, topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=LOCAL]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], crd=true]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Coordinator received single message [ver=AffinityTopologyVersion
[topVer=2, minorTopVer=2], node=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
allReceived=true]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: finishExchangeOnCoordinator [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish exchange future [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
err=null, rebalanced=true, wasRebalanced=true]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish proxy initialization, cacheName=SQL_PUBLIC_DEF,
localNodeId=96b07658-525d-4230-92bc-4bb756c633c4
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Completed partition exchange
[localNode=96b07658-525d-4230-92bc-4bb756c633c4,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT,
evtNode=TcpDiscoveryNode [id=96b07658-525d-4230-92bc-4bb756c633c4,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47500, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47500, /127.0.0.1:47500,
machinename.companyname.LOCAL/x.x.x.y:47500], discPort=47500, order=1,
intOrder=1, lastExchangeTime=1584018221884, loc=true,
ver=2.8.0#20200226-sha1:341b01df, isClient=false], done=true,
newCrdFut=null], topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange timings [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (3 ms), stage="Update caches registry" (3 ms), stage="Start
caches" (78 ms), stage="Affinity initialization on cache group start" (7
ms), stage="Determine exchange type" (0 ms), stage="Preloading notification"
(0 ms), stage="WAL history reservation" (0 ms), stage="Wait partitions
release" (1 ms), stage="Wait partitions release latch" (2 ms), stage="Wait
partitions release" (0 ms), stage="After states restored callback" (39 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="Apply update counters" (0
ms), stage="Full message preparing" (2 ms), stage="Full message sending" (0
ms), stage="Exchange done" (2 ms), stage="Total time" (137 ms), Discovery
lag=17 ms, Latest started node id=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange longest local stages [startVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], stage="Affinity initialization on cache group start
[grp=SQL_PUBLIC_DEF]" (7 ms) (parent=Affinity initialization on cache group
start)]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=2, minorTopVer=2], force=false, evt=DISCOVERY_CUSTOM_EVT,
node=96b07658-525d-4230-92bc-4bb756c633c4]
Mar 12, 2020 1:04:12 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 3170 milliseconds.
Mar 12, 2020 1:04:13 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 565 milliseconds.
Mar 12, 2020 1:04:13 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 534 milliseconds.
Mar 12, 2020 1:04:14 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 890 milliseconds.
Mar 12, 2020 1:04:15 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 623 milliseconds.
Mar 12, 2020 1:04:16 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 600 milliseconds.
Mar 12, 2020 1:04:17 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 969 milliseconds.
Mar 12, 2020 1:04:18 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 755 milliseconds.
Mar 12, 2020 1:04:19 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 601 milliseconds.
Mar 12, 2020 1:04:21 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 597 milliseconds.
Mar 12, 2020 1:04:23 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 884 milliseconds.
Mar 12, 2020 1:04:23 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 576 milliseconds.
Mar 12, 2020 1:04:24 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 565 milliseconds.
Mar 12, 2020 1:04:27 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 792 milliseconds.
Mar 12, 2020 1:04:29 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 1046 milliseconds.
Mar 12, 2020 1:04:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Local node seems to be disconnected from topology (failure detection
timeout is reached) [failureDetectionTimeout=10000, connCheckInterval=500]
Mar 12, 2020 1:04:41 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 12185 milliseconds.
Mar 12, 2020 1:04:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: TCP discovery accepted incoming connection [rmtAddr=/127.0.0.1,
rmtPort=63159]
Mar 12, 2020 1:04:42 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=grid-nio-worker-tcp-comm-11,
threadName=grid-nio-worker-tcp-comm-11-#83, blockedFor=12s]
Mar 12, 2020 1:04:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: TCP discovery spawning a new thread for connection
[rmtAddr=/127.0.0.1, rmtPort=63159]
Mar 12, 2020 1:04:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished serving remote node connection
[rmtAddr=/0:0:0:0:0:0:0:1:63143, rmtPort=63143
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="grid-nio-worker-tcp-comm-11-#83", id=112,
state=RUNNABLE, blockCnt=0, waitCnt=0]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Possible too long JVM pause: 1208 milliseconds.
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started serving remote node connection [rmtAddr=/127.0.0.1:63159,
rmtPort=63159]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger info
INFO:
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=96b07658, uptime=00:02:04.973]
^-- H/N/C [hosts=1, nodes=2, CPUs=32]
^-- CPU [cur=0.13%, avg=0.12%, GC=0%]
^-- PageMemory [pages=1264]
^-- Heap [used=214MB, free=97.03%, comm=732MB]
^-- Off-heap [used=4MB, free=99.93%, comm=336MB]
^-- sysMemPlc region [used=0MB, free=99.21%, comm=40MB]
^-- default region [used=4MB, free=99.94%, comm=256MB]
^-- TxLog region [used=0MB, free=100%, comm=40MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=5, qSize=0]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Initialized connection with remote server node
[nodeId=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a, rmtAddr=/127.0.0.1:63159]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=grid-nio-worker-tcp-comm-11,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=grid-nio-worker-tcp-comm-11, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283558, 2020-03-12
13:04:43.558)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=partition-exchanger,
threadName=exchange-worker-#103, blockedFor=14s]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="exchange-worker-#103", id=162, state=TIMED_WAITING,
blockCnt=0, waitCnt=32]
Lock
[object=java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@7eb5c0f3,
ownerName=null, ownerId=-1]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=partition-exchanger,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=partition-exchanger, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283564, 2020-03-12
13:04:43.564)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=grid-nio-worker-tcp-comm-10,
threadName=grid-nio-worker-tcp-comm-10-#82, blockedFor=14s]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="grid-nio-worker-tcp-comm-10-#82", id=111,
state=RUNNABLE, blockCnt=0, waitCnt=0]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=grid-nio-worker-tcp-comm-10,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=grid-nio-worker-tcp-comm-10, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283565, 2020-03-12
13:04:43.565)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=grid-nio-worker-tcp-comm-14,
threadName=grid-nio-worker-tcp-comm-14-#86, blockedFor=14s]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="grid-nio-worker-tcp-comm-14-#86", id=115,
state=RUNNABLE, blockCnt=0, waitCnt=0]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=grid-nio-worker-tcp-comm-14,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=grid-nio-worker-tcp-comm-14, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283566, 2020-03-12
13:04:43.566)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=nio-acceptor-tcp-comm,
threadName=nio-acceptor-tcp-comm-#88, blockedFor=14s]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="nio-acceptor-tcp-comm-#88", id=120, state=RUNNABLE,
blockCnt=1, waitCnt=0]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=nio-acceptor-tcp-comm,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=nio-acceptor-tcp-comm, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283566, 2020-03-12
13:04:43.566)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger error
SEVERE: Blocked system-critical thread has been detected. This can lead to
cluster-wide undefined behaviour [workerName=grid-nio-worker-tcp-comm-9,
threadName=grid-nio-worker-tcp-comm-9-#81, blockedFor=14s]
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Thread [name="grid-nio-worker-tcp-comm-9-#81", id=110,
state=RUNNABLE, blockCnt=0, waitCnt=0]
Mar 12, 2020 1:04:43 PM java.util.logging.LogManager$RootLogger log
WARNING: Possible failure suppressed accordingly to a configured handler
[hnd=StopNodeOrHaltFailureHandler [tryStop=false, timeout=0,
super=AbstractFailureHandler [ignoredFailureTypes=UnmodifiableSet
[SYSTEM_WORKER_BLOCKED, SYSTEM_CRITICAL_OPERATION_TIMEOUT]]],
failureCtx=FailureContext [type=SYSTEM_WORKER_BLOCKED, err=class
o.a.i.IgniteException: GridWorker [name=grid-nio-worker-tcp-comm-9,
igniteInstanceName=null, finished=false, heartbeatTs=1584018269555]]]
class org.apache.ignite.IgniteException: GridWorker
[name=grid-nio-worker-tcp-comm-9, igniteInstanceName=null, finished=false,
heartbeatTs=1584018269555]
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1803)
at
org.apache.ignite.internal.IgnitionEx$IgniteNamedInstance$2.apply(IgnitionEx.java:1798)
at
org.apache.ignite.internal.worker.WorkersRegistry.onIdle(WorkersRegistry.java:234)
at
org.apache.ignite.internal.util.worker.GridWorker.onIdle(GridWorker.java:297)
at
org.apache.ignite.internal.processors.cache.GridCacheSharedTtlCleanupManager$CleanupWorker.body(GridCacheSharedTtlCleanupManager.java:194)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at java.lang.Thread.run(Thread.java:748)
Mar 12, 2020 1:04:43 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Page locks dump:
Thread=[name=exchange-worker-#103, id=162], state=TIMED_WAITING
Locked pages = []
Locked pages log: name=exchange-worker-#103 time=(1584018283567, 2020-03-12
13:04:43.567)
=====================================================================
Server 2 :
INFO: Started exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], crd=false, evt=DISCOVERY_CUSTOM_EVT,
evtNode=96b07658-525d-4230-92bc-4bb756c633c4,
customEvt=DynamicCacheChangeBatch
[id=679d6dec071-87d6067d-1b6b-44b8-a596-18ff29dca0f4, reqs=ArrayList
[DynamicCacheChangeRequest [cacheName=SQL_PUBLIC_DEF, hasCfg=true,
nodeId=96b07658-525d-4230-92bc-4bb756c633c4, clientStartOnly=false,
stop=false, destroy=false, disabledAfterStartfalse]],
exchangeActions=ExchangeActions [startCaches=[SQL_PUBLIC_DEF],
stopCaches=null, startGrps=[SQL_PUBLIC_DEF], stopGrps=[], resetParts=null,
stateChangeRequest=null], startCaches=false], allowMerge=false,
exchangeFreeSwitch=false]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Started cache [name=SQL_PUBLIC_DEF, id=-897950656,
dataRegionName=default, mode=PARTITIONED, atomicity=ATOMIC, backups=0,
mvcc=false]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=DISTRIBUTED]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partitions release latch: ClientLatch
[coordinator=TcpDiscoveryNode [id=96b07658-525d-4230-92bc-4bb756c633c4,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47500, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47500, /127.0.0.1:47500,
machinename.companyname.LOCAL/x.x.x.y:47500], discPort=47500, order=1,
intOrder=1, lastExchangeTime=1584018173220, loc=false,
ver=2.8.0#20200226-sha1:341b01df, isClient=false], ackSent=true,
super=CompletableLatch [id=CompletableLatchUid [id=exchange,
topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]]]
Mar 12, 2020 1:03:41 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished waiting for partition release future
[topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2], waitTime=0ms,
futInfo=NA, mode=LOCAL]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished exchange init [topVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], crd=false]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Received full message, will finish exchange
[node=96b07658-525d-4230-92bc-4bb756c633c4, resVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2]]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish exchange future [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
err=null, rebalanced=true, wasRebalanced=true]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finish proxy initialization, cacheName=SQL_PUBLIC_DEF,
localNodeId=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Completed partition exchange
[localNode=c003c5d9-08c9-404e-91c8-0a2b3ddbbb5a,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], evt=DISCOVERY_CUSTOM_EVT,
evtNode=TcpDiscoveryNode [id=96b07658-525d-4230-92bc-4bb756c633c4,
consistentId=0:0:0:0:0:0:0:1,x.x.x.y,127.0.0.1:47500, addrs=ArrayList
[0:0:0:0:0:0:0:1, x.x.x.y, 127.0.0.1], sockAddrs=HashSet
[/0:0:0:0:0:0:0:1:47500, /127.0.0.1:47500,
machinename.companyname.LOCAL/x.x.x.y:47500], discPort=47500, order=1,
intOrder=1, lastExchangeTime=1584018173220, loc=false,
ver=2.8.0#20200226-sha1:341b01df, isClient=false], done=true,
newCrdFut=null], topVer=AffinityTopologyVersion [topVer=2, minorTopVer=2]]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange timings [startVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2, minorTopVer=2],
stage="Waiting in exchange queue" (0 ms), stage="Exchange parameters
initialization" (3 ms), stage="Update caches registry" (3 ms), stage="Start
caches" (60 ms), stage="Affinity initialization on cache group start" (8
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" (4 ms), stage="Wait
partitions release" (0 ms), stage="After states restored callback" (32 ms),
stage="Waiting for Full message" (13 ms), stage="Affinity recalculation" (0
ms), stage="Full map updating" (2 ms), stage="Exchange done" (2 ms),
stage="Total time" (127 ms)]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Exchange longest local stages [startVer=AffinityTopologyVersion
[topVer=2, minorTopVer=2], resVer=AffinityTopologyVersion [topVer=2,
minorTopVer=2], stage="Affinity initialization on cache group start
[grp=SQL_PUBLIC_DEF]" (8 ms) (parent=Affinity initialization on cache group
start)]
Mar 12, 2020 1:03:42 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Skipping rebalancing (nothing scheduled) [top=AffinityTopologyVersion
[topVer=2, minorTopVer=2], force=false, evt=DISCOVERY_CUSTOM_EVT,
node=96b07658-525d-4230-92bc-4bb756c633c4]
Mar 12, 2020 1:03:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO:
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=c003c5d9, uptime=00:01:00.007]
^-- H/N/C [hosts=1, nodes=2, CPUs=32]
^-- CPU [cur=0.07%, avg=0.12%, GC=0%]
^-- PageMemory [pages=1192]
^-- Heap [used=138MB, free=98.09%, comm=620MB]
^-- Off-heap [used=4MB, free=99.93%, comm=336MB]
^-- sysMemPlc region [used=0MB, free=99.21%, comm=40MB]
^-- default region [used=3MB, free=99.94%, comm=256MB]
^-- TxLog region [used=0MB, free=100%, comm=40MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=27, qSize=0]
Mar 12, 2020 1:04:40 PM org.apache.ignite.logger.java.JavaLogger warning
WARNING: Timed out waiting for message delivery receipt (most probably, the
reason is in long GC pauses on remote node; consider tuning GC and
increasing 'ackTimeout' configuration property). Will retry to send message
with increased timeout [currentTimeout=10000,
rmtAddr=/0:0:0:0:0:0:0:1:47500, rmtPort=47500]
Mar 12, 2020 1:04:53 PM org.apache.ignite.logger.java.JavaLogger info
INFO:
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
^-- Node [id=c003c5d9, uptime=00:02:00.027]
^-- H/N/C [hosts=1, nodes=2, CPUs=32]
^-- CPU [cur=0.03%, avg=0.09%, GC=0%]
^-- PageMemory [pages=1192]
^-- Heap [used=142MB, free=98.02%, comm=620MB]
^-- Off-heap [used=4MB, free=99.93%, comm=336MB]
^-- sysMemPlc region [used=0MB, free=99.21%, comm=40MB]
^-- default region [used=3MB, free=99.94%, comm=256MB]
^-- TxLog region [used=0MB, free=100%, comm=40MB]
^-- Outbound messages queue [size=0]
^-- Public thread pool [active=0, idle=0, qSize=0]
^-- System thread pool [active=0, idle=6, qSize=0]
Mar 12, 2020 1:05:10 PM org.apache.ignite.logger.java.JavaLogger info
INFO: Finished serving remote node connection
[rmtAddr=/0:0:0:0:0:0:0:1:63142, rmtPort=63142
====================================================================
My Ignite config looks like :
<beans xmlns="http://www.springframework.org/schema/beans";
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance";
xsi:schemaLocation="
http://www.springframework.org/schema/beans
http://www.springframework.org/schema/beans/spring-beans.xsd";>
<bean id="grid.cfg"
class="org.apache.ignite.configuration.IgniteConfiguration">
<property name="pluginConfigurations">
<bean id="securityPlugin"
class="com.xxx.xxx.xxx.xxx.plugin.security.SecurityPluginConfiguration">
<constructor-arg value="xxx"/>
</bean>
</property>
<property name="discoverySpi" ref="tcpDiscSpiSpecific"/>
<property name="clientFailureDetectionTimeout" value="30000"/>
</bean>
<bean id="tcpPortConfig"
class="org.apache.ignite.spi.discovery.tcp.ipfinder.vm.TcpDiscoveryVmIpFinder">
<property name="addresses">
<list>
<value>127.0.0.1:47500..47502</value>
</list>
</property>
</bean>
<bean id="nodeSecurityCredential"
class="org.apache.ignite.plugin.security.SecurityCredentials">
<constructor-arg value="xxx"/>
<constructor-arg value="xxx"/>
</bean>
<bean id="tcpDiscSpiSpecific"
class="com.xxx.xxx.xxx.common.plugin.discoveryspi.CustomTcpDiscoverySpi"
parent="tcpDiscSpi">
</bean>
<bean id="tcpDiscSpi"
class="com.xxx.xxx.xxx.common.plugin.discoveryspi.CustomTcpDiscoverySpi"
abstract="true">
<constructor-arg ref="nodeSecurityCredential"/>
<property name="ipFinder" ref="tcpPortConfig"/>
</bean>
</beans>
<http://apache-ignite-users.70518.x6.nabble.com/file/t2757/queryhanging.png>
--
Sent from: http://apache-ignite-users.70518.x6.nabble.com/
