You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by sk...@apache.org on 2021/04/15 11:23:38 UTC
[ignite] branch master updated: IGNITE-13818 Add extended logging
topology for node left/join a grid. Fixes #8559
This is an automated email from the ASF dual-hosted git repository.
sk0x50 pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/ignite.git
The following commit(s) were added to refs/heads/master by this push:
new 3baeac8 IGNITE-13818 Add extended logging topology for node left/join a grid. Fixes #8559
3baeac8 is described below
commit 3baeac815d77346a89df23d1f16b84eb4512e57b
Author: makedonskaya <m....@gmail.com>
AuthorDate: Thu Apr 15 14:16:20 2021 +0300
IGNITE-13818 Add extended logging topology for node left/join a grid. Fixes #8559
Signed-off-by: Slava Koptilin <sl...@gmail.com>
---
.../managers/discovery/GridDiscoveryManager.java | 78 ++++++--
.../IgniteTopologyPrintFormatSelfTest.java | 212 +++++++++++++--------
2 files changed, 197 insertions(+), 93 deletions(-)
diff --git a/modules/core/src/main/java/org/apache/ignite/internal/managers/discovery/GridDiscoveryManager.java b/modules/core/src/main/java/org/apache/ignite/internal/managers/discovery/GridDiscoveryManager.java
index b992f7b..39b4c5a 100644
--- a/modules/core/src/main/java/org/apache/ignite/internal/managers/discovery/GridDiscoveryManager.java
+++ b/modules/core/src/main/java/org/apache/ignite/internal/managers/discovery/GridDiscoveryManager.java
@@ -104,6 +104,7 @@ import org.apache.ignite.internal.util.typedef.X;
import org.apache.ignite.internal.util.typedef.internal.CU;
import org.apache.ignite.internal.util.typedef.internal.LT;
import org.apache.ignite.internal.util.typedef.internal.S;
+import org.apache.ignite.internal.util.typedef.internal.SB;
import org.apache.ignite.internal.util.typedef.internal.U;
import org.apache.ignite.internal.util.worker.GridWorker;
import org.apache.ignite.lang.IgniteClosure;
@@ -1429,7 +1430,7 @@ public class GridDiscoveryManager extends GridManagerAdapter<DiscoverySpi> {
return null;
}
- }, topVer, discoCache, evtType, evtNode, srvNodes.size(), clientNodes.size(), totalCpus, heap, offheap);
+ }, topVer, discoCache, evtType, evtNode, srvNodes.size(), clientNodes.size(), totalCpus, heap, offheap, false);
if (log.isDebugEnabled()) {
String dbg = "";
@@ -1480,7 +1481,7 @@ public class GridDiscoveryManager extends GridManagerAdapter<DiscoverySpi> {
return null;
}
- }, topVer, discoCache, evtType, evtNode, srvNodes.size(), clientNodes.size(), totalCpus, heap, offheap);
+ }, topVer, discoCache, evtType, evtNode, srvNodes.size(), clientNodes.size(), totalCpus, heap, offheap, true);
}
/**
@@ -1546,23 +1547,54 @@ public class GridDiscoveryManager extends GridManagerAdapter<DiscoverySpi> {
* @param totalCpus Total cpu number.
* @param heap Heap size.
* @param offheap Offheap size.
- */
- private void topologySnapshotMessage(IgniteClosure<String, Void> clo, long topVer, DiscoCache discoCache,
- int evtType, ClusterNode evtNode, int srvNodesNum, int clientNodesNum, int totalCpus, double heap,
- double offheap) {
+ * @param needNodesDetails Flag for additional alive nodes logging.
+ */
+ private void topologySnapshotMessage(
+ IgniteClosure<String, Void> clo,
+ long topVer,
+ DiscoCache discoCache,
+ int evtType,
+ ClusterNode evtNode,
+ int srvNodesNum,
+ int clientNodesNum,
+ int totalCpus,
+ double heap,
+ double offheap,
+ boolean needNodesDetails
+ ) {
DiscoveryDataClusterState state = discoCache.state();
- String summary = PREFIX + " [" +
- (discoOrdered ? "ver=" + topVer + ", " : "") +
- "locNode=" + U.id8(discoCache.localNode().id()) +
- ", servers=" + srvNodesNum +
- ", clients=" + clientNodesNum +
- ", state=" + (state.active() ? "ACTIVE" : "INACTIVE") +
- ", CPUs=" + totalCpus +
- ", offheap=" + offheap + "GB" +
- ", heap=" + heap + "GB]";
+ SB summary = new SB(PREFIX);
+
+ summary.a(" [");
+ summary.a(discoOrdered ? "ver=" + topVer + ", " : "");
+ summary.a("locNode=").a(U.id8(discoCache.localNode().id()));
+ summary.a(", servers=").a(srvNodesNum);
+ summary.a(", clients=").a(clientNodesNum);
+ summary.a(", state=").a(state.active() ? "ACTIVE" : "INACTIVE");
+ summary.a(", CPUs=").a(totalCpus);
+ summary.a(", offheap=").a(offheap).a("GB");
+ summary.a(", heap=").a(heap).a("GB");
+
+ if ((evtType == EVT_NODE_JOINED
+ || evtType == EVT_NODE_LEFT
+ || evtType == EVT_NODE_FAILED)
+ && needNodesDetails) {
+ summary.a(", aliveNodes=[");
+
+ for (ClusterNode clusterNode : discoCache.allNodes()) {
+ if (discoCache.alive(clusterNode.id()))
+ summary.a(nodeDescription(clusterNode)).a(", ");
+ }
+
+ summary.setLength(summary.length() - 2);
+
+ summary.a(']');
+ }
+
+ summary.a(']');
- clo.apply(summary);
+ clo.apply(summary.toString());
ClusterNode currCrd = discoCache.oldestServerNode();
@@ -1606,6 +1638,20 @@ public class GridDiscoveryManager extends GridManagerAdapter<DiscoverySpi> {
}
}
+ /**
+ * Provides text descrition of a cluster node.
+ *
+ * @param node Node.
+ */
+ private static String nodeDescription(ClusterNode node) {
+ return new SB(node.getClass().getSimpleName())
+ .a(" [id=").a(node.id())
+ .a(", consistentId=").a(node.consistentId())
+ .a(", isClient=").a(node.isClient())
+ .a(", ver=").a(node.version()).a(']')
+ .toString();
+ }
+
/** {@inheritDoc} */
@Override public void onKernalStop0(boolean cancel) {
startLatch.countDown();
diff --git a/modules/core/src/test/java/org/apache/ignite/internal/managers/discovery/IgniteTopologyPrintFormatSelfTest.java b/modules/core/src/test/java/org/apache/ignite/internal/managers/discovery/IgniteTopologyPrintFormatSelfTest.java
index 7aeeea5..ca2dd80 100644
--- a/modules/core/src/test/java/org/apache/ignite/internal/managers/discovery/IgniteTopologyPrintFormatSelfTest.java
+++ b/modules/core/src/test/java/org/apache/ignite/internal/managers/discovery/IgniteTopologyPrintFormatSelfTest.java
@@ -19,15 +19,16 @@ package org.apache.ignite.internal.managers.discovery;
import java.util.ArrayList;
import java.util.List;
+import java.util.regex.Pattern;
import org.apache.ignite.Ignite;
import org.apache.ignite.configuration.IgniteConfiguration;
import org.apache.ignite.internal.IgniteKernal;
import org.apache.ignite.internal.managers.GridManagerAdapter;
-import org.apache.ignite.internal.util.typedef.F;
import org.apache.ignite.internal.util.typedef.internal.U;
-import org.apache.ignite.lang.IgnitePredicate;
import org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi;
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.apache.ignite.testframework.junits.logger.GridTestLog4jLogger;
import org.apache.log4j.Level;
@@ -38,20 +39,29 @@ import org.junit.Test;
*/
public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
/** */
- public static final String TOPOLOGY_SNAPSHOT = "Topology snapshot";
+ private static final String ALIVE_NODES_MSG = ".*aliveNodes=\\[(TcpDiscoveryNode " +
+ "\\[id=[0-9a-fA-F]{8}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{12}," +
+ " consistentId=.*, isClient=(false|true), ver=.*](, )?){%s,%s}]]";
/** */
- public static final String SERV_NODE = ">>> Number of server nodes";
+ private static final String NUMBER_SRV_NODES = ">>> Number of server nodes: %d";
/** */
- public static final String CLIENT_NODE = ">>> Number of client nodes";
+ private static final String CLIENT_NODES_COUNT = ">>> Number of client nodes: %d";
+
+ /** */
+ private static final String TOPOLOGY_MSG = "Topology snapshot [ver=%d, locNode=%s, servers=%d, clients=%d,";
+
+ /** */
+ private ListeningTestLogger testLog = new ListeningTestLogger(log);
/** */
public static final String COORDINATOR_CHANGED = "Coordinator changed";
/** {@inheritDoc} */
@Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception {
- IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName);
+ IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName)
+ .setGridLogger(testLog);
if (igniteInstanceName.endsWith("client_force_server"))
((TcpDiscoverySpi)cfg.getDiscoverySpi()).setForceServerMode(true);
@@ -61,6 +71,8 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
/** {@inheritDoc} */
@Override protected void beforeTest() throws Exception {
+ super.beforeTest();
+
stopAllGrids();
}
@@ -68,142 +80,161 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
@Override protected void afterTest() throws Exception {
stopAllGrids();
- if (log instanceof MockLogger)
- ((MockLogger)log).clear();
+ super.afterTest();
}
/**
+ * Checks topology snapshot message with two server nodes in INFO log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testServerLogs() throws Exception {
- MockLogger log = new MockLogger();
+ ((GridTestLog4jLogger)log).setLevel(Level.INFO);
- log.setLevel(Level.INFO);
-
- doServerLogTest(log);
+ doServerLogTest();
}
/**
+ * Checks topology snapshot message with two server nodes in DEBUG log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testServerDebugLogs() throws Exception {
- MockLogger log = new MockLogger();
+ ((GridTestLog4jLogger)log).setLevel(Level.DEBUG);
- log.setLevel(Level.DEBUG);
-
- doServerLogTest(log);
+ doServerLogTest();
}
/**
- * @param log Logger.
* @throws Exception If failed.
*/
- private void doServerLogTest(MockLogger log) throws Exception {
+ private void doServerLogTest() throws Exception {
String nodeId8;
+ testLog = new ListeningTestLogger(log);
+
+ Pattern ptrn = Pattern.compile(String.format(ALIVE_NODES_MSG, 1, 2));
+
+ LogListener aliveNodesLsnr = LogListener.matches(ptrn).times(log.isDebugEnabled() ? 0 : 4).build();
+
+ testLog.registerListener(aliveNodesLsnr);
+
+ LogListener lsnr;
+ LogListener lsnr2;
+
try {
- Ignite server = startGrid("server");
+ Ignite srv = startGrid("server");
+
+ nodeId8 = U.id8(srv.cluster().localNode().id());
- nodeId8 = U.id8(server.cluster().localNode().id());
+ lsnr = LogListener.matches(String.format(TOPOLOGY_MSG, 2, nodeId8, 2, 0)).build();
- setLogger(log, server);
+ lsnr2 = LogListener.matches(s -> s.contains(String.format(NUMBER_SRV_NODES, 2))
+ && s.contains(String.format(CLIENT_NODES_COUNT, 0))).build();
- Ignite server1 = startGrid("server1");
+ testLog.registerAllListeners(lsnr, lsnr2);
- waitForDiscovery(server, server1);
+ Ignite srv1 = startGrid("server1");
+
+ waitForDiscovery(srv, srv1);
}
finally {
stopAllGrids();
}
- assertTrue(F.forAny(log.logs(), new IgnitePredicate<String>() {
- @Override public boolean apply(String s) {
- return s.contains("Topology snapshot [ver=2, locNode=" + nodeId8 + ", servers=2, clients=0,")
- || (s.contains(">>> Number of server nodes: 2") && s.contains(">>> Number of client nodes: 0"));
- }
- }));
+ checkLogMessages(aliveNodesLsnr, lsnr, lsnr2);
}
/**
+ * Checks topology snapshot message with server and client nodes in INFO log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testServerAndClientLogs() throws Exception {
- MockLogger log = new MockLogger();
+ ((GridTestLog4jLogger)log).setLevel(Level.INFO);
- log.setLevel(Level.INFO);
-
- doServerAndClientTest(log);
+ doServerAndClientTest();
}
/**
+ * Checks topology snapshot message with server and client nodes in DEBUG log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testServerAndClientDebugLogs() throws Exception {
- MockLogger log = new MockLogger();
+ ((GridTestLog4jLogger)log).setLevel(Level.DEBUG);
- log.setLevel(Level.DEBUG);
-
- doServerAndClientTest(log);
+ doServerAndClientTest();
}
/**
- * @param log Log.
* @throws Exception If failed.
*/
- private void doServerAndClientTest(MockLogger log) throws Exception {
+ private void doServerAndClientTest() throws Exception {
String nodeId8;
+ testLog = new ListeningTestLogger(log);
+
+ Pattern ptrn = Pattern.compile(String.format(ALIVE_NODES_MSG, 1, 4));
+
+ LogListener aliveNodesLsnr = LogListener.matches(ptrn).times(log.isDebugEnabled() ? 0 : 16).build();
+
+ testLog.registerListener(aliveNodesLsnr);
+
+ LogListener lsnr;
+ LogListener lsnr2;
+
try {
- Ignite server = startGrid("server");
+ Ignite srv = startGrid("server");
- nodeId8 = U.id8(server.cluster().localNode().id());
+ nodeId8 = U.id8(srv.cluster().localNode().id());
- setLogger(log, server);
+ lsnr = LogListener.matches(String.format(TOPOLOGY_MSG, 4, nodeId8, 2, 2)).build();
- Ignite server1 = startGrid("server1");
+ lsnr2 = LogListener.matches(s -> s.contains(String.format(NUMBER_SRV_NODES, 2))
+ && s.contains(String.format(CLIENT_NODES_COUNT, 2))).build();
+
+ testLog.registerAllListeners(lsnr, lsnr2);
+
+ Ignite srv1 = startGrid("server1");
Ignite client1 = startClientGrid("first client");
Ignite client2 = startClientGrid("second client");
- waitForDiscovery(server, server1, client1, client2);
+ waitForDiscovery(srv, srv1, client1, client2);
}
finally {
stopAllGrids();
}
- assertTrue(F.forAny(log.logs(), new IgnitePredicate<String>() {
- @Override public boolean apply(String s) {
- return s.contains("Topology snapshot [ver=4, locNode=" + nodeId8 + ", servers=2, clients=2,")
- || (s.contains(">>> Number of server nodes: 2") && s.contains(">>> Number of client nodes: 2"));
- }
- }));
+ checkLogMessages(aliveNodesLsnr, lsnr, lsnr2);
}
/**
+ * Checks topology snapshot message with server, client and force client nodes in INFO log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testForceServerAndClientLogs() throws Exception {
- MockLogger log = new MockLogger();
-
- log.setLevel(Level.INFO);
+ ((GridTestLog4jLogger)log).setLevel(Level.INFO);
- doForceServerAndClientTest(log);
+ doForceServerAndClientTest();
}
/**
+ * Checks topology snapshot message with server, client and force client nodes in DEBUG log level.
+ *
* @throws Exception If failed.
*/
@Test
public void testForceServerAndClientDebugLogs() throws Exception {
- MockLogger log = new MockLogger();
-
- log.setLevel(Level.DEBUG);
+ ((GridTestLog4jLogger)log).setLevel(Level.DEBUG);
- doForceServerAndClientTest(log);
+ doForceServerAndClientTest();
}
@Test
@@ -228,36 +259,46 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
}
/**
- * @param log Log.
* @throws Exception If failed.
*/
- private void doForceServerAndClientTest(MockLogger log) throws Exception {
+ private void doForceServerAndClientTest() throws Exception {
String nodeId8;
+ testLog = new ListeningTestLogger(log);
+
+ Pattern ptrn = Pattern.compile(String.format(ALIVE_NODES_MSG, 1, 4));
+
+ LogListener aliveNodesLsnr = LogListener.matches(ptrn).times(log.isDebugEnabled() ? 0 : 25).build();
+
+ testLog.registerListener(aliveNodesLsnr);
+
+ LogListener lsnr;
+ LogListener lsnr2;
+
try {
- Ignite server = startGrid("server");
+ Ignite srv = startGrid("server");
+
+ nodeId8 = U.id8(srv.cluster().localNode().id());
+
+ lsnr = LogListener.matches(String.format(TOPOLOGY_MSG, 5, nodeId8, 2, 3)).build();
- nodeId8 = U.id8(server.cluster().localNode().id());
+ lsnr2 = LogListener.matches(s -> s.contains(String.format(NUMBER_SRV_NODES, 2))
+ && s.contains(String.format(CLIENT_NODES_COUNT, 3))).build();
- setLogger(log, server);
+ testLog.registerAllListeners(lsnr, lsnr2);
- Ignite server1 = startGrid("server1");
+ Ignite srv1 = startGrid("server1");
Ignite client1 = startClientGrid("first client");
Ignite client2 = startClientGrid("second client");
Ignite forceServClnt3 = startClientGrid("third client_force_server");
- waitForDiscovery(server, server1, client1, client2, forceServClnt3);
+ waitForDiscovery(srv, srv1, client1, client2, forceServClnt3);
}
finally {
stopAllGrids();
}
- assertTrue(F.forAny(log.logs(), new IgnitePredicate<String>() {
- @Override public boolean apply(String s) {
- return s.contains("Topology snapshot [ver=5, locNode=" + nodeId8 + ", servers=2, clients=3,")
- || (s.contains(">>> Number of server nodes: 2") && s.contains(">>> Number of client nodes: 3"));
- }
- }));
+ checkLogMessages(aliveNodesLsnr, lsnr, lsnr2);
}
/**
@@ -275,6 +316,23 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
}
/**
+ * Check nodes details in log.
+ *
+ * @param aliveNodesLsnr log listener.
+ */
+ private void checkLogMessages(LogListener aliveNodesLsnr, LogListener lsnr, LogListener lsnr2) {
+ if (testLog.isDebugEnabled()) {
+ assertTrue(aliveNodesLsnr.check());
+ assertFalse(lsnr.check());
+ assertTrue(lsnr2.check());
+ } else {
+ assertTrue(aliveNodesLsnr.check());
+ assertTrue(lsnr.check());
+ assertFalse(lsnr2.check());
+ }
+ }
+
+ /**
*
*/
private static class MockLogger extends GridTestLog4jLogger {
@@ -284,9 +342,9 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
/** {@inheritDoc} */
@Override public void debug(String msg) {
if ((msg != null && !msg.isEmpty()) && (
- msg.contains(TOPOLOGY_SNAPSHOT)
- || msg.contains(SERV_NODE)
- || msg.contains(CLIENT_NODE)))
+ msg.contains(TOPOLOGY_MSG)
+ || msg.contains(NUMBER_SRV_NODES)
+ || msg.contains(CLIENT_NODES_COUNT)))
logs.add(msg);
super.debug(msg);
@@ -295,9 +353,9 @@ public class IgniteTopologyPrintFormatSelfTest extends GridCommonAbstractTest {
/** {@inheritDoc} */
@Override public void info(String msg) {
if ((msg != null && !msg.isEmpty()) && (
- msg.contains(TOPOLOGY_SNAPSHOT)
- || msg.contains(SERV_NODE)
- || msg.contains(CLIENT_NODE))
+ msg.contains(TOPOLOGY_MSG)
+ || msg.contains(NUMBER_SRV_NODES)
+ || msg.contains(CLIENT_NODES_COUNT))
|| msg.contains(COORDINATOR_CHANGED))
logs.add(msg);