[Zen2] Minor logging improvements (#36818)

* Adds term number and greppable phrase 'coordinator becoming' to Coordinator mode changes * Adds term and version to messages from the ClusterApplier about master changes * Reduces some LeaderChecker messages to TRACE level
elastic · Dec 20, 2018 · 52d34e4 · 52d34e4
1 parent b42074c
commit 52d34e4
Show file tree

Hide file tree

Showing 4 changed files with 13 additions and 8 deletions.
diff --git a/server/src/main/java/org/elasticsearch/cluster/coordination/Coordinator.java b/server/src/main/java/org/elasticsearch/cluster/coordination/Coordinator.java
@@ -403,7 +403,8 @@ private void handleJoinRequest(JoinRequest joinRequest, JoinHelper.JoinCallback
 
     void becomeCandidate(String method) {
         assert Thread.holdsLock(mutex) : "Coordinator mutex not held";
-        logger.debug("{}: becoming CANDIDATE (was {}, lastKnownLeader was [{}])", method, mode, lastKnownLeader);
+        logger.debug("{}: coordinator becoming CANDIDATE in term {} (was {}, lastKnownLeader was [{}])",
+            method, getCurrentTerm(), mode, lastKnownLeader);
 
         if (mode != Mode.CANDIDATE) {
             mode = Mode.CANDIDATE;
@@ -440,7 +441,8 @@ void becomeLeader(String method) {
         assert mode == Mode.CANDIDATE : "expected candidate but was " + mode;
         assert getLocalNode().isMasterNode() : getLocalNode() + " became a leader but is not master-eligible";
 
-        logger.debug("{}: becoming LEADER (was {}, lastKnownLeader was [{}])", method, mode, lastKnownLeader);
+        logger.debug("{}: coordinator becoming LEADER in term {} (was {}, lastKnownLeader was [{}])",
+            method, getCurrentTerm(), mode, lastKnownLeader);
 
         mode = Mode.LEADER;
         joinAccumulator.close(mode);
@@ -461,7 +463,8 @@ void becomeFollower(String method, DiscoveryNode leaderNode) {
         assert Thread.holdsLock(mutex) : "Coordinator mutex not held";
         assert leaderNode.isMasterNode() : leaderNode + " became a leader but is not master-eligible";
 
-        logger.debug("{}: becoming FOLLOWER of [{}] (was {}, lastKnownLeader was [{}])", method, leaderNode, mode, lastKnownLeader);
+        logger.debug("{}: coordinator becoming FOLLOWER of [{}] in term {} (was {}, lastKnownLeader was [{}])",
+            method, leaderNode, getCurrentTerm(), mode, lastKnownLeader);
 
         final boolean restartLeaderChecker = (mode == Mode.FOLLOWER && Optional.of(leaderNode).equals(lastKnownLeader)) == false;
 

diff --git a/server/src/main/java/org/elasticsearch/cluster/coordination/LeaderChecker.java b/server/src/main/java/org/elasticsearch/cluster/coordination/LeaderChecker.java
@@ -203,15 +203,15 @@ private class CheckScheduler implements Releasable {
         @Override
         public void close() {
             if (isClosed.compareAndSet(false, true) == false) {
-                logger.debug("already closed");
+                logger.trace("already closed, doing nothing");
             } else {
                 logger.debug("closed");
             }
         }
 
         void handleWakeUp() {
             if (isClosed.get()) {
-                logger.debug("closed check scheduler woken up, doing nothing");
+                logger.trace("closed check scheduler woken up, doing nothing");
                 return;
             }
 
@@ -289,7 +289,7 @@ void leaderFailed() {
             if (isClosed.compareAndSet(false, true)) {
                 transportService.getThreadPool().generic().execute(onLeaderFailure);
             } else {
-                logger.debug("already closed, not failing leader");
+                logger.trace("already closed, not failing leader");
             }
         }
 

diff --git a/server/src/main/java/org/elasticsearch/cluster/service/ClusterApplierService.java b/server/src/main/java/org/elasticsearch/cluster/service/ClusterApplierService.java
@@ -446,7 +446,8 @@ private void applyChanges(UpdateTask task, ClusterState previousClusterState, Cl
         if (nodesDelta.hasChanges() && logger.isInfoEnabled()) {
             String summary = nodesDelta.shortSummary();
             if (summary.length() > 0) {
-                logger.info("{}, reason: {}", summary, task.source);
+                logger.info("{}, term: {}, version: {}, reason: {}",
+                    summary, newClusterState.term(), newClusterState.version(), task.source);
             }
         }
 

diff --git a/server/src/main/java/org/elasticsearch/cluster/service/MasterService.java b/server/src/main/java/org/elasticsearch/cluster/service/MasterService.java
@@ -230,7 +230,8 @@ protected void runTasks(TaskInputs taskInputs) {
                 if (nodesDelta.hasChanges() && logger.isInfoEnabled()) {
                     String nodeSummary = nodesDelta.shortSummary();
                     if (nodeSummary.length() > 0) {
-                        logger.info("{}, reason: {}", summary, nodeSummary);
+                        logger.info("{}, term: {}, version: {}, reason: {}",
+                            summary, newClusterState.term(), newClusterState.version(), nodeSummary);
                     }
                 }