Hello! I can see a lot of activity from your side, and ask you to participate in debugging and development.
Please file tickets about the issues that you encounter and propose fixes. I think you have as much expertise around writing security plugin as anybody else. Regards, -- Ilya Kasnacheev чт, 12 мар. 2020 г. в 16:19, VeenaMithare <[email protected]>: > 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/ > >
