From 57eb247e8658bcd7705e298f5f49f766007df055 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Wed, 24 Apr 2024 16:51:41 +0300 Subject: [PATCH 01/24] IGNITE-21830 * New logs for socket connection check * Integration tests --- .../ignite/spi/discovery/tcp/ServerImpl.java | 10 +- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 338 ++++++++++++++++++ 2 files changed, 347 insertions(+), 1 deletion(-) create mode 100644 modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index db09f9148725c..d1267525e8c26 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7287,10 +7287,18 @@ private InetSocketAddress checkConnection(List addrs, int tim sock.connect(addr, perAddrTimeout); liveAddrHolder.compareAndSet(null, addr); + + if (log.isInfoEnabled()) + log.info("Successful connection to the server [address=" + addr + "]"); + } + else if (log.isInfoEnabled()) { + log.info("Connection to the server [address=" + addr + "] is ignored. " + + "Alive address is found at [address=" + liveAddrHolder.get() + "]"); } } catch (Exception ignored) { - // No-op. + U.warn(log, "Failed to connect the socket to the server [address=" + addr + + ", timeout=" + perAddrTimeout + ", cause=" + ignored.getMessage() + "]"); } finally { latch.countDown(); diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java new file mode 100644 index 0000000000000..84b6eead7be0d --- /dev/null +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -0,0 +1,338 @@ +package org.apache.ignite.spi.discovery.tcp; + +import java.io.IOException; +import java.io.OutputStream; +import java.net.InetSocketAddress; +import java.net.Socket; +import java.util.LinkedHashSet; +import java.util.UUID; +import java.util.concurrent.Callable; +import java.util.concurrent.CountDownLatch; +import org.apache.ignite.Ignite; +import org.apache.ignite.IgniteCheckedException; +import org.apache.ignite.configuration.IgniteConfiguration; +import org.apache.ignite.events.DiscoveryEvent; +import org.apache.ignite.events.Event; +import org.apache.ignite.internal.IgniteEx; +import org.apache.ignite.internal.IgniteInternalFuture; +import org.apache.ignite.internal.util.typedef.internal.U; +import org.apache.ignite.lang.IgnitePredicate; +import org.apache.ignite.spi.discovery.tcp.internal.TcpDiscoveryNode; +import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryAbstractMessage; +import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryNodeAddedMessage; +import org.apache.ignite.testframework.GridTestUtils; +import org.apache.ignite.testframework.ListeningTestLogger; +import org.apache.ignite.testframework.LogListener; +import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; +import org.junit.Test; + +import static org.apache.ignite.events.EventType.EVT_NODE_FAILED; +import static org.apache.ignite.testframework.GridTestUtils.waitForCondition; + +/** + * Class for {@link TcpDiscoverySpi} logging tests. + */ +public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { + /** + * Listener log messages + */ + private static ListeningTestLogger testLog; + + /** */ + private static final ThreadLocal nodeSpi = new ThreadLocal<>(); + + /** {@inheritDoc} */ + @Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception { + IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName); + + TcpDiscoverySpi spi = nodeSpi.get(); + + if (spi == null) + spi = new TcpDiscoverySpi(); + else + nodeSpi.set(null); + + cfg.setDiscoverySpi(spi); + + cfg.setGridLogger(testLog); + + return cfg; + } + + /** {@inheritDoc} */ + @Override protected void beforeTest() throws Exception { + super.beforeTest(); + + testLog = new ListeningTestLogger(log); + } + + /** {@inheritDoc} */ + @Override protected void afterTest() throws Exception { + testLog.clearListeners(); + + super.afterTest(); + } + + /** + * This test checks all the possible logs from socket connection after coordinator quiet close. + *

+ * There are 3 nodes used in the test. After the coordinator closure, the 3rd node will try to check the connection + * to the 2nd one. In other words the 3rd will try to connect to all effective addresses of the 2nd through socket, + * which can be accessed with 3's Discovery SPI. + *

+ * For us to get multiple effective addresses for connection, we override + * {@link TcpDiscoverySpi#getEffectiveNodeAddresses(TcpDiscoveryNode)} method in + * {@link TestCustomEffectiveNodeAddressesSpi} to return custom collection of {@link InetSocketAddress}. + * We only need the custom collection once, when 3rd node is trying to probe the 2nd one. As the method is used in + * different other scenarios throughout the test, we restrain the method to deviate from expected behaviour only + * for the test case, that is when {@link TcpDiscoveryNode#discoveryPort()} is 47501. + *

+ * By manipulating the collection order we can check the failing, successful and ignored connection logs at once. + * + * @see TcpDiscoverySpi#getEffectiveNodeAddresses(TcpDiscoveryNode) + * @see TestCustomEffectiveNodeAddressesSpi + * @throws Exception If failed. + * */ + @Test + public void testMultipleSocketConnectionLogMessage() throws Exception { + LogListener lsnr = LogListener.matches(s -> + s.contains("Successful connection to the server [address=") || + s.contains("Failed to connect the socket to the server [address=") || + s.contains("Connection to the server [address=")).build(); + + testLog.registerListener(lsnr); + + try { + startGrid(0); + startGrid(1); + + TestCustomEffectiveNodeAddressesSpi spi = new TestCustomEffectiveNodeAddressesSpi(); + nodeSpi.set(spi); + + startGrid(2); + + ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + + assertTrue(waitForCondition(lsnr::check, 10_000L)); + } + finally { + stopAllGrids(); + } + } + + /** + * This test uses quiet closure of given {@link Socket} ignoring possible checked exception, which triggers + * the previous node to check the connection to the following surviving one. + * @see TcpDiscoverySpi#brakeConnection() + * @throws Exception If failed. + * */ + @Test + public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { + LogListener lsnr = LogListener.matches("Successful connection to the server [address=") + .atLeast(1) + .build(); + + testLog.registerListener(lsnr); + + try { + startGridsMultiThreaded(3); + ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + assertTrue(waitForCondition(lsnr::check, 10_000L)); + } + finally { + stopAllGrids(); + } + } + + /** + * This test uses node failure by stopping service threads, which makes the node unresponsive and results in + * failing connection to the server. + * @see TcpDiscoverySpi#simulateNodeFailure() + * @throws Exception If failed. + * */ + @Test + public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { + LogListener lsnr = LogListener.matches("Failed to connect the socket to the server [address=") + .atLeast(1) + .build(); + + testLog.registerListener(lsnr); + + try { + startGridsMultiThreaded(3); + ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); + + assertTrue(waitForCondition(lsnr::check, 10_000L)); + } + finally { + stopAllGrids(); + } + } + + /** + * Simulates coordinator's {@code NODE_FAILED} event + *

+ * Coordinator's (node-0) {@code NODE_FAILED} event is forced on the second in line node in the ring (node-1). + * This event leads the cluster to fall apart into 2 parts: coordinator and others nodes. As the previously known + * coordinator node (node-0) is not accessible anymore, the log should contain 'Failed to connect the socket + * to the server', when trying to check the connection from node-1. + * @throws Exception If failed. + */ + @Test + public void testCheckSocketConnectionFailureLogMessage() throws Exception { + LogListener lsnr = LogListener.matches("Failed to connect the socket to the server [address=") + .atLeast(1) + .build(); + + testLog.registerListener(lsnr); + + try { + IgniteEx coord = (IgniteEx)startGridsMultiThreaded(3); + + UUID coordId = coord.localNode().id(); + + IgniteEx ignite1 = grid(1); + + CountDownLatch failedLatch = new CountDownLatch(2); + + IgnitePredicate failLsnr = evt -> { + assertEquals(EVT_NODE_FAILED, evt.type()); + + UUID nodeId = ((DiscoveryEvent)evt).eventNode().id(); + + if (coordId.equals(nodeId)) + failedLatch.countDown(); + + return true; + }; + + ignite1.events().localListen(failLsnr, EVT_NODE_FAILED); + + grid(2).events().localListen(failLsnr, EVT_NODE_FAILED); + + ignite1.configuration().getDiscoverySpi().failNode(coordId, null); + + assertTrue(waitForCondition(lsnr::check, 10_000L));; + } + finally { + stopAllGrids(); + } + } + + /** + * Emulates coordinator's {@code NODE_FAILED} event in {@link TcpDiscoveryNodeAddedMessage} while new node joins + * the cluster with following coordinator shutdown. + *

+ * Coordinator's (node-0) {@code NODE_FAILED} event, happening on {@link TcpDiscoveryNodeAddedMessage} processing + * with following coordinator's shutdown, prompts the new node (node-2) to check previous node's addresses (node-1). + * As the previous node (node-1) is already established in new topology after the coordinator (node-0) shutdown, + * the log should contain 'Success connection to the server' message, which describes successful connection + * between new node (node-2) and previous surviving node (node-1). + * @throws Exception If failed. + */ + @Test + public void testCheckSocketConnectionSuccessLogMessage() throws Exception { + LogListener lsnr = LogListener.matches("Successful connection to the server [address=") + .atLeast(1) + .build(); + + testLog.registerListener(lsnr); + + try { + TestCustomEventLogSocketSpi spi0 = new TestCustomEventLogSocketSpi(); + + nodeSpi.set(spi0); + + final Ignite ignite0 = startGrid(0); + + TcpDiscoverySpi spi1 = new TcpDiscoverySpi(); + + nodeSpi.set(spi1); + + startGrid(1); + + CountDownLatch latch1 = new CountDownLatch(1); + CountDownLatch latch2 = new CountDownLatch(1); + + spi0.nodeAdded1 = latch1; + spi0.nodeAdded2 = latch2; + spi0.debug = true; + + IgniteInternalFuture fut1 = GridTestUtils.runAsync(new Callable() { + @Override public Void call() throws Exception { + startGrid(2); + + return null; + } + }); + + latch1.await(); + + spi0.stop = true; + + latch2.countDown(); + + ignite0.close(); + + fut1.get(); + + assertTrue(waitForCondition(lsnr::check, 10_000L)); + } + finally { + stopAllGrids(); + } + } + + private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi { + private final static LinkedHashSet customAddrs = new LinkedHashSet<>(); + + static { + customAddrs.add(new InetSocketAddress("127.0.0.1", 47505)); + customAddrs.add(new InetSocketAddress("127.0.0.1", 47501)); + customAddrs.add(new InetSocketAddress("127.0.0.1", 47503)); + customAddrs.add(new InetSocketAddress("127.0.0.1", 47504)); + } + + /** {@inheritDoc} */ + @Override LinkedHashSet getEffectiveNodeAddresses(TcpDiscoveryNode node) { + if(node.discoveryPort() == 47501) + return customAddrs; + + return super.getEffectiveNodeAddresses(node); + } + } + + private static class TestCustomEventLogSocketSpi extends TcpDiscoverySpi { + /** */ + private volatile CountDownLatch nodeAdded1; + + /** */ + private volatile CountDownLatch nodeAdded2; + + /** */ + private volatile boolean stop; + + /** */ + private boolean debug; + + /** {@inheritDoc} */ + @Override protected void writeToSocket(Socket sock, OutputStream out, TcpDiscoveryAbstractMessage msg, + long timeout) throws IOException, IgniteCheckedException { + if (msg instanceof TcpDiscoveryNodeAddedMessage) { + if (nodeAdded1 != null) { + nodeAdded1.countDown(); + + if (debug) + log.info("--- Wait node added: " + msg); + + U.await(nodeAdded2); + + if (stop) + return; + } + } + + super.writeToSocket(sock, out, msg, timeout); + } + } +} From 0aa975153c2e64eafb5f3b3f3af87f0955dcf7a6 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 25 Apr 2024 14:55:07 +0300 Subject: [PATCH 02/24] IGNITE-21830 * clean-up, checkstyle --- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 19 +++++++++++-------- 1 file changed, 11 insertions(+), 8 deletions(-) diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 84b6eead7be0d..5d80897a99011 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -97,8 +97,8 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { public void testMultipleSocketConnectionLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> s.contains("Successful connection to the server [address=") || - s.contains("Failed to connect the socket to the server [address=") || - s.contains("Connection to the server [address=")).build(); + s.contains("Failed to connect the socket to the server [address=") || + s.contains("Connection to the server [address=")).build(); testLog.registerListener(lsnr); @@ -111,7 +111,7 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { startGrid(2); - ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); assertTrue(waitForCondition(lsnr::check, 10_000L)); } @@ -136,7 +136,7 @@ public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws E try { startGridsMultiThreaded(3); - ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); assertTrue(waitForCondition(lsnr::check, 10_000L)); } finally { @@ -160,7 +160,7 @@ public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { try { startGridsMultiThreaded(3); - ((TcpDiscoverySpi) ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); + ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); assertTrue(waitForCondition(lsnr::check, 10_000L)); } @@ -212,7 +212,7 @@ public void testCheckSocketConnectionFailureLogMessage() throws Exception { ignite1.configuration().getDiscoverySpi().failNode(coordId, null); - assertTrue(waitForCondition(lsnr::check, 10_000L));; + assertTrue(waitForCondition(lsnr::check, 10_000L)); } finally { stopAllGrids(); @@ -283,8 +283,10 @@ public void testCheckSocketConnectionSuccessLogMessage() throws Exception { } } + /** {@inheritDoc} */ private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi { - private final static LinkedHashSet customAddrs = new LinkedHashSet<>(); + /** {@inheritDoc} */ + private static final LinkedHashSet customAddrs = new LinkedHashSet<>(); static { customAddrs.add(new InetSocketAddress("127.0.0.1", 47505)); @@ -295,13 +297,14 @@ private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi /** {@inheritDoc} */ @Override LinkedHashSet getEffectiveNodeAddresses(TcpDiscoveryNode node) { - if(node.discoveryPort() == 47501) + if (node.discoveryPort() == 47501) return customAddrs; return super.getEffectiveNodeAddresses(node); } } + /** {@inheritDoc} */ private static class TestCustomEventLogSocketSpi extends TcpDiscoverySpi { /** */ private volatile CountDownLatch nodeAdded1; From 4d0e1cef87312c2f71f1c899c8d68d45b080f83c Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 25 Apr 2024 15:49:14 +0300 Subject: [PATCH 03/24] IGNITE-21830 * clean-up, license --- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 5d80897a99011..bb4b2c73f0c01 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -1,3 +1,20 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + package org.apache.ignite.spi.discovery.tcp; import java.io.IOException; From 9cee5f87a1bdd035fdde22d13a1a3925599eecad Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 26 Apr 2024 11:51:56 +0300 Subject: [PATCH 04/24] IGNITE-21830 * redundant logging removed * tests corrected --- .../ignite/spi/discovery/tcp/ServerImpl.java | 5 +---- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 18 +++++++++--------- 2 files changed, 10 insertions(+), 13 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index d1267525e8c26..62b9e77f63557 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7287,9 +7287,6 @@ private InetSocketAddress checkConnection(List addrs, int tim sock.connect(addr, perAddrTimeout); liveAddrHolder.compareAndSet(null, addr); - - if (log.isInfoEnabled()) - log.info("Successful connection to the server [address=" + addr + "]"); } else if (log.isInfoEnabled()) { log.info("Connection to the server [address=" + addr + "] is ignored. " + @@ -7297,7 +7294,7 @@ else if (log.isInfoEnabled()) { } } catch (Exception ignored) { - U.warn(log, "Failed to connect the socket to the server [address=" + addr + + log.info("Failed to connect the socket to the server [address=" + addr + ", timeout=" + perAddrTimeout + ", cause=" + ignored.getMessage() + "]"); } finally { diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index bb4b2c73f0c01..563f5bab905d0 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -113,7 +113,7 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { @Test public void testMultipleSocketConnectionLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> - s.contains("Successful connection to the server [address=") || + s.contains("Connection check to previous node done: [liveAddr=/") || s.contains("Failed to connect the socket to the server [address=") || s.contains("Connection to the server [address=")).build(); @@ -145,7 +145,7 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { * */ @Test public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Successful connection to the server [address=") + LogListener lsnr = LogListener.matches("Connection check to previous node done: [liveAddr=/") .atLeast(1) .build(); @@ -169,9 +169,9 @@ public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws E * */ @Test public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Failed to connect the socket to the server [address=") - .atLeast(1) - .build(); + LogListener lsnr = LogListener.matches(s -> + s.contains("Connection check to previous node done: [liveAddr=null") || + s.contains("Failed to connect the socket to the server [address=")).build(); testLog.registerListener(lsnr); @@ -197,9 +197,9 @@ public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { */ @Test public void testCheckSocketConnectionFailureLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Failed to connect the socket to the server [address=") - .atLeast(1) - .build(); + LogListener lsnr = LogListener.matches(s -> + s.contains("Connection check to previous node done: [liveAddr=null") || + s.contains("Failed to connect the socket to the server [address=")).build(); testLog.registerListener(lsnr); @@ -249,7 +249,7 @@ public void testCheckSocketConnectionFailureLogMessage() throws Exception { */ @Test public void testCheckSocketConnectionSuccessLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Successful connection to the server [address=") + LogListener lsnr = LogListener.matches("Connection check to previous node done: [liveAddr=/") .atLeast(1) .build(); From 0497fae703761cd6fe6f8961448b393d344e18bd Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 26 Apr 2024 14:34:42 +0300 Subject: [PATCH 05/24] IGNITE-21830 * ignored connection logs removed --- .../java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java | 4 ---- .../ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java | 3 +-- 2 files changed, 1 insertion(+), 6 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 62b9e77f63557..8f7c133a30225 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7288,10 +7288,6 @@ private InetSocketAddress checkConnection(List addrs, int tim liveAddrHolder.compareAndSet(null, addr); } - else if (log.isInfoEnabled()) { - log.info("Connection to the server [address=" + addr + "] is ignored. " + - "Alive address is found at [address=" + liveAddrHolder.get() + "]"); - } } catch (Exception ignored) { log.info("Failed to connect the socket to the server [address=" + addr + diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 563f5bab905d0..16e6fa6e02442 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -114,8 +114,7 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { public void testMultipleSocketConnectionLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> s.contains("Connection check to previous node done: [liveAddr=/") || - s.contains("Failed to connect the socket to the server [address=") || - s.contains("Connection to the server [address=")).build(); + s.contains("Failed to connect the socket to the server [address=")).build(); testLog.registerListener(lsnr); From c4b04a88b1cd1b8c9fff49971fb2e1156a90841f Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 2 May 2024 15:19:36 +0300 Subject: [PATCH 06/24] IGNITE-21830 * Added nodeId to logs * Adjusted tests --- .../ignite/spi/discovery/tcp/ServerImpl.java | 25 +++++++++++++------ .../discovery/tcp/TcpDiscoverySpiLogTest.java | 24 ++++++++++-------- 2 files changed, 32 insertions(+), 17 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 8f7c133a30225..1346063c8bac0 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6770,7 +6770,6 @@ else if (req.changeTopology()) { if (previous != null && !previous.id().equals(nodeId) && (req.checkPreviousNodeId() == null || previous.id().equals(req.checkPreviousNodeId()))) { - Collection nodeAddrs = spi.getEffectiveNodeAddresses(previous); // The connection recovery connection to one node is connCheckTick. // We need to suppose network delays. So we use half of this time. @@ -6781,12 +6780,12 @@ else if (req.changeTopology()) { "previous [" + previous + "] with timeout " + backwardCheckTimeout); } - liveAddr = checkConnection(new ArrayList<>(nodeAddrs), backwardCheckTimeout); + liveAddr = checkConnection(previous, backwardCheckTimeout); if (log.isInfoEnabled()) { log.info("Connection check to previous node done: [liveAddr=" + liveAddr - + ", previousNode=" + U.toShortString(previous) + ", addressesToCheck=" + - nodeAddrs + ", connectingNodeId=" + nodeId + ']'); + + ", previousNode=" + U.toShortString(previous) + ", connectingNodeId=" + + nodeId + ']'); } } @@ -7254,9 +7253,11 @@ private void ringMessageReceived() { } /** @return Alive address if was able to connected to. {@code Null} otherwise. */ - private InetSocketAddress checkConnection(List addrs, int timeout) { + private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { AtomicReference liveAddrHolder = new AtomicReference<>(); + List addrs = new ArrayList<>(spi.getEffectiveNodeAddresses(node)); + CountDownLatch latch = new CountDownLatch(addrs.size()); int addrLeft = addrs.size(); @@ -7287,11 +7288,21 @@ private InetSocketAddress checkConnection(List addrs, int tim sock.connect(addr, perAddrTimeout); liveAddrHolder.compareAndSet(null, addr); + + if (log.isInfoEnabled()) { + log.info("Connection check to node: [addressToCheck=" + addr + + ", result=success, node=" + U.toShortString(node) + ']'); + } + } + else if (log.isInfoEnabled()) { + log.info("Connection check to node: [addressToCheck=" + addr + + ", result=skipped, node=" + U.toShortString(node) + ']'); } } catch (Exception ignored) { - log.info("Failed to connect the socket to the server [address=" + addr + - ", timeout=" + perAddrTimeout + ", cause=" + ignored.getMessage() + "]"); + log.info("Connection check to node: [addressToCheck=" + addr + + ", result=failed, cause=" + ignored.getMessage() + ", node=" + + U.toShortString(node) + ']'); } finally { latch.countDown(); diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 16e6fa6e02442..53216ae5841d0 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -113,8 +113,10 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { @Test public void testMultipleSocketConnectionLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> - s.contains("Connection check to previous node done: [liveAddr=/") || - s.contains("Failed to connect the socket to the server [address=")).build(); + (s.contains("Connection check to node") && s.contains("result=success")) || + (s.contains("Connection check to node") && s.contains("result=skipped")) || + (s.contains("Connection check to node") && s.contains("result=failed"))) + .build(); testLog.registerListener(lsnr); @@ -144,8 +146,8 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { * */ @Test public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Connection check to previous node done: [liveAddr=/") - .atLeast(1) + LogListener lsnr = LogListener.matches(s -> + (s.contains("Connection check to node") && s.contains("result=success"))) .build(); testLog.registerListener(lsnr); @@ -169,8 +171,9 @@ public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws E @Test public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> - s.contains("Connection check to previous node done: [liveAddr=null") || - s.contains("Failed to connect the socket to the server [address=")).build(); + s.contains("Connection check to previous node done: [liveAddr=null") || + (s.contains("Connection check to node") && s.contains("result=failed"))) + .build(); testLog.registerListener(lsnr); @@ -197,8 +200,9 @@ public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { @Test public void testCheckSocketConnectionFailureLogMessage() throws Exception { LogListener lsnr = LogListener.matches(s -> - s.contains("Connection check to previous node done: [liveAddr=null") || - s.contains("Failed to connect the socket to the server [address=")).build(); + s.contains("Connection check to previous node done: [liveAddr=null") || + (s.contains("Connection check to node") && s.contains("result=failed"))) + .build(); testLog.registerListener(lsnr); @@ -248,8 +252,8 @@ public void testCheckSocketConnectionFailureLogMessage() throws Exception { */ @Test public void testCheckSocketConnectionSuccessLogMessage() throws Exception { - LogListener lsnr = LogListener.matches("Connection check to previous node done: [liveAddr=/") - .atLeast(1) + LogListener lsnr = LogListener.matches(s -> + (s.contains("Connection check to node") && s.contains("result=success"))) .build(); testLog.registerListener(lsnr); From b89045733b91b415ec3d686eb3d26fb532033d1d Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 2 May 2024 16:00:55 +0300 Subject: [PATCH 07/24] IGNITE-21830 * test suit error fixed --- .../ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java | 2 ++ 1 file changed, 2 insertions(+) diff --git a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java index 1264c16124576..4a3ce340cd2a7 100644 --- a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java +++ b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java @@ -62,6 +62,7 @@ import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySnapshotHistoryTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiConfigSelfTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiFailureTimeoutSelfTest; +import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiLogTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiMBeanTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiReconnectDelayTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiSelfTest; @@ -107,6 +108,7 @@ TcpDiscoverySpiMBeanTest.class, TcpDiscoverySpiStartStopSelfTest.class, TcpDiscoverySpiConfigSelfTest.class, + TcpDiscoverySpiLogTest.class, TcpDiscoveryMarshallerCheckSelfTest.class, TcpDiscoverySnapshotHistoryTest.class, TcpDiscoveryNodeJoinAndFailureTest.class, From 269fecb6b6e9dbe229177e2136171567e7fd5b58 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 3 May 2024 17:27:36 +0300 Subject: [PATCH 08/24] IGNITE-21830 * Warning added for failures * logs builder --- .../ignite/spi/discovery/tcp/ServerImpl.java | 39 ++- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 224 ++++-------------- 2 files changed, 70 insertions(+), 193 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 1346063c8bac0..e7faf6924c63f 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6782,7 +6782,11 @@ else if (req.changeTopology()) { liveAddr = checkConnection(previous, backwardCheckTimeout); - if (log.isInfoEnabled()) { + if (liveAddr == null) { + U.warn(log, "Connection check to previous node failed: [previousNode=" + + U.toShortString(previous) + ", connectingNodeId=" + nodeId + ']'); + } + else if (log.isInfoEnabled()) { log.info("Connection check to previous node done: [liveAddr=" + liveAddr + ", previousNode=" + U.toShortString(previous) + ", connectingNodeId=" + nodeId + ']'); @@ -7283,28 +7287,39 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { for (int i = 0; i < addrsToCheck; ++i) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); + StringBuilder logMessageBuilder = new StringBuilder("Connection check to node: [addressToCheck=") + .append(addr) + .append(", result="); + try (Socket sock = new Socket()) { if (liveAddrHolder.get() == null) { sock.connect(addr, perAddrTimeout); liveAddrHolder.compareAndSet(null, addr); - if (log.isInfoEnabled()) { - log.info("Connection check to node: [addressToCheck=" + addr - + ", result=success, node=" + U.toShortString(node) + ']'); - } - } - else if (log.isInfoEnabled()) { - log.info("Connection check to node: [addressToCheck=" + addr - + ", result=skipped, node=" + U.toShortString(node) + ']'); + logMessageBuilder.append("success"); } + else + logMessageBuilder.append("skipped"); } catch (Exception ignored) { - log.info("Connection check to node: [addressToCheck=" + addr - + ", result=failed, cause=" + ignored.getMessage() + ", node=" - + U.toShortString(node) + ']'); + logMessageBuilder + .append("failed, cause=") + .append(ignored.getMessage()); } finally { + logMessageBuilder + .append(", node=") + .append(U.toShortString(node)) + .append(']'); + + String logMessage = logMessageBuilder.toString(); + + if(logMessage.contains("failed")) + U.warn(log, logMessage); + else + log.info(logMessage); + latch.countDown(); } } diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 53216ae5841d0..0c42de958c38e 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -17,33 +17,16 @@ package org.apache.ignite.spi.discovery.tcp; -import java.io.IOException; -import java.io.OutputStream; import java.net.InetSocketAddress; import java.net.Socket; import java.util.LinkedHashSet; -import java.util.UUID; -import java.util.concurrent.Callable; -import java.util.concurrent.CountDownLatch; -import org.apache.ignite.Ignite; -import org.apache.ignite.IgniteCheckedException; import org.apache.ignite.configuration.IgniteConfiguration; -import org.apache.ignite.events.DiscoveryEvent; -import org.apache.ignite.events.Event; -import org.apache.ignite.internal.IgniteEx; -import org.apache.ignite.internal.IgniteInternalFuture; -import org.apache.ignite.internal.util.typedef.internal.U; -import org.apache.ignite.lang.IgnitePredicate; import org.apache.ignite.spi.discovery.tcp.internal.TcpDiscoveryNode; -import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryAbstractMessage; -import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryNodeAddedMessage; -import org.apache.ignite.testframework.GridTestUtils; import org.apache.ignite.testframework.ListeningTestLogger; import org.apache.ignite.testframework.LogListener; import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; import org.junit.Test; -import static org.apache.ignite.events.EventType.EVT_NODE_FAILED; import static org.apache.ignite.testframework.GridTestUtils.waitForCondition; /** @@ -112,13 +95,26 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { * */ @Test public void testMultipleSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches(s -> - (s.contains("Connection check to node") && s.contains("result=success")) || - (s.contains("Connection check to node") && s.contains("result=skipped")) || - (s.contains("Connection check to node") && s.contains("result=failed"))) + LogListener lsnr0 = LogListener.matches(s -> + s.contains("Connection check to node") && s.contains("result=success")) .build(); - testLog.registerListener(lsnr); + LogListener lsnr1 = LogListener.matches(s -> + s.contains("Connection check to node") && s.contains("result=skipped")) + .build(); + + LogListener lsnr2 = LogListener.matches(s -> + s.contains("Connection check to node") && s.contains("result=failed")) + .build(); + + LogListener lsnr3 = LogListener.matches(s -> + s.contains("Connection check to previous node done")) + .build(); + + testLog.registerListener(lsnr0); + testLog.registerListener(lsnr1); + testLog.registerListener(lsnr2); + testLog.registerListener(lsnr3); try { startGrid(0); @@ -131,7 +127,10 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); - assertTrue(waitForCondition(lsnr::check, 10_000L)); + assertTrue(waitForCondition(lsnr0::check, 10_000L)); + assertTrue(waitForCondition(lsnr1::check, 10_000L)); + assertTrue(waitForCondition(lsnr2::check, 10_000L)); + assertTrue(waitForCondition(lsnr3::check, 10_000L)); } finally { stopAllGrids(); @@ -146,16 +145,24 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { * */ @Test public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches(s -> + LogListener lsnr0 = LogListener.matches(s -> (s.contains("Connection check to node") && s.contains("result=success"))) .build(); - testLog.registerListener(lsnr); + LogListener lsnr1 = LogListener.matches(s -> + s.contains("Connection check to previous node done")) + .build(); + + testLog.registerListener(lsnr0); + testLog.registerListener(lsnr1); try { startGridsMultiThreaded(3); + ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); - assertTrue(waitForCondition(lsnr::check, 10_000L)); + + assertTrue(waitForCondition(lsnr0::check, 10_000L)); + assertTrue(waitForCondition(lsnr1::check, 10_000L)); } finally { stopAllGrids(); @@ -170,133 +177,23 @@ public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws E * */ @Test public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { - LogListener lsnr = LogListener.matches(s -> - s.contains("Connection check to previous node done: [liveAddr=null") || - (s.contains("Connection check to node") && s.contains("result=failed"))) + LogListener lsnr0 = LogListener.matches(s -> + s.contains("Connection check to node") && s.contains("result=failed")) .build(); - testLog.registerListener(lsnr); - - try { - startGridsMultiThreaded(3); - ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); - - assertTrue(waitForCondition(lsnr::check, 10_000L)); - } - finally { - stopAllGrids(); - } - } - - /** - * Simulates coordinator's {@code NODE_FAILED} event - *

- * Coordinator's (node-0) {@code NODE_FAILED} event is forced on the second in line node in the ring (node-1). - * This event leads the cluster to fall apart into 2 parts: coordinator and others nodes. As the previously known - * coordinator node (node-0) is not accessible anymore, the log should contain 'Failed to connect the socket - * to the server', when trying to check the connection from node-1. - * @throws Exception If failed. - */ - @Test - public void testCheckSocketConnectionFailureLogMessage() throws Exception { - LogListener lsnr = LogListener.matches(s -> - s.contains("Connection check to previous node done: [liveAddr=null") || - (s.contains("Connection check to node") && s.contains("result=failed"))) + LogListener lsnr1 = LogListener.matches(s -> + s.contains("Connection check to previous node failed")) .build(); - testLog.registerListener(lsnr); + testLog.registerListener(lsnr0); + testLog.registerListener(lsnr1); try { - IgniteEx coord = (IgniteEx)startGridsMultiThreaded(3); - - UUID coordId = coord.localNode().id(); - - IgniteEx ignite1 = grid(1); - - CountDownLatch failedLatch = new CountDownLatch(2); - - IgnitePredicate failLsnr = evt -> { - assertEquals(EVT_NODE_FAILED, evt.type()); - - UUID nodeId = ((DiscoveryEvent)evt).eventNode().id(); - - if (coordId.equals(nodeId)) - failedLatch.countDown(); - - return true; - }; - - ignite1.events().localListen(failLsnr, EVT_NODE_FAILED); - - grid(2).events().localListen(failLsnr, EVT_NODE_FAILED); - - ignite1.configuration().getDiscoverySpi().failNode(coordId, null); - - assertTrue(waitForCondition(lsnr::check, 10_000L)); - } - finally { - stopAllGrids(); - } - } - - /** - * Emulates coordinator's {@code NODE_FAILED} event in {@link TcpDiscoveryNodeAddedMessage} while new node joins - * the cluster with following coordinator shutdown. - *

- * Coordinator's (node-0) {@code NODE_FAILED} event, happening on {@link TcpDiscoveryNodeAddedMessage} processing - * with following coordinator's shutdown, prompts the new node (node-2) to check previous node's addresses (node-1). - * As the previous node (node-1) is already established in new topology after the coordinator (node-0) shutdown, - * the log should contain 'Success connection to the server' message, which describes successful connection - * between new node (node-2) and previous surviving node (node-1). - * @throws Exception If failed. - */ - @Test - public void testCheckSocketConnectionSuccessLogMessage() throws Exception { - LogListener lsnr = LogListener.matches(s -> - (s.contains("Connection check to node") && s.contains("result=success"))) - .build(); - - testLog.registerListener(lsnr); - - try { - TestCustomEventLogSocketSpi spi0 = new TestCustomEventLogSocketSpi(); - - nodeSpi.set(spi0); - - final Ignite ignite0 = startGrid(0); - - TcpDiscoverySpi spi1 = new TcpDiscoverySpi(); - - nodeSpi.set(spi1); - - startGrid(1); - - CountDownLatch latch1 = new CountDownLatch(1); - CountDownLatch latch2 = new CountDownLatch(1); - - spi0.nodeAdded1 = latch1; - spi0.nodeAdded2 = latch2; - spi0.debug = true; - - IgniteInternalFuture fut1 = GridTestUtils.runAsync(new Callable() { - @Override public Void call() throws Exception { - startGrid(2); - - return null; - } - }); - - latch1.await(); - - spi0.stop = true; - - latch2.countDown(); - - ignite0.close(); - - fut1.get(); + startGridsMultiThreaded(3); + ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); - assertTrue(waitForCondition(lsnr::check, 10_000L)); + assertTrue(waitForCondition(lsnr0::check, 10_000L)); + assertTrue(waitForCondition(lsnr1::check, 10_000L)); } finally { stopAllGrids(); @@ -323,39 +220,4 @@ private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi return super.getEffectiveNodeAddresses(node); } } - - /** {@inheritDoc} */ - private static class TestCustomEventLogSocketSpi extends TcpDiscoverySpi { - /** */ - private volatile CountDownLatch nodeAdded1; - - /** */ - private volatile CountDownLatch nodeAdded2; - - /** */ - private volatile boolean stop; - - /** */ - private boolean debug; - - /** {@inheritDoc} */ - @Override protected void writeToSocket(Socket sock, OutputStream out, TcpDiscoveryAbstractMessage msg, - long timeout) throws IOException, IgniteCheckedException { - if (msg instanceof TcpDiscoveryNodeAddedMessage) { - if (nodeAdded1 != null) { - nodeAdded1.countDown(); - - if (debug) - log.info("--- Wait node added: " + msg); - - U.await(nodeAdded2); - - if (stop) - return; - } - } - - super.writeToSocket(sock, out, msg, timeout); - } - } } From e2274049a260374cd1cbc8c688b40a79145e3ead Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Mon, 6 May 2024 13:03:24 +0300 Subject: [PATCH 09/24] IGNITE-21830 * clean-up --- .../ignite/spi/discovery/tcp/ServerImpl.java | 2 +- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 18 ++++++++++-------- 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index e7faf6924c63f..4920b1dedc1ee 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7315,7 +7315,7 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { String logMessage = logMessageBuilder.toString(); - if(logMessage.contains("failed")) + if (logMessage.contains("failed")) U.warn(log, logMessage); else log.info(logMessage); diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 0c42de958c38e..7e31078f5663f 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -89,10 +89,10 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { *

* By manipulating the collection order we can check the failing, successful and ignored connection logs at once. * + * @throws Exception If failed. * @see TcpDiscoverySpi#getEffectiveNodeAddresses(TcpDiscoveryNode) * @see TestCustomEffectiveNodeAddressesSpi - * @throws Exception If failed. - * */ + */ @Test public void testMultipleSocketConnectionLogMessage() throws Exception { LogListener lsnr0 = LogListener.matches(s -> @@ -100,11 +100,11 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { .build(); LogListener lsnr1 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=skipped")) + s.contains("Connection check to node") && s.contains("result=skipped")) .build(); LogListener lsnr2 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=failed")) + s.contains("Connection check to node") && s.contains("result=failed")) .build(); LogListener lsnr3 = LogListener.matches(s -> @@ -140,9 +140,10 @@ public void testMultipleSocketConnectionLogMessage() throws Exception { /** * This test uses quiet closure of given {@link Socket} ignoring possible checked exception, which triggers * the previous node to check the connection to the following surviving one. - * @see TcpDiscoverySpi#brakeConnection() + * * @throws Exception If failed. - * */ + * @see TcpDiscoverySpi#brakeConnection() + */ @Test public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { LogListener lsnr0 = LogListener.matches(s -> @@ -172,9 +173,10 @@ public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws E /** * This test uses node failure by stopping service threads, which makes the node unresponsive and results in * failing connection to the server. - * @see TcpDiscoverySpi#simulateNodeFailure() + * * @throws Exception If failed. - * */ + * @see TcpDiscoverySpi#simulateNodeFailure() + */ @Test public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { LogListener lsnr0 = LogListener.matches(s -> From 1edc9a249d16c3e64aa607eced821f5fa464a9fe Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Tue, 7 May 2024 12:21:35 +0300 Subject: [PATCH 10/24] IGNITE-21830 * log refactor * tests clean-up --- .../ignite/spi/discovery/tcp/ServerImpl.java | 47 ++--- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 172 ++++++------------ 2 files changed, 74 insertions(+), 145 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 4920b1dedc1ee..56ec57750d3b1 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6782,15 +6782,14 @@ else if (req.changeTopology()) { liveAddr = checkConnection(previous, backwardCheckTimeout); - if (liveAddr == null) { - U.warn(log, "Connection check to previous node failed: [previousNode=" - + U.toShortString(previous) + ", connectingNodeId=" + nodeId + ']'); - } - else if (log.isInfoEnabled()) { - log.info("Connection check to previous node done: [liveAddr=" + liveAddr - + ", previousNode=" + U.toShortString(previous) + ", connectingNodeId=" - + nodeId + ']'); - } + String logMsg = "Connection check to previous node " + (liveAddr == null ? "failed" : "done") + + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(previous) + + ", aliveAddr=" + liveAddr + "]."; + + if (liveAddr == null) + U.warn(log, logMsg); + else if (log.isInfoEnabled()) + log.info(logMsg); } ok = liveAddr != null; @@ -7287,9 +7286,8 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { for (int i = 0; i < addrsToCheck; ++i) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); - StringBuilder logMessageBuilder = new StringBuilder("Connection check to node: [addressToCheck=") - .append(addr) - .append(", result="); + String logMsg = "Checking connection to node: [nodeId=" + node.id() + ", address=" + addr + ", result="; + String failReason = null; try (Socket sock = new Socket()) { if (liveAddrHolder.get() == null) { @@ -7297,28 +7295,19 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { liveAddrHolder.compareAndSet(null, addr); - logMessageBuilder.append("success"); + logMsg += "success]."; } else - logMessageBuilder.append("skipped"); + logMsg += "skipped, another alive address is already found]."; } - catch (Exception ignored) { - logMessageBuilder - .append("failed, cause=") - .append(ignored.getMessage()); + catch (Exception e) { + failReason = e.getMessage(); } finally { - logMessageBuilder - .append(", node=") - .append(U.toShortString(node)) - .append(']'); - - String logMessage = logMessageBuilder.toString(); - - if (logMessage.contains("failed")) - U.warn(log, logMessage); - else - log.info(logMessage); + if (failReason != null) + U.warn(log, logMsg + "failed, cause='" + failReason + "']."); + else if (log.isInfoEnabled()) + log.info(logMsg); latch.countDown(); } diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index 7e31078f5663f..eaeb0a874a224 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -18,7 +18,8 @@ package org.apache.ignite.spi.discovery.tcp; import java.net.InetSocketAddress; -import java.net.Socket; +import java.util.ArrayList; +import java.util.Collection; import java.util.LinkedHashSet; import org.apache.ignite.configuration.IgniteConfiguration; import org.apache.ignite.spi.discovery.tcp.internal.TcpDiscoveryNode; @@ -33,44 +34,11 @@ * Class for {@link TcpDiscoverySpi} logging tests. */ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { - /** - * Listener log messages - */ - private static ListeningTestLogger testLog; - - /** */ - private static final ThreadLocal nodeSpi = new ThreadLocal<>(); - - /** {@inheritDoc} */ - @Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception { - IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName); - - TcpDiscoverySpi spi = nodeSpi.get(); - - if (spi == null) - spi = new TcpDiscoverySpi(); - else - nodeSpi.set(null); - - cfg.setDiscoverySpi(spi); - - cfg.setGridLogger(testLog); - - return cfg; - } - - /** {@inheritDoc} */ - @Override protected void beforeTest() throws Exception { - super.beforeTest(); - - testLog = new ListeningTestLogger(log); - } - /** {@inheritDoc} */ @Override protected void afterTest() throws Exception { - testLog.clearListeners(); - super.afterTest(); + + stopAllGrids(); } /** @@ -95,111 +63,83 @@ public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { */ @Test public void testMultipleSocketConnectionLogMessage() throws Exception { - LogListener lsnr0 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=success")) - .build(); + ListeningTestLogger testLog = new ListeningTestLogger(log); - LogListener lsnr1 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=skipped")) - .build(); + String startLogMsg = "Checking connection to node"; - LogListener lsnr2 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=failed")) - .build(); + Collection lsnrs = new ArrayList<>(); - LogListener lsnr3 = LogListener.matches(s -> - s.contains("Connection check to previous node done")) - .build(); + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(2).build()); + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=failed").times(1).build()); + lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); - testLog.registerListener(lsnr0); - testLog.registerListener(lsnr1); - testLog.registerListener(lsnr2); - testLog.registerListener(lsnr3); + lsnrs.forEach(testLog::registerListener); - try { - startGrid(0); - startGrid(1); + TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); - TestCustomEffectiveNodeAddressesSpi spi = new TestCustomEffectiveNodeAddressesSpi(); - nodeSpi.set(spi); + startGrid(getTestConfigWithSpi(spi0, "ignite-0")); + startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1")); - startGrid(2); + IgniteConfiguration cfg = getTestConfigWithSpi(new TestCustomEffectiveNodeAddressesSpi(), "ignite-2"); + cfg.setGridLogger(testLog); + startGrid(cfg); - ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + spi0.brakeConnection(); - assertTrue(waitForCondition(lsnr0::check, 10_000L)); - assertTrue(waitForCondition(lsnr1::check, 10_000L)); - assertTrue(waitForCondition(lsnr2::check, 10_000L)); - assertTrue(waitForCondition(lsnr3::check, 10_000L)); - } - finally { - stopAllGrids(); - } + for (LogListener lsnr : lsnrs) + waitForCondition(lsnr::check, getTestTimeout()); + + testLog.clearListeners(); } /** - * This test uses quiet closure of given {@link Socket} ignoring possible checked exception, which triggers - * the previous node to check the connection to the following surviving one. + * This test uses node failure by stopping service threads, which makes the node unresponsive and results in + * failing connection to the server. * * @throws Exception If failed. - * @see TcpDiscoverySpi#brakeConnection() + * @see TcpDiscoverySpi#simulateNodeFailure() */ @Test - public void testCheckBrakeConnectionSuccessSocketConnectionLogMessage() throws Exception { - LogListener lsnr0 = LogListener.matches(s -> - (s.contains("Connection check to node") && s.contains("result=success"))) - .build(); + public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { + ListeningTestLogger testLog = new ListeningTestLogger(log); - LogListener lsnr1 = LogListener.matches(s -> - s.contains("Connection check to previous node done")) - .build(); + Collection lsnrs = new ArrayList<>(); - testLog.registerListener(lsnr0); - testLog.registerListener(lsnr1); + lsnrs.add(LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build()); + lsnrs.add(LogListener.matches("Connection check to previous node failed").times(1).build()); - try { - startGridsMultiThreaded(3); + lsnrs.forEach(testLog::registerListener); - ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).brakeConnection(); + TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); - assertTrue(waitForCondition(lsnr0::check, 10_000L)); - assertTrue(waitForCondition(lsnr1::check, 10_000L)); - } - finally { - stopAllGrids(); - } - } + startGrid(getTestConfigWithSpi(spi0, "ignite-0")); - /** - * This test uses node failure by stopping service threads, which makes the node unresponsive and results in - * failing connection to the server. - * - * @throws Exception If failed. - * @see TcpDiscoverySpi#simulateNodeFailure() - */ - @Test - public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { - LogListener lsnr0 = LogListener.matches(s -> - s.contains("Connection check to node") && s.contains("result=failed")) - .build(); + IgniteConfiguration cfg1 = getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1"); + cfg1.setGridLogger(testLog); - LogListener lsnr1 = LogListener.matches(s -> - s.contains("Connection check to previous node failed")) - .build(); + startGrid(cfg1); - testLog.registerListener(lsnr0); - testLog.registerListener(lsnr1); + startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-2")); - try { - startGridsMultiThreaded(3); - ((TcpDiscoverySpi)ignite(0).configuration().getDiscoverySpi()).simulateNodeFailure(); + spi0.simulateNodeFailure(); - assertTrue(waitForCondition(lsnr0::check, 10_000L)); - assertTrue(waitForCondition(lsnr1::check, 10_000L)); - } - finally { - stopAllGrids(); - } + for (LogListener lsnr : lsnrs) + waitForCondition(lsnr::check, getTestTimeout()); + + testLog.clearListeners(); + } + + + /** + * Returns default {@link IgniteConfiguration} with specified ignite instance name and {@link TcpDiscoverySpi}. + * @param spi {@link TcpDiscoverySpi} + * @param igniteInstanceName ignite instance name + * @return {@link IgniteConfiguration} + * @throws Exception If failed. + */ + private IgniteConfiguration getTestConfigWithSpi(TcpDiscoverySpi spi, String igniteInstanceName) throws Exception { + return getConfiguration(igniteInstanceName).setDiscoverySpi(spi); } /** {@inheritDoc} */ @@ -222,4 +162,4 @@ private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi return super.getEffectiveNodeAddresses(node); } } -} +} \ No newline at end of file From 1f895d296201052cf4bbd9f61604580145498b6d Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Tue, 7 May 2024 14:03:34 +0300 Subject: [PATCH 11/24] IGNITE-21830 * tests clean-up --- .../ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java index eaeb0a874a224..d9a3cf3e97620 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java @@ -130,7 +130,6 @@ public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { testLog.clearListeners(); } - /** * Returns default {@link IgniteConfiguration} with specified ignite instance name and {@link TcpDiscoverySpi}. * @param spi {@link TcpDiscoverySpi} @@ -162,4 +161,4 @@ private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi return super.getEffectiveNodeAddresses(node); } } -} \ No newline at end of file +} From 5854121040d1bf5de281c6687d06d4d2aaf6291e Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Tue, 7 May 2024 16:39:55 +0300 Subject: [PATCH 12/24] IGNITE-21830 * Redundant tests removed --- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 82 ++++++++- .../discovery/tcp/TcpDiscoverySpiLogTest.java | 164 ------------------ .../IgniteSpiDiscoverySelfTestSuite.java | 2 - 3 files changed, 79 insertions(+), 169 deletions(-) delete mode 100644 modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index e8b97f4ca629f..82e1fdabc2932 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -56,6 +56,8 @@ import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryHandshakeRequest; import org.apache.ignite.spi.discovery.tcp.messages.TcpDiscoveryHandshakeResponse; import org.apache.ignite.testframework.GridTestUtils; +import org.apache.ignite.testframework.ListeningTestLogger; +import org.apache.ignite.testframework.LogListener; import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; import org.junit.Test; @@ -109,6 +111,9 @@ public class TcpDiscoveryNetworkIssuesTest extends GridCommonAbstractTest { /** */ private TcpDiscoverySpi specialSpi; + /** */ + private ListeningTestLogger testLog; + /** */ private boolean usePortFromNodeName; @@ -153,6 +158,11 @@ public class TcpDiscoveryNetworkIssuesTest extends GridCommonAbstractTest { cfg.setLocalHost(localhost); + if (testLog != null) { + cfg.setGridLogger(testLog); + testLog = null; + } + return cfg; } @@ -234,7 +244,7 @@ public void testServerGetsSegmentedOnBecomeDangling() throws Exception { */ @Test public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exception { - doTestBackwardNodeCheckWithSameLoopback("127.0.0.1"); + doTestBackwardNodeCheckWithSameLoopback("127.0.0.1", null); } /** @@ -243,14 +253,31 @@ public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exc */ @Test public void testBackwardNodeCheckWithSameLoopbackSeveralLocalAddresses() throws Exception { - doTestBackwardNodeCheckWithSameLoopback("0.0.0.0"); + ListeningTestLogger testMethodLog = new ListeningTestLogger(log); + + String startLogMsg = "Checking connection to node"; + + Collection lsnrs = new ArrayList<>(); + + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(3).build()); + lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); + + lsnrs.forEach(testMethodLog::registerListener); + + doTestBackwardNodeCheckWithSameLoopback("0.0.0.0", testMethodLog); + + for (LogListener lsnr : lsnrs) + waitForCondition(lsnr::check, getTestTimeout()); + + testMethodLog.clearListeners(); } /** * Performs Tests backward node ping if {@link TcpDiscoveryNode#socketAddresses()} contains same loopback address as of local node. * Assumes several local address are resolved. */ - private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Exception { + private void doTestBackwardNodeCheckWithSameLoopback(String localhost, ListeningTestLogger testMethodLog) throws Exception { this.localhost = localhost; specialSpi = new TestDiscoverySpi(); @@ -262,6 +289,7 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Ex Ignite node1 = startGrid(1); specialSpi = new TestDiscoverySpi(); + testLog = testMethodLog; Ignite node2 = startGrid(2); @@ -383,6 +411,54 @@ private void simulateFailureOfTwoNodes(boolean sequentionally) throws Exception } } + /** + * This test uses node failure by stopping service threads, which makes the node unresponsive and results in + * failing connection to the server. + * + * @throws Exception If failed. + * @see TcpDiscoverySpi#simulateNodeFailure() + */ + @Test + public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { + ListeningTestLogger testLog = new ListeningTestLogger(log); + + Collection lsnrs = new ArrayList<>(); + + lsnrs.add(LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build()); + lsnrs.add(LogListener.matches("Connection check to previous node failed").times(1).build()); + + lsnrs.forEach(testLog::registerListener); + + TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); + + startGrid(getTestConfigWithSpi(spi0, "ignite-0")); + + IgniteConfiguration cfg1 = getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1"); + cfg1.setGridLogger(testLog); + + startGrid(cfg1); + + startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-2")); + + spi0.simulateNodeFailure(); + + for (LogListener lsnr : lsnrs) + waitForCondition(lsnr::check, getTestTimeout()); + + testLog.clearListeners(); + } + + /** + * Returns default {@link IgniteConfiguration} with specified ignite instance name and {@link TcpDiscoverySpi}. + * @param spi {@link TcpDiscoverySpi} + * @param igniteInstanceName ignite instance name + * @return {@link IgniteConfiguration} + * @throws Exception If failed. + */ + private IgniteConfiguration getTestConfigWithSpi(TcpDiscoverySpi spi, String igniteInstanceName) throws Exception { + return getConfiguration(igniteInstanceName).setDiscoverySpi(spi); + } + /** * @param ig Ignite instance to get failedNodes collection from. */ diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java deleted file mode 100644 index d9a3cf3e97620..0000000000000 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoverySpiLogTest.java +++ /dev/null @@ -1,164 +0,0 @@ -/* - * Licensed to the Apache Software Foundation (ASF) under one or more - * contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. - * The ASF licenses this file to You under the Apache License, Version 2.0 - * (the "License"); you may not use this file except in compliance with - * the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package org.apache.ignite.spi.discovery.tcp; - -import java.net.InetSocketAddress; -import java.util.ArrayList; -import java.util.Collection; -import java.util.LinkedHashSet; -import org.apache.ignite.configuration.IgniteConfiguration; -import org.apache.ignite.spi.discovery.tcp.internal.TcpDiscoveryNode; -import org.apache.ignite.testframework.ListeningTestLogger; -import org.apache.ignite.testframework.LogListener; -import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; -import org.junit.Test; - -import static org.apache.ignite.testframework.GridTestUtils.waitForCondition; - -/** - * Class for {@link TcpDiscoverySpi} logging tests. - */ -public class TcpDiscoverySpiLogTest extends GridCommonAbstractTest { - /** {@inheritDoc} */ - @Override protected void afterTest() throws Exception { - super.afterTest(); - - stopAllGrids(); - } - - /** - * This test checks all the possible logs from socket connection after coordinator quiet close. - *

- * There are 3 nodes used in the test. After the coordinator closure, the 3rd node will try to check the connection - * to the 2nd one. In other words the 3rd will try to connect to all effective addresses of the 2nd through socket, - * which can be accessed with 3's Discovery SPI. - *

- * For us to get multiple effective addresses for connection, we override - * {@link TcpDiscoverySpi#getEffectiveNodeAddresses(TcpDiscoveryNode)} method in - * {@link TestCustomEffectiveNodeAddressesSpi} to return custom collection of {@link InetSocketAddress}. - * We only need the custom collection once, when 3rd node is trying to probe the 2nd one. As the method is used in - * different other scenarios throughout the test, we restrain the method to deviate from expected behaviour only - * for the test case, that is when {@link TcpDiscoveryNode#discoveryPort()} is 47501. - *

- * By manipulating the collection order we can check the failing, successful and ignored connection logs at once. - * - * @throws Exception If failed. - * @see TcpDiscoverySpi#getEffectiveNodeAddresses(TcpDiscoveryNode) - * @see TestCustomEffectiveNodeAddressesSpi - */ - @Test - public void testMultipleSocketConnectionLogMessage() throws Exception { - ListeningTestLogger testLog = new ListeningTestLogger(log); - - String startLogMsg = "Checking connection to node"; - - Collection lsnrs = new ArrayList<>(); - - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(2).build()); - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=failed").times(1).build()); - lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); - - lsnrs.forEach(testLog::registerListener); - - TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); - - startGrid(getTestConfigWithSpi(spi0, "ignite-0")); - startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1")); - - IgniteConfiguration cfg = getTestConfigWithSpi(new TestCustomEffectiveNodeAddressesSpi(), "ignite-2"); - cfg.setGridLogger(testLog); - startGrid(cfg); - - spi0.brakeConnection(); - - for (LogListener lsnr : lsnrs) - waitForCondition(lsnr::check, getTestTimeout()); - - testLog.clearListeners(); - } - - /** - * This test uses node failure by stopping service threads, which makes the node unresponsive and results in - * failing connection to the server. - * - * @throws Exception If failed. - * @see TcpDiscoverySpi#simulateNodeFailure() - */ - @Test - public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { - ListeningTestLogger testLog = new ListeningTestLogger(log); - - Collection lsnrs = new ArrayList<>(); - - lsnrs.add(LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build()); - lsnrs.add(LogListener.matches("Connection check to previous node failed").times(1).build()); - - lsnrs.forEach(testLog::registerListener); - - TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); - - startGrid(getTestConfigWithSpi(spi0, "ignite-0")); - - IgniteConfiguration cfg1 = getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1"); - cfg1.setGridLogger(testLog); - - startGrid(cfg1); - - startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-2")); - - spi0.simulateNodeFailure(); - - for (LogListener lsnr : lsnrs) - waitForCondition(lsnr::check, getTestTimeout()); - - testLog.clearListeners(); - } - - /** - * Returns default {@link IgniteConfiguration} with specified ignite instance name and {@link TcpDiscoverySpi}. - * @param spi {@link TcpDiscoverySpi} - * @param igniteInstanceName ignite instance name - * @return {@link IgniteConfiguration} - * @throws Exception If failed. - */ - private IgniteConfiguration getTestConfigWithSpi(TcpDiscoverySpi spi, String igniteInstanceName) throws Exception { - return getConfiguration(igniteInstanceName).setDiscoverySpi(spi); - } - - /** {@inheritDoc} */ - private static class TestCustomEffectiveNodeAddressesSpi extends TcpDiscoverySpi { - /** {@inheritDoc} */ - private static final LinkedHashSet customAddrs = new LinkedHashSet<>(); - - static { - customAddrs.add(new InetSocketAddress("127.0.0.1", 47505)); - customAddrs.add(new InetSocketAddress("127.0.0.1", 47501)); - customAddrs.add(new InetSocketAddress("127.0.0.1", 47503)); - customAddrs.add(new InetSocketAddress("127.0.0.1", 47504)); - } - - /** {@inheritDoc} */ - @Override LinkedHashSet getEffectiveNodeAddresses(TcpDiscoveryNode node) { - if (node.discoveryPort() == 47501) - return customAddrs; - - return super.getEffectiveNodeAddresses(node); - } - } -} diff --git a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java index 4a3ce340cd2a7..1264c16124576 100644 --- a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java +++ b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteSpiDiscoverySelfTestSuite.java @@ -62,7 +62,6 @@ import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySnapshotHistoryTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiConfigSelfTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiFailureTimeoutSelfTest; -import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiLogTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiMBeanTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiReconnectDelayTest; import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiSelfTest; @@ -108,7 +107,6 @@ TcpDiscoverySpiMBeanTest.class, TcpDiscoverySpiStartStopSelfTest.class, TcpDiscoverySpiConfigSelfTest.class, - TcpDiscoverySpiLogTest.class, TcpDiscoveryMarshallerCheckSelfTest.class, TcpDiscoverySnapshotHistoryTest.class, TcpDiscoveryNodeJoinAndFailureTest.class, From 55bc441aa13d92b346742ab2aa0613e3a67fbb63 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Mon, 13 May 2024 14:46:11 +0300 Subject: [PATCH 13/24] IGNITE-21830 * Square brackets corrected * Tests refactored --- .../ignite/spi/discovery/tcp/ServerImpl.java | 8 ++-- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 37 ++++++++++--------- 2 files changed, 23 insertions(+), 22 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 56ec57750d3b1..da9dfb1a71323 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7286,7 +7286,7 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { for (int i = 0; i < addrsToCheck; ++i) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); - String logMsg = "Checking connection to node: [nodeId=" + node.id() + ", address=" + addr + ", result="; + String logMsg = "Checking connection to node [nodeId=" + node.id() + ", address=" + addr + "], result="; String failReason = null; try (Socket sock = new Socket()) { @@ -7295,17 +7295,17 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { liveAddrHolder.compareAndSet(null, addr); - logMsg += "success]."; + logMsg += "success."; } else - logMsg += "skipped, another alive address is already found]."; + logMsg += "skipped, cause='Another alive address is already found'."; } catch (Exception e) { failReason = e.getMessage(); } finally { if (failReason != null) - U.warn(log, logMsg + "failed, cause='" + failReason + "']."); + U.warn(log, logMsg + "failed, cause='" + failReason + "'."); else if (log.isInfoEnabled()) log.info(logMsg); diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 82e1fdabc2932..8da6f0504eaf5 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -34,6 +34,7 @@ import java.util.concurrent.atomic.AtomicReference; import java.util.function.BiConsumer; import java.util.function.Consumer; +import javax.annotation.Nullable; import org.apache.ignite.Ignite; import org.apache.ignite.IgniteCheckedException; import org.apache.ignite.configuration.IgniteConfiguration; @@ -158,10 +159,8 @@ public class TcpDiscoveryNetworkIssuesTest extends GridCommonAbstractTest { cfg.setLocalHost(localhost); - if (testLog != null) { + if (testLog != null) cfg.setGridLogger(testLog); - testLog = null; - } return cfg; } @@ -244,7 +243,7 @@ public void testServerGetsSegmentedOnBecomeDangling() throws Exception { */ @Test public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exception { - doTestBackwardNodeCheckWithSameLoopback("127.0.0.1", null); + doTestBackwardNodeCheckWithSameLoopback("127.0.0.1", false); } /** @@ -253,6 +252,14 @@ public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exc */ @Test public void testBackwardNodeCheckWithSameLoopbackSeveralLocalAddresses() throws Exception { + doTestBackwardNodeCheckWithSameLoopback("0.0.0.0", true); + } + + /** + * Performs Tests backward node ping if {@link TcpDiscoveryNode#socketAddresses()} contains same loopback address as of local node. + * Assumes several local address are resolved. + */ + private void doTestBackwardNodeCheckWithSameLoopback(String localhost, boolean withSkippedLogs) throws Exception { ListeningTestLogger testMethodLog = new ListeningTestLogger(log); String startLogMsg = "Checking connection to node"; @@ -260,24 +267,11 @@ public void testBackwardNodeCheckWithSameLoopbackSeveralLocalAddresses() throws Collection lsnrs = new ArrayList<>(); lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(3).build()); + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").atLeast(withSkippedLogs ? 1 : 0).build()); lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); lsnrs.forEach(testMethodLog::registerListener); - doTestBackwardNodeCheckWithSameLoopback("0.0.0.0", testMethodLog); - - for (LogListener lsnr : lsnrs) - waitForCondition(lsnr::check, getTestTimeout()); - - testMethodLog.clearListeners(); - } - - /** - * Performs Tests backward node ping if {@link TcpDiscoveryNode#socketAddresses()} contains same loopback address as of local node. - * Assumes several local address are resolved. - */ - private void doTestBackwardNodeCheckWithSameLoopback(String localhost, ListeningTestLogger testMethodLog) throws Exception { this.localhost = localhost; specialSpi = new TestDiscoverySpi(); @@ -293,6 +287,8 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost, Listening Ignite node2 = startGrid(2); + testLog = null; + CountDownLatch handshakeToNode2 = new CountDownLatch(1); // Listener of handshake request from node0 to node2. Activates simulation of same localhost address of node1 @@ -341,6 +337,11 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost, Listening // Node 1 must not be kicked. for (Ignite ig : G.allGrids()) assertEquals(3, ig.cluster().nodes().size()); + + for (LogListener lsnr : lsnrs) + waitForCondition(lsnr::check, getTestTimeout()); + + testMethodLog.clearListeners(); } /** From 4a026be9013034b22d4ff3f4b9b9fd2ec19de49d Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Mon, 13 May 2024 16:01:19 +0300 Subject: [PATCH 14/24] IGNITE-21830 * Square brackets corrected * Tests refactored --- .../ignite/spi/discovery/tcp/ServerImpl.java | 3 ++- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 17 ++++++++++------- 2 files changed, 12 insertions(+), 8 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index da9dfb1a71323..eafa735760e96 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7286,7 +7286,8 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { for (int i = 0; i < addrsToCheck; ++i) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); - String logMsg = "Checking connection to node [nodeId=" + node.id() + ", address=" + addr + "], result="; + String logMsg = "Checking connection to node [nodeId=" + node.id() + ", order=" + node.order() + + ", address=" + addr + "]: result="; String failReason = null; try (Socket sock = new Socket()) { diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 8da6f0504eaf5..9660e6604b56c 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -34,7 +34,6 @@ import java.util.concurrent.atomic.AtomicReference; import java.util.function.BiConsumer; import java.util.function.Consumer; -import javax.annotation.Nullable; import org.apache.ignite.Ignite; import org.apache.ignite.IgniteCheckedException; import org.apache.ignite.configuration.IgniteConfiguration; @@ -243,7 +242,7 @@ public void testServerGetsSegmentedOnBecomeDangling() throws Exception { */ @Test public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exception { - doTestBackwardNodeCheckWithSameLoopback("127.0.0.1", false); + doTestBackwardNodeCheckWithSameLoopback("127.0.0.1"); } /** @@ -252,14 +251,14 @@ public void testBackwardNodeCheckWithSameLoopbackSingleLocalAddress() throws Exc */ @Test public void testBackwardNodeCheckWithSameLoopbackSeveralLocalAddresses() throws Exception { - doTestBackwardNodeCheckWithSameLoopback("0.0.0.0", true); + doTestBackwardNodeCheckWithSameLoopback("0.0.0.0"); } /** * Performs Tests backward node ping if {@link TcpDiscoveryNode#socketAddresses()} contains same loopback address as of local node. * Assumes several local address are resolved. */ - private void doTestBackwardNodeCheckWithSameLoopback(String localhost, boolean withSkippedLogs) throws Exception { + private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Exception { ListeningTestLogger testMethodLog = new ListeningTestLogger(log); String startLogMsg = "Checking connection to node"; @@ -267,11 +266,8 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost, boolean w Collection lsnrs = new ArrayList<>(); lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").atLeast(withSkippedLogs ? 1 : 0).build()); lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); - lsnrs.forEach(testMethodLog::registerListener); - this.localhost = localhost; specialSpi = new TestDiscoverySpi(); @@ -285,6 +281,13 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost, boolean w specialSpi = new TestDiscoverySpi(); testLog = testMethodLog; + int effAddrsSizeNode0 = spi(node0).getEffectiveNodeAddresses((TcpDiscoveryNode)node1.cluster().localNode()).size(); + + if (effAddrsSizeNode0 > 1) + lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(effAddrsSizeNode0 - 1).build()); + + lsnrs.forEach(testMethodLog::registerListener); + Ignite node2 = startGrid(2); testLog = null; From 391508b8f93431097d962d061f687a1eb69f1cd9 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Tue, 14 May 2024 13:29:34 +0300 Subject: [PATCH 15/24] IGNITE-21830 * log corrected * tests refactored --- .../ignite/spi/discovery/tcp/ServerImpl.java | 2 +- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 52 ++++++++----------- 2 files changed, 22 insertions(+), 32 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index eafa735760e96..41173d8503445 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7287,7 +7287,7 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); String logMsg = "Checking connection to node [nodeId=" + node.id() + ", order=" + node.order() - + ", address=" + addr + "]: result="; + + ", address=" + addr + "], result="; String failReason = null; try (Socket sock = new Socket()) { diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 9660e6604b56c..7afa9fe671a23 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -343,8 +343,6 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Ex for (LogListener lsnr : lsnrs) waitForCondition(lsnr::check, getTestTimeout()); - - testMethodLog.clearListeners(); } /** @@ -417,50 +415,42 @@ private void simulateFailureOfTwoNodes(boolean sequentionally) throws Exception /** * This test uses node failure by stopping service threads, which makes the node unresponsive and results in - * failing connection to the server. + * failing connection to the server. Failures are simulated on the 1st node in the ring. In this case, + * the 2nd node in the ring will trigger 'Backward Connection Check', which should result in failing attempt of connection. + * This result is followed by the corresponding logs, indicating described failures. The test verifies the logs. * * @throws Exception If failed. - * @see TcpDiscoverySpi#simulateNodeFailure() */ @Test - public void testCheckNodeFailureSocketConnectionLogMessage() throws Exception { + public void testBackwardConnectionCheckFailedLogMessage() throws Exception { ListeningTestLogger testLog = new ListeningTestLogger(log); - Collection lsnrs = new ArrayList<>(); - - lsnrs.add(LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build()); - lsnrs.add(LogListener.matches("Connection check to previous node failed").times(1).build()); + LogListener lsnr0 = LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build(); + LogListener lsnr1 = LogListener.matches("Connection check to previous node failed").times(1).build(); - lsnrs.forEach(testLog::registerListener); + testLog.registerListener(lsnr0); + testLog.registerListener(lsnr1); - TcpDiscoverySpi spi0 = new TcpDiscoverySpi(); + startGrid(0); - startGrid(getTestConfigWithSpi(spi0, "ignite-0")); + IgniteConfiguration cfg = getConfiguration(getTestIgniteInstanceName(1)); + cfg.setGridLogger(testLog); - IgniteConfiguration cfg1 = getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-1"); - cfg1.setGridLogger(testLog); + startGrid(cfg); - startGrid(cfg1); + startGrid(2); - startGrid(getTestConfigWithSpi(new TcpDiscoverySpi(), "ignite-2")); + spi(grid(0)).simulateNodeFailure(); - spi0.simulateNodeFailure(); + waitForCondition(lsnr0::check, getTestTimeout()); + waitForCondition(lsnr1::check, getTestTimeout()); - for (LogListener lsnr : lsnrs) - waitForCondition(lsnr::check, getTestTimeout()); + for (int i = 1; i < 2; ++i) { + int finalI = i; + waitForCondition(() -> grid(finalI).cluster().nodes().size() == 2, getTestTimeout()); - testLog.clearListeners(); - } - - /** - * Returns default {@link IgniteConfiguration} with specified ignite instance name and {@link TcpDiscoverySpi}. - * @param spi {@link TcpDiscoverySpi} - * @param igniteInstanceName ignite instance name - * @return {@link IgniteConfiguration} - * @throws Exception If failed. - */ - private IgniteConfiguration getTestConfigWithSpi(TcpDiscoverySpi spi, String igniteInstanceName) throws Exception { - return getConfiguration(igniteInstanceName).setDiscoverySpi(spi); + assertTrue(F.viewReadOnly(grid(i).cluster().nodes(), n -> n, n -> n.order() == 1).isEmpty()); + } } /** From ba9866315b5deb4c2e959a0833755aaa677e5b9c Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Tue, 14 May 2024 15:54:27 +0300 Subject: [PATCH 16/24] IGNITE-21830 * tests refactored --- .../discovery/tcp/TcpDiscoveryNetworkIssuesTest.java | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 7afa9fe671a23..d339aa21cf384 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -22,6 +22,7 @@ import java.net.Socket; import java.net.SocketTimeoutException; import java.util.ArrayList; +import java.util.Arrays; import java.util.Collection; import java.util.Collections; import java.util.HashSet; @@ -281,7 +282,7 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Ex specialSpi = new TestDiscoverySpi(); testLog = testMethodLog; - int effAddrsSizeNode0 = spi(node0).getEffectiveNodeAddresses((TcpDiscoveryNode)node1.cluster().localNode()).size(); + int effAddrsSizeNode0 = spi(node0).getEffectiveNodeAddresses((TcpDiscoveryNode)node0.cluster().localNode()).size(); if (effAddrsSizeNode0 > 1) lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(effAddrsSizeNode0 - 1).build()); @@ -445,11 +446,10 @@ public void testBackwardConnectionCheckFailedLogMessage() throws Exception { waitForCondition(lsnr0::check, getTestTimeout()); waitForCondition(lsnr1::check, getTestTimeout()); - for (int i = 1; i < 2; ++i) { - int finalI = i; - waitForCondition(() -> grid(finalI).cluster().nodes().size() == 2, getTestTimeout()); + for (Ignite ig : Arrays.asList(grid(1), grid(2))) { + waitForCondition(() -> ig.cluster().nodes().size() == 2, getTestTimeout()); - assertTrue(F.viewReadOnly(grid(i).cluster().nodes(), n -> n, n -> n.order() == 1).isEmpty()); + assertTrue(F.viewReadOnly(ig.cluster().nodes(), n -> n, n -> n.order() == 1).isEmpty()); } } From 7d2cbbbb2011201faad3b5ed576555d0fbd6a81c Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 16 May 2024 12:15:15 +0300 Subject: [PATCH 17/24] IGNITE-21830 * tests refactored * redundant logs removed --- .../ignite/spi/discovery/tcp/ServerImpl.java | 16 ++--------- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 28 ------------------- 2 files changed, 2 insertions(+), 42 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 41173d8503445..51a608aa18ff9 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7286,30 +7286,18 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { for (int i = 0; i < addrsToCheck; ++i) { InetSocketAddress addr = addrs.get(addrIdx.getAndIncrement()); - String logMsg = "Checking connection to node [nodeId=" + node.id() + ", order=" + node.order() - + ", address=" + addr + "], result="; - String failReason = null; - try (Socket sock = new Socket()) { if (liveAddrHolder.get() == null) { sock.connect(addr, perAddrTimeout); liveAddrHolder.compareAndSet(null, addr); - - logMsg += "success."; } - else - logMsg += "skipped, cause='Another alive address is already found'."; } catch (Exception e) { - failReason = e.getMessage(); + U.warn(log, "Checking connection to node [nodeId=" + node.id() + ", order=" + node.order() + + ", address=" + addr + "], result=failed, cause='" + e.getMessage() + "'."); } finally { - if (failReason != null) - U.warn(log, logMsg + "failed, cause='" + failReason + "'."); - else if (log.isInfoEnabled()) - log.info(logMsg); - latch.countDown(); } } diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index d339aa21cf384..1ef777997933e 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -112,9 +112,6 @@ public class TcpDiscoveryNetworkIssuesTest extends GridCommonAbstractTest { /** */ private TcpDiscoverySpi specialSpi; - /** */ - private ListeningTestLogger testLog; - /** */ private boolean usePortFromNodeName; @@ -159,9 +156,6 @@ public class TcpDiscoveryNetworkIssuesTest extends GridCommonAbstractTest { cfg.setLocalHost(localhost); - if (testLog != null) - cfg.setGridLogger(testLog); - return cfg; } @@ -260,15 +254,6 @@ public void testBackwardNodeCheckWithSameLoopbackSeveralLocalAddresses() throws * Assumes several local address are resolved. */ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Exception { - ListeningTestLogger testMethodLog = new ListeningTestLogger(log); - - String startLogMsg = "Checking connection to node"; - - Collection lsnrs = new ArrayList<>(); - - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=success").times(1).build()); - lsnrs.add(LogListener.matches("Connection check to previous node done").times(1).build()); - this.localhost = localhost; specialSpi = new TestDiscoverySpi(); @@ -280,19 +265,9 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Ex Ignite node1 = startGrid(1); specialSpi = new TestDiscoverySpi(); - testLog = testMethodLog; - - int effAddrsSizeNode0 = spi(node0).getEffectiveNodeAddresses((TcpDiscoveryNode)node0.cluster().localNode()).size(); - - if (effAddrsSizeNode0 > 1) - lsnrs.add(LogListener.matches(startLogMsg).andMatches("result=skipped").times(effAddrsSizeNode0 - 1).build()); - - lsnrs.forEach(testMethodLog::registerListener); Ignite node2 = startGrid(2); - testLog = null; - CountDownLatch handshakeToNode2 = new CountDownLatch(1); // Listener of handshake request from node0 to node2. Activates simulation of same localhost address of node1 @@ -341,9 +316,6 @@ private void doTestBackwardNodeCheckWithSameLoopback(String localhost) throws Ex // Node 1 must not be kicked. for (Ignite ig : G.allGrids()) assertEquals(3, ig.cluster().nodes().size()); - - for (LogListener lsnr : lsnrs) - waitForCondition(lsnr::check, getTestTimeout()); } /** From a09cc3da0c8678f79588f27105f17b67dd045b01 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 16 May 2024 12:37:27 +0300 Subject: [PATCH 18/24] IGNITE-21830 * result log corrected --- .../java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 51a608aa18ff9..8669c8c0a0888 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6784,7 +6784,8 @@ else if (req.changeTopology()) { String logMsg = "Connection check to previous node " + (liveAddr == null ? "failed" : "done") + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(previous) - + ", aliveAddr=" + liveAddr + "]."; + + ", firstAliveAddr=" + liveAddr + ", addressesToCheck=" + + spi.getEffectiveNodeAddresses(previous) + "]."; if (liveAddr == null) U.warn(log, logMsg); From 9ee75ad6d303e4b0124757ab78b3f7bcd494a443 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 16 May 2024 13:17:04 +0300 Subject: [PATCH 19/24] IGNITE-21830 * Code style fix --- .../java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 8669c8c0a0888..f3ee64d5f5609 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6785,7 +6785,7 @@ else if (req.changeTopology()) { String logMsg = "Connection check to previous node " + (liveAddr == null ? "failed" : "done") + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(previous) + ", firstAliveAddr=" + liveAddr + ", addressesToCheck=" + - spi.getEffectiveNodeAddresses(previous) + "]."; + spi.getEffectiveNodeAddresses(previous) + "]."; if (liveAddr == null) U.warn(log, logMsg); From 4eedffcbbc9eb5c93a59a29ef9e0e8b674f419bf Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Thu, 16 May 2024 18:25:42 +0300 Subject: [PATCH 20/24] IGNITE-21830 * Log optimizations --- .../ignite/spi/discovery/tcp/ServerImpl.java | 19 +++++++++---------- 1 file changed, 9 insertions(+), 10 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index f3ee64d5f5609..3c1f9b7c6b548 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -6781,16 +6781,6 @@ else if (req.changeTopology()) { } liveAddr = checkConnection(previous, backwardCheckTimeout); - - String logMsg = "Connection check to previous node " + (liveAddr == null ? "failed" : "done") - + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(previous) - + ", firstAliveAddr=" + liveAddr + ", addressesToCheck=" + - spi.getEffectiveNodeAddresses(previous) + "]."; - - if (liveAddr == null) - U.warn(log, logMsg); - else if (log.isInfoEnabled()) - log.info(logMsg); } ok = liveAddr != null; @@ -7313,6 +7303,15 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { // No-op. } + String logMsg = "Connection check to previous node " + (liveAddrHolder.get() == null ? "failed" : "done") + + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(node) + + ", firstAliveAddr=" + liveAddrHolder.get() + ", addressesToCheck=" + addrs + "]."; + + if (liveAddrHolder.get() == null) + U.warn(log, logMsg); + else if (log.isInfoEnabled()) + log.info(logMsg); + return liveAddrHolder.get(); } From 6332536c510dcb3b1417ae229ef56cffed9b008c Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 17 May 2024 14:21:06 +0300 Subject: [PATCH 21/24] IGNITE-21830 * logs refactored --- .../ignite/spi/discovery/tcp/ServerImpl.java | 15 +++++++-------- .../tcp/TcpDiscoveryNetworkIssuesTest.java | 5 +---- 2 files changed, 8 insertions(+), 12 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 3c1f9b7c6b548..8d115bae8e8ed 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7285,8 +7285,8 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { } } catch (Exception e) { - U.warn(log, "Checking connection to node [nodeId=" + node.id() + ", order=" + node.order() - + ", address=" + addr + "], result=failed, cause='" + e.getMessage() + "'."); + U.warn(log, "Failed to check connection to previous node [nodeId=" + node.id() + ", order=" + + node.order() + ", address=" + addr + "].", e); } finally { latch.countDown(); @@ -7303,14 +7303,13 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { // No-op. } - String logMsg = "Connection check to previous node " + (liveAddrHolder.get() == null ? "failed" : "done") - + ". ConnectingNodeId=" + nodeId + ". PreviousNode=" + U.toShortString(node) - + ", firstAliveAddr=" + liveAddrHolder.get() + ", addressesToCheck=" + addrs + "]."; - if (liveAddrHolder.get() == null) - U.warn(log, logMsg); + U.warn(log, "Failed to check connection to previous node [connectingNodeId=" + nodeId + + ", previousNode=" + U.toShortString(node) + ", previousNodeKnownAddresses=" + addrs + "]."); else if (log.isInfoEnabled()) - log.info(logMsg); + log.info("Connection check to previous node done [connectingNodeId=" + nodeId + ", previousNode=" + + U.toShortString(node) + ", firstRespondedAddress=" + liveAddrHolder.get() + + ", previousNodeKnownAddresses=" + addrs + "]."); return liveAddrHolder.get(); } diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 1ef777997933e..874a587c8e6f6 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -398,11 +398,9 @@ private void simulateFailureOfTwoNodes(boolean sequentionally) throws Exception public void testBackwardConnectionCheckFailedLogMessage() throws Exception { ListeningTestLogger testLog = new ListeningTestLogger(log); - LogListener lsnr0 = LogListener.matches("Checking connection to node").andMatches("result=failed").times(1).build(); - LogListener lsnr1 = LogListener.matches("Connection check to previous node failed").times(1).build(); + LogListener lsnr0 = LogListener.matches("Failed to check connection to previous node").times(2).build(); testLog.registerListener(lsnr0); - testLog.registerListener(lsnr1); startGrid(0); @@ -416,7 +414,6 @@ public void testBackwardConnectionCheckFailedLogMessage() throws Exception { spi(grid(0)).simulateNodeFailure(); waitForCondition(lsnr0::check, getTestTimeout()); - waitForCondition(lsnr1::check, getTestTimeout()); for (Ignite ig : Arrays.asList(grid(1), grid(2))) { waitForCondition(() -> ig.cluster().nodes().size() == 2, getTestTimeout()); From 662d61eb74716666fc1a6d285e96dadbcd1e7388 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 17 May 2024 14:34:12 +0300 Subject: [PATCH 22/24] IGNITE-21830 * clean-up --- .../org/apache/ignite/spi/discovery/tcp/ServerImpl.java | 6 +++--- .../spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 8d115bae8e8ed..6ead6309fc3b6 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7286,7 +7286,7 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { } catch (Exception e) { U.warn(log, "Failed to check connection to previous node [nodeId=" + node.id() + ", order=" - + node.order() + ", address=" + addr + "].", e); + + node.order() + ", address=" + addr + ']', e); } finally { latch.countDown(); @@ -7305,11 +7305,11 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { if (liveAddrHolder.get() == null) U.warn(log, "Failed to check connection to previous node [connectingNodeId=" + nodeId - + ", previousNode=" + U.toShortString(node) + ", previousNodeKnownAddresses=" + addrs + "]."); + + ", previousNode=" + U.toShortString(node) + ", previousNodeKnownAddresses=" + addrs + ']'); else if (log.isInfoEnabled()) log.info("Connection check to previous node done [connectingNodeId=" + nodeId + ", previousNode=" + U.toShortString(node) + ", firstRespondedAddress=" + liveAddrHolder.get() + - ", previousNodeKnownAddresses=" + addrs + "]."); + ", previousNodeKnownAddresses=" + addrs + ']'); return liveAddrHolder.get(); } diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 874a587c8e6f6..7b7391eaa5f61 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -413,7 +413,7 @@ public void testBackwardConnectionCheckFailedLogMessage() throws Exception { spi(grid(0)).simulateNodeFailure(); - waitForCondition(lsnr0::check, getTestTimeout()); + assertTrue(lsnr0.check(getTestTimeout())); for (Ignite ig : Arrays.asList(grid(1), grid(2))) { waitForCondition(() -> ig.cluster().nodes().size() == 2, getTestTimeout()); From 19a94f5304048b008e4effd3bb3eaf038c7e4c89 Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 17 May 2024 14:38:42 +0300 Subject: [PATCH 23/24] IGNITE-21830 * test refactored --- .../ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java index 7b7391eaa5f61..12b655b3ec2f3 100644 --- a/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java +++ b/modules/core/src/test/java/org/apache/ignite/spi/discovery/tcp/TcpDiscoveryNetworkIssuesTest.java @@ -418,7 +418,7 @@ public void testBackwardConnectionCheckFailedLogMessage() throws Exception { for (Ignite ig : Arrays.asList(grid(1), grid(2))) { waitForCondition(() -> ig.cluster().nodes().size() == 2, getTestTimeout()); - assertTrue(F.viewReadOnly(ig.cluster().nodes(), n -> n, n -> n.order() == 1).isEmpty()); + assertTrue(ig.cluster().nodes().stream().noneMatch(node -> node.order() == 1)); } } From ad066322d2f16e66768234ee2edf7704a8c7c9ff Mon Sep 17 00:00:00 2001 From: Maksim Davydov Date: Fri, 17 May 2024 15:37:00 +0300 Subject: [PATCH 24/24] IGNITE-21830 * Code style fix --- .../org/apache/ignite/spi/discovery/tcp/ServerImpl.java | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java index 6ead6309fc3b6..0ba98ae709756 100644 --- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java +++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.java @@ -7303,13 +7303,15 @@ private InetSocketAddress checkConnection(TcpDiscoveryNode node, int timeout) { // No-op. } - if (liveAddrHolder.get() == null) + if (liveAddrHolder.get() == null) { U.warn(log, "Failed to check connection to previous node [connectingNodeId=" + nodeId + ", previousNode=" + U.toShortString(node) + ", previousNodeKnownAddresses=" + addrs + ']'); - else if (log.isInfoEnabled()) + } + else if (log.isInfoEnabled()) { log.info("Connection check to previous node done [connectingNodeId=" + nodeId + ", previousNode=" + U.toShortString(node) + ", firstRespondedAddress=" + liveAddrHolder.get() + ", previousNodeKnownAddresses=" + addrs + ']'); + } return liveAddrHolder.get(); }