You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ignite.apache.org by sb...@apache.org on 2017/07/20 09:13:18 UTC
ignite git commit: debug
Repository: ignite
Updated Branches:
refs/heads/ignite-5569-debug [created] b8fee2ad9
debug
Project: http://git-wip-us.apache.org/repos/asf/ignite/repo
Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/b8fee2ad
Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/b8fee2ad
Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/b8fee2ad
Branch: refs/heads/ignite-5569-debug
Commit: b8fee2ad98ffdc36b1ed48fe0c993dca795e5385
Parents: 02e2507
Author: sboikov <sb...@gridgain.com>
Authored: Thu Jul 20 12:13:06 2017 +0300
Committer: sboikov <sb...@gridgain.com>
Committed: Thu Jul 20 12:13:06 2017 +0300
----------------------------------------------------------------------
.../ignite/spi/discovery/tcp/ClientImpl.java | 2 +
.../ignite/spi/discovery/tcp/ServerImpl.java | 96 ++++++++++++++++----
2 files changed, 79 insertions(+), 19 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/ignite/blob/b8fee2ad/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ClientImpl.java
----------------------------------------------------------------------
diff --git a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ClientImpl.java b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ClientImpl.java
index 5dbfe6e..6468ccc 100644
--- a/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ClientImpl.java
+++ b/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ClientImpl.java
@@ -457,6 +457,8 @@ class ClientImpl extends TcpDiscoveryImpl {
TcpDiscoveryNode node = rmtNodes.get(nodeId);
if (node != null) {
+ log.info("Add TcpDiscoveryNodeFailedMessage, explicit call [node=" + nodeId + ']');
+
TcpDiscoveryNodeFailedMessage msg = new TcpDiscoveryNodeFailedMessage(getLocalNodeId(),
node.id(),
node.internalOrder());
http://git-wip-us.apache.org/repos/asf/ignite/blob/b8fee2ad/modules/core/src/main/java/org/apache/ignite/spi/discovery/tcp/ServerImpl.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 d621fb3..85e2666 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
@@ -786,6 +786,8 @@ class ServerImpl extends TcpDiscoveryImpl {
TcpDiscoveryNode node = ring.node(nodeId);
if (node != null) {
+ log.info("Add TcpDiscoveryNodeFailedMessage, explicit call [node=" + nodeId + ']');
+
TcpDiscoveryNodeFailedMessage msg = new TcpDiscoveryNodeFailedMessage(getLocalNodeId(),
node.id(),
node.internalOrder());
@@ -2498,6 +2500,12 @@ class ServerImpl extends TcpDiscoveryImpl {
return;
}
+ if (msg instanceof TcpDiscoveryNodeFailedMessage) {
+ ServerImpl.this.log.info("Add TcpDiscoveryNodeFailedMessage in queue [" +
+ "node=" + ((TcpDiscoveryNodeFailedMessage) msg).failedNodeId() +
+ ", queueSize=" + queue.size() + ']');
+ }
+
if (msg.highPriority())
queue.addFirst(msg);
else
@@ -2780,6 +2788,10 @@ class ServerImpl extends TcpDiscoveryImpl {
log.debug("New next node [newNext=" + newNext + ", formerNext=" + next +
", ring=" + ring + ", failedNodes=" + failedNodes + ']');
+ log.info("New next node [newNext=" + newNext.id() +
+ ", formerNext=" + (next != null ? next.id() : null) +
+ ", failedNodes=" + failedNodes + ']');
+
if (debugMode)
debugLog(msg, "New next node [newNext=" + newNext + ", formerNext=" + next +
", ring=" + ring + ", failedNodes=" + failedNodes + ']');
@@ -2796,9 +2808,6 @@ class ServerImpl extends TcpDiscoveryImpl {
log.trace("Next node remains the same [nextId=" + next.id() +
", nextOrder=" + next.internalOrder() + ']');
- // Flag that shows whether next node exists and accepts incoming connections.
- boolean nextNodeExists = sock != null;
-
final boolean sameHost = U.sameMacs(locNode, next);
List<InetSocketAddress> locNodeAddrs = U.arrayList(locNode.socketAddresses());
@@ -2823,8 +2832,6 @@ class ServerImpl extends TcpDiscoveryImpl {
if (timeoutHelper == null)
timeoutHelper = new IgniteSpiOperationTimeoutHelper(spi, true);
- nextNodeExists = false;
-
boolean success = false;
boolean openSock = false;
@@ -2869,6 +2876,11 @@ class ServerImpl extends TcpDiscoveryImpl {
log.debug("Failed to restore ring because next node ID received is not as " +
"expected [expectedId=" + next.id() + ", rcvdId=" + nextId + ']');
+ log.error("Failed to restore ring because next node ID received is not as " +
+ "expected [expectedId=" + next.id() +
+ ", sock=" + sock + ", addr=" + addr +
+ ", rcvdId=" + nextId + ']');
+
if (debugMode)
debugLog(msg, "Failed to restore ring because next node ID received is not " +
"as expected [expectedId=" + next.id() + ", rcvdId=" + nextId + ']');
@@ -2891,6 +2903,11 @@ class ServerImpl extends TcpDiscoveryImpl {
"is not as expected [expected=" + next.internalOrder() +
", rcvd=" + nextOrder + ", id=" + next.id() + ']');
+ log.error("Failed to restore ring because next node order received " +
+ "is not as expected [expected=" + next.internalOrder() +
+ ", sock=" + sock + ", addr=" + addr +
+ ", rcvd=" + nextOrder + ", id=" + next.id() + ']');
+
if (debugMode)
debugLog(msg, "Failed to restore ring because next node order " +
"received is not as expected [expected=" + next.internalOrder() +
@@ -2903,6 +2920,9 @@ class ServerImpl extends TcpDiscoveryImpl {
if (log.isDebugEnabled())
log.debug("Initialized connection with next node: " + next.id());
+ log.info("Initialized connection with next node [next=" + next.id() +
+ ", sock=" + sock + ", addr=" + addr + ']');
+
if (debugMode)
debugLog(msg, "Initialized connection with next node: " + next.id());
@@ -2923,6 +2943,12 @@ class ServerImpl extends TcpDiscoveryImpl {
U.error(log, "Failed to connect to next node [msg=" + msg
+ ", err=" + e.getMessage() + ']', e);
+ U.error(log, "Failed to connect to next node [node=" + next.id() +
+ ", openSock=" + openSock +
+ ", sock=" + sock + ", addr=" + addr +
+ ", msg=" + msg
+ + ", err=" + e.getMessage() + ']', e);
+
onException("Failed to connect to next node [msg=" + msg + ", err=" + e + ']', e);
if (!openSock)
@@ -2948,13 +2974,14 @@ class ServerImpl extends TcpDiscoveryImpl {
if (log.isDebugEnabled())
log.debug("Closing socket to next: " + next);
+ log.error("Closing socket to next [next=" + next.id() +
+ ", sock=" + sock + ", addr=" + addr + ']');
+
U.closeQuiet(sock);
sock = null;
}
else {
- // Next node exists and accepts incoming messages.
- nextNodeExists = true;
// Resetting timeout control object to let the code below to use a new one
// for the next bunch of operations.
timeoutHelper = null;
@@ -3046,6 +3073,12 @@ class ServerImpl extends TcpDiscoveryImpl {
if (latencyCheck && log.isInfoEnabled())
log.info("Latency check message has been written to socket: " + msg.id());
+ if (msg instanceof TcpDiscoveryNodeAddFinishedMessage) {
+ TcpDiscoveryNodeAddFinishedMessage msg0 = (TcpDiscoveryNodeAddFinishedMessage)msg;
+
+ log.info("TcpDiscoveryNodeAddFinishedMessage has been written to socket [node=" + msg0.nodeId() + ", next=" + next.id() + ", addr=" + addr + ']');
+ }
+
spi.writeToSocket(sock, out, msg, timeoutHelper.nextTimeoutChunk(spi.getSocketTimeout()));
long tstamp0 = U.currentTimeMillis();
@@ -3055,6 +3088,12 @@ class ServerImpl extends TcpDiscoveryImpl {
if (latencyCheck && log.isInfoEnabled())
log.info("Latency check message has been acked: " + msg.id());
+ if (msg instanceof TcpDiscoveryNodeAddFinishedMessage) {
+ TcpDiscoveryNodeAddFinishedMessage msg0 = (TcpDiscoveryNodeAddFinishedMessage)msg;
+
+ log.info("TcpDiscoveryNodeAddFinishedMessage has been acked [node=" + msg0.nodeId() + ", next=" + next.id() + ", addr=" + addr + ']');
+ }
+
spi.stats.onMessageSent(msg, tstamp0 - tstamp);
onMessageExchanged();
@@ -3095,6 +3134,12 @@ class ServerImpl extends TcpDiscoveryImpl {
U.error(log, "Failed to send message to next node [next=" + next.id() + ", msg=" + msg +
", err=" + e + ']', e);
+ U.error(log, "Failed to send message to next node [next=" + next.id() +
+ ", msg=" + msg +
+ ", sock=" + sock +
+ ", addr=" + addr +
+ ", err=" + e + ']', e);
+
onException("Failed to send message to next node [next=" + next.id() + ", msg=" + msg + ']',
e);
@@ -3120,6 +3165,9 @@ class ServerImpl extends TcpDiscoveryImpl {
if (log.isDebugEnabled())
log.debug("Closing socket to next (not sent): " + next);
+ log.error("Closing socket to next (not sent) [next=" + next.id() +
+ ", sock=" + sock + ", addr=" + addr + ']');
+
U.closeQuiet(sock);
sock = null;
@@ -3136,17 +3184,15 @@ class ServerImpl extends TcpDiscoveryImpl {
if (!failedNodes.contains(next)) {
failedNodes.add(next);
- if (state == CONNECTED) {
- Exception err = errs != null ?
- U.exceptionWithSuppressed("Failed to send message to next node [msg=" + msg +
- ", next=" + U.toShortString(next) + ']', errs) :
- null;
+ Exception err = errs != null ? U.exceptionWithSuppressed("Failed to send message to " +
+ "next node [msg=" + msg + ", next=" + U.toShortString(next) + ']', errs) : null;
- // If node existed on connection initialization we should check
- // whether it has not gone yet.
- U.warn(log, "Failed to send message to next node [msg=" + msg + ", next=" + next +
- ", errMsg=" + (err != null ? err.getMessage() : "N/A") + ']');
- }
+ // If node existed on connection initialization we should check
+ // whether it has not gone yet.
+ U.error(log, "Failed to send message to next node [msg=" + msg +
+ ", next=" + next +
+ ", sock=" + sock +
+ ", errMsg=" + (err != null ? err.getMessage() : "N/A") + ']', err);
}
next = null;
@@ -3181,8 +3227,11 @@ class ServerImpl extends TcpDiscoveryImpl {
failedNodesMsgSent.add(failedNode.id());
}
- for (TcpDiscoveryNode n : failedNodes)
+ for (TcpDiscoveryNode n : failedNodes) {
+ log.info("Add TcpDiscoveryNodeFailedMessage, send error [node=" + n.id() + ']');
+
msgWorker.addMessage(new TcpDiscoveryNodeFailedMessage(locNodeId, n.id(), n.internalOrder()));
+ }
if (!sent) {
assert next == null : next;
@@ -3329,6 +3378,8 @@ class ServerImpl extends TcpDiscoveryImpl {
if (!pingNode(existingNode)) {
U.warn(log, "Sending node failed message for existing node: " + node);
+ log.info("Add TcpDiscoveryNodeFailedMessage, failed ping [node=" + node.id() + ']');
+
addMessage(new TcpDiscoveryNodeFailedMessage(locNodeId,
existingNode.id(), existingNode.internalOrder()));
@@ -3933,6 +3984,8 @@ class ServerImpl extends TcpDiscoveryImpl {
log.debug("Failing reconnecting client node because failed to restore pending " +
"messages [locNodeId=" + locNodeId + ", clientNodeId=" + nodeId + ']');
+ log.info("Add TcpDiscoveryNodeFailedMessage, client reconnect [node=" + node.id() + ']');
+
TcpDiscoveryNodeFailedMessage nodeFailedMsg = new TcpDiscoveryNodeFailedMessage(locNodeId,
node.id(), node.internalOrder());
@@ -4152,6 +4205,8 @@ class ServerImpl extends TcpDiscoveryImpl {
"[node=" + node + ", err=" + e.getMessage() + ']', e);
}
+ log.info("Add TcpDiscoveryNodeFailedMessage, auth failed [node=" + node.id() + ']');
+
addMessage(new TcpDiscoveryNodeFailedMessage(locNodeId, node.id(),
node.internalOrder()));
}
@@ -5093,6 +5148,8 @@ class ServerImpl extends TcpDiscoveryImpl {
"(consider increasing configuration property) " +
"[timeout=" + spi.clientFailureDetectionTimeout() + ", node=" + clientNode + ']');
+ log.info("Add TcpDiscoveryNodeFailedMessage, client metrics updates [node=" + clientNode.id() + ']');
+
TcpDiscoveryNodeFailedMessage nodeFailedMsg = new TcpDiscoveryNodeFailedMessage(
locNodeId, clientNode.id(), clientNode.internalOrder());
@@ -5378,7 +5435,8 @@ class ServerImpl extends TcpDiscoveryImpl {
if (msgs != null) {
for (TcpDiscoveryNodeFailedMessage msg : msgs) {
- U.warn(log, "Added node failed message for node from failed nodes list: " + msg);
+ //U.warn(log, "Added node failed message for node from failed nodes list: " + msg);
+ log.info("Add TcpDiscoveryNodeFailedMessage, failed nodes list [node=" + msg.failedNodeId() + ']');
addMessage(msg);
}