Log version to complete remote task

Normally, if a SetNodeStateRequest changes the state of a node,
scheduleVersionDependentTasksForFutureCompletion(FleetController.java:1003)
will ensure that the request waits for the successful publication of the next
cluster state version before returning 200.

There are reasons to believe there is an edge case, likely triggered by losing
the ZooKeeper connection just prior to trying to set the new wanted state in
ZK, that makes scheduleVersionDependentTasksForFutureCompletion() complete the
request at the current version.

This PR will make it possible to prove or disprove the theory.

3 files changed, 12 insertions, 2 deletions

diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/FleetController.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/FleetController.java
index ebde8f3a98c..948e416eb53 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/FleetController.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/FleetController.java
@@ -1004,8 +1004,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd
         // TODO expose and use monotonic clock instead of system clock
         final long maxDeadlineTimePointMs = timer.getCurrentTimeInMillis() + options.getMaxDeferredTaskVersionWaitTime().toMillis();
         for (RemoteClusterControllerTask task : tasksPendingStateRecompute) {
-            context.log(logger, Level.FINEST, () -> String.format("Adding task of type '%s' to be completed at version %d",
-                                                  task.getClass().getName(), completeAtVersion));
+            context.log(logger, Level.INFO, task + " will be completed at version " + completeAtVersion);
             taskCompletionQueue.add(new VersionDependentTaskCompletion(completeAtVersion, task, maxDeadlineTimePointMs));
         }
         tasksPendingStateRecompute.clear();
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/RemoteClusterControllerTask.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/RemoteClusterControllerTask.java
index 39ffed1051a..949ad6f56a2 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/RemoteClusterControllerTask.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/RemoteClusterControllerTask.java
@@ -123,4 +123,6 @@ public abstract class RemoteClusterControllerTask {
         }
     }
 
+    @Override
+    public String toString() { return RemoteClusterControllerTask.class.getSimpleName(); }
 }
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/restapiv2/requests/SetNodeStateRequest.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/restapiv2/requests/SetNodeStateRequest.java
index f406ec46ccc..431c207af5c 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/restapiv2/requests/SetNodeStateRequest.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/restapiv2/requests/SetNodeStateRequest.java
@@ -98,6 +98,15 @@ public class SetNodeStateRequest extends Request<SetResponse> {
         return super.isFailed() || (resultSet && !result.getWasModified());
     }
 
+    @Override
+    public String toString() {
+        return "SetNodeStateRequest{" +
+               "node=" + id + "," +
+               "newState=" + newStates.get("user") + "," +
+               (probe ? "probe=" + probe + "," : "") +
+               "}";
+    }
+
     static SetResponse setWantedState(
             ContentCluster cluster,
             SetUnitStateRequest.Condition condition,