More lazy debug log message generation

14 files changed, 123 insertions, 133 deletions

diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/ClusterStateView.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/ClusterStateView.java
index f8774b87b2a..c2215ef94c7 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/ClusterStateView.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/ClusterStateView.java
@@ -89,7 +89,7 @@ public class ClusterStateView {
             // The distributor may be old (null), or the distributor may not have updated
             // to the latest state version just yet. We log here with fine, because it may
             // also be a symptom of something wrong.
-            log.log(Level.FINE, "Current state version is " + currentStateVersion +
+            log.log(Level.FINE, () -> "Current state version is " + currentStateVersion +
                     ", while host info received from distributor " + node.getNodeIndex() +
                     " is " + hostVersion);
             return;
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/EventLog.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/EventLog.java
index f6a90124b1e..93fd176edd1 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/EventLog.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/EventLog.java
@@ -64,7 +64,7 @@ public class EventLog implements EventLogInterface {
         if (e instanceof NodeEvent) {
             addNodeOnlyEvent((NodeEvent)e, logInfo ? Level.INFO: Level.FINE);
         } else {
-            log.log(logInfo ? Level.INFO : Level.FINE, e.toString());
+            log.log(logInfo ? Level.INFO : Level.FINE, e::toString);
         }
     }
 
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 75eea998346..2bb0fb2afc4 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
@@ -579,8 +579,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd
             responseCode = StatusPageResponse.ResponseCode.INTERNAL_SERVER_ERROR;
             message = "Internal Server Error";
             hiddenMessage = ExceptionUtils.getStackTraceAsString(e);
-            log.log(Level.FINE, "Unknown exception thrown for request " + httpRequest.getRequest() +
-                    ": " + hiddenMessage);
+            log.log(Level.FINE, "Unknown exception thrown for request " + httpRequest.getRequest() + ": " + hiddenMessage);
         }
 
         TimeZone tz = TimeZone.getTimeZone("UTC");
@@ -1093,7 +1092,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd
                 firstAllowedStateBroadcast = currentTime + options.minTimeBeforeFirstSystemStateBroadcast;
                 isMaster = true;
                 inMasterMoratorium = true;
-                log.log(Level.FINE, "At time " + currentTime + " we set first system state broadcast time to be "
+                log.log(Level.FINE, () -> "At time " + currentTime + " we set first system state broadcast time to be "
                         + options.minTimeBeforeFirstSystemStateBroadcast + " ms after at time " + firstAllowedStateBroadcast + ".");
                 didWork = true;
             }
@@ -1127,7 +1126,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd
                 tick();
             }
         } catch (InterruptedException e) {
-            log.log(Level.FINE, "Event thread stopped by interrupt exception: " + e);
+            log.log(Level.FINE, () -> "Event thread stopped by interrupt exception: " + e);
         } catch (Throwable t) {
             t.printStackTrace();
             log.log(Level.SEVERE, "Fatal error killed fleet controller", t);
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/MasterElectionHandler.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/MasterElectionHandler.java
index 2c03520ec01..b6b1593034e 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/MasterElectionHandler.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/MasterElectionHandler.java
@@ -35,7 +35,7 @@ public class MasterElectionHandler implements MasterInterface {
         this.nextInLineCount = Integer.MAX_VALUE;
         // Only a given set of nodes can ever become master
         if (index > (totalCount - 1) / 2) {
-            log.log(Level.FINE, "Cluster controller " + index + ": We can never become master and will always stay a follower.");
+            log.log(Level.FINE, () -> "Cluster controller " + index + ": We can never become master and will always stay a follower.");
         }
             // Tag current time as when we have not seen any other master. Make sure we're not taking over at once for master that is on the way down
         masterGoneFromZooKeeperTime = timer.getCurrentTimeInMillis();
@@ -125,7 +125,7 @@ public class MasterElectionHandler implements MasterInterface {
         }
         if (nextMasterData == null) {
             if (masterCandidate == null) {
-                log.log(Level.FINEST, "Cluster controller " + index + ": No current master candidate. Waiting for data to do master election.");
+                log.log(Level.FINEST, () -> "Cluster controller " + index + ": No current master candidate. Waiting for data to do master election.");
             }
             return false; // Nothing have happened since last time.
         }
@@ -195,7 +195,7 @@ public class MasterElectionHandler implements MasterInterface {
             if (nextInLineCount != ourPosition) {
                 nextInLineCount = ourPosition;
                 if (ourPosition > 0) {
-                    log.log(Level.FINE, "Cluster controller " + index + ": We are now " + getPosition(nextInLineCount) + " in queue to take over being master.");
+                    log.log(Level.FINE, () -> "Cluster controller " + index + ": We are now " + getPosition(nextInLineCount) + " in queue to take over being master.");
                 }
             }
         }
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeInfo.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeInfo.java
index f014690947d..2ce6a5261e1 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeInfo.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeInfo.java
@@ -167,7 +167,7 @@ abstract public class NodeInfo implements Comparable<NodeInfo> {
         }
         if (prematureCrashCount != count) {
             prematureCrashCount = count;
-            log.log(Level.FINE, "Premature crash count on " + toString() + " set to " + count);
+            log.log(Level.FINE, () -> "Premature crash count on " + toString() + " set to " + count);
         }
     }
     public int getPrematureCrashCount() { return prematureCrashCount; }
@@ -309,17 +309,17 @@ abstract public class NodeInfo implements Comparable<NodeInfo> {
         if (state.getState().oneOf("dsm") && !reportedState.getState().oneOf("dsm")) {
             wentDownWithStartTime = reportedState.getStartTimestamp();
             wentDownAtClusterState = getNewestSystemStateSent();
-            log.log(Level.FINE, "Setting going down timestamp of node " + node + " to " + wentDownWithStartTime);
+            log.log(Level.FINE, () -> "Setting going down timestamp of node " + node + " to " + wentDownWithStartTime);
         }
         if (state.getState().equals(State.DOWN) && !reportedState.getState().oneOf("d")) {
             downStableStateTime = time;
-            log.log(Level.FINE, "Down stable state on " + toString() + " altered to " + time);
+            log.log(Level.FINE, () -> "Down stable state on " + toString() + " altered to " + time);
             if (reportedState.getState() == State.INITIALIZING) {
                 recentlyObservedUnstableDuringInit = true;
             }
         } else if (state.getState().equals(State.UP) && !reportedState.getState().oneOf("u")) {
             upStableStateTime = time;
-            log.log(Level.FINE, "Up stable state on " + toString() + " altered to " + time);
+            log.log(Level.FINE, () -> "Up stable state on " + toString() + " altered to " + time);
         }
         if (!state.getState().validReportedNodeState(node.getType())) {
             throw new IllegalStateException("Trying to set illegal reported node state: " + state);
@@ -342,19 +342,19 @@ abstract public class NodeInfo implements Comparable<NodeInfo> {
             } else {
                 nextAttemptTime = time + 5000;
             }
-            log.log(Level.FINEST, "Failed to get state from node " + toString() + ", scheduling next attempt in " + (nextAttemptTime - time) + " ms.");
+            log.log(Level.FINEST, () -> "Failed to get state from node " + toString() + ", scheduling next attempt in " + (nextAttemptTime - time) + " ms.");
         } else {
             connectionAttemptCount = 0;
             timeOfFirstFailingConnectionAttempt = 0;
             reportedState = state;
             if (version == 0 || state.getState().equals(State.STOPPING)) {
                 nextAttemptTime = time + cluster.getPollingFrequency();
-                log.log(Level.FINEST, "Scheduling next attempt to get state from " + toString() + " in " + (nextAttemptTime - time) + " ms (polling freq).");
+                log.log(Level.FINEST, () -> "Scheduling next attempt to get state from " + toString() + " in " + (nextAttemptTime - time) + " ms (polling freq).");
             } else {
                 nextAttemptTime = time;
             }
         }
-        log.log(Level.FINEST, "Set reported state of node " + this + " to " + reportedState + ". Next connection attempt is at " + nextAttemptTime);
+        log.log(Level.FINEST, () -> "Set reported state of node " + this + " to " + reportedState + ". Next connection attempt is at " + nextAttemptTime);
     }
 
     /** Sets the wanted state. The wanted state is taken as UP if a null argument is given */
@@ -374,7 +374,7 @@ abstract public class NodeInfo implements Comparable<NodeInfo> {
             }
         }
         wantedState = newWanted;
-        log.log(Level.FINEST, "Set wanted state of node " + this + " to " + wantedState + ".");
+        log.log(Level.FINEST, () -> "Set wanted state of node " + this + " to " + wantedState + ".");
     }
 
     public long getTimeForNextStateRequestAttempt() {
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeStateGatherer.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeStateGatherer.java
index da32caa0c4e..995a7c7ed1f 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeStateGatherer.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/NodeStateGatherer.java
@@ -64,12 +64,12 @@ public class NodeStateGatherer {
             if (info.getTimeForNextStateRequestAttempt() > currentTime) continue; // too early
 
             if (info.getRpcAddress() == null || info.isRpcAddressOutdated()) { // Cannot query state of node without RPC address
-                log.log(Level.FINE, "Not sending getNodeState request to node " + info.getNode() + ": Not in slobrok");
+                log.log(Level.FINE, () -> "Not sending getNodeState request to node " + info.getNode() + ": Not in slobrok");
                 NodeState reportedState = info.getReportedState().clone();
                 if (( ! reportedState.getState().equals(State.DOWN) && currentTime - info.getRpcAddressOutdatedTimestamp() > maxSlobrokDisconnectGracePeriod)
                     || reportedState.getState().equals(State.STOPPING)) // Don't wait for grace period if we expect node to be stopping
                 {
-                    log.log(Level.FINE, "Setting reported state to DOWN "
+                    log.log(Level.FINE, () -> "Setting reported state to DOWN "
                             + (reportedState.getState().equals(State.STOPPING)
                                 ? "as node completed stopping."
                                 : "as node has been out of slobrok longer than " + maxSlobrokDisconnectGracePeriod + "."));
@@ -102,7 +102,7 @@ public class NodeStateGatherer {
                 NodeInfo info = req.getNodeInfo();
 
                 if (!info.isPendingGetNodeStateRequest(req)) {
-                    log.log(Level.FINE, "Ignoring getnodestate response from " + info.getNode()
+                    log.log(Level.FINE, () -> "Ignoring getnodestate response from " + info.getNode()
                             + " as request replied to is not the most recent pending request.");
                     continue;
                 }
@@ -118,10 +118,10 @@ public class NodeStateGatherer {
                             listener.handleNewNodeState(info, newState.clone());
                             info.setReportedState(newState, currentTime);
                         } else {
-                            log.log(Level.FINE, "Ignoring get node state error. Need to resend");
+                            log.log(Level.FINE, () -> "Ignoring get node state error. Need to resend");
                         }
                     } else {
-                        log.log(Level.FINE, "Ignoring getnodestate response from " + info.getNode() + " as it was aborted by client");
+                        log.log(Level.FINE, () -> "Ignoring getnodestate response from " + info.getNode() + " as it was aborted by client");
                     }
 
                     continue;
@@ -159,7 +159,7 @@ public class NodeStateGatherer {
             if (info.getReportedState().getState().oneOf("ui")) {
                 eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + "RPC timeout talking to node.", NodeEvent.Type.REPORTED, currentTime), Level.INFO);
             } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                log.log(Level.FINE, () -> "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
             }
             newState.setDescription(msg);
         } else if (req.getReply().getReturnCode() == ErrorCode.CONNECTION) {
@@ -174,8 +174,9 @@ public class NodeStateGatherer {
                     if (info.getReportedState().getState().oneOf("ui")) {
                         eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.INFO);
                     } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                        log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode()
-                                + " " + req.getReply().getReturnMessage() + ": " + msg);
+                        if (log.isLoggable(Level.FINE))
+                            log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode()
+                                                + " " + req.getReply().getReturnMessage() + ": " + msg);
                     }
                     newState.setState(State.DOWN);
                 } else if (msg.equals("jrt: Connection closed by peer") || msg.equals("Connection reset by peer")) {
@@ -186,7 +187,8 @@ public class NodeStateGatherer {
                     if (info.getReportedState().getState().oneOf("ui")) {
                         eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.INFO);
                     } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                        log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                        if (log.isLoggable(Level.FINE))
+                            log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
                     }
                     newState.setState(State.DOWN).setDescription(msg);
                 } else if (msg.equals("Connection timed out")) {
@@ -194,14 +196,16 @@ public class NodeStateGatherer {
                         msg = "Connection error: Timeout";
                         eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.INFO);
                     } else {
-                        log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                        if (log.isLoggable(Level.FINE))
+                            log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
                     }
                 } else {
                     msg = "Connection error: " + reason;
                     if (info.getReportedState().getState().oneOf("ui")) {
                         eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.WARNING);
                     } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                        log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                        if (log.isLoggable(Level.FINE))
+                            log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
                     }
                     newState.setDescription(msg);
                 }
@@ -212,7 +216,7 @@ public class NodeStateGatherer {
                 if (info.getReportedState().getState().oneOf("ui")) {
                     eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.WARNING);
                 } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                    log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                    log.log(Level.FINE, () -> "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
                 }
                 newState.setDescription(msg);
             }
@@ -223,19 +227,19 @@ public class NodeStateGatherer {
             if (info.getReportedState().getState().oneOf("ui")) {
                 eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.WARNING);
             } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                log.log(Level.FINE, () -> "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
             }
             newState.setState(State.DOWN).setDescription(msg + ": get node state");
         } else if (req.getReply().getReturnCode() == 75004) {
             String msg = "Node refused to answer RPC request and is likely stopping: " + req.getReply().getReturnMessage();
                 // The node is shutting down and is not accepting requests from anyone
             if (info.getReportedState().getState().equals(State.STOPPING)) {
-                log.log(Level.FINE, "Failed to get node state from " + info + " because it is still shutting down.");
+                log.log(Level.FINE, () -> "Failed to get node state from " + info + " because it is still shutting down.");
             } else {
                 if (info.getReportedState().getState().oneOf("ui")) {
                     eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.INFO);
                 } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                    log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                    log.log(Level.FINE, () -> "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
                 }
             }
             newState.setState(State.STOPPING).setDescription(msg);
@@ -244,7 +248,7 @@ public class NodeStateGatherer {
             if (info.getReportedState().getState().oneOf("ui")) {
                 eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), Level.WARNING);
             } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) {
-                log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
+                log.log(Level.FINE, () -> "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg);
             }
             newState.setState(State.DOWN).setDescription(msg);
         }
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/StateChangeHandler.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/StateChangeHandler.java
index fdc5b664180..3e1390a608c 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/StateChangeHandler.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/StateChangeHandler.java
@@ -52,7 +52,7 @@ public class StateChangeHandler {
                                             final DatabaseHandler database,
                                             final DatabaseHandler.Context dbContext) throws InterruptedException {
         int startTimestampsReset = 0;
-        log.log(Level.FINE, String.format("handleAllDistributorsInSync invoked for state version %d", currentState.getVersion()));
+        log.log(Level.FINE, "handleAllDistributorsInSync invoked for state version %d", currentState.getVersion());
         for (NodeType nodeType : NodeType.getTypes()) {
             for (ConfiguredNode configuredNode : nodes) {
                 final Node node = new Node(nodeType, configuredNode.index());
@@ -60,16 +60,11 @@ public class StateChangeHandler {
                 final NodeState nodeState = currentState.getNodeState(node);
                 if (nodeInfo != null && nodeState != null) {
                     if (nodeState.getStartTimestamp() > nodeInfo.getStartTimestamp()) {
-                        if (log.isLoggable(Level.FINE)) {
-                            log.log(Level.FINE, String.format("Storing away new start timestamp for node %s (%d)",
-                                    node, nodeState.getStartTimestamp()));
-                        }
+                        log.log(Level.FINE, () -> String.format("Storing away new start timestamp for node %s (%d)", node, nodeState.getStartTimestamp()));
                         nodeInfo.setStartTimestamp(nodeState.getStartTimestamp());
                     }
                     if (nodeState.getStartTimestamp() > 0) {
-                        if (log.isLoggable(Level.FINE)) {
-                            log.log(Level.FINE, String.format("Resetting timestamp in cluster state for node %s", node));
-                        }
+                        log.log(Level.FINE, "Resetting timestamp in cluster state for node %s", node);
                         ++startTimestampsReset;
                     }
                 } else if (log.isLoggable(Level.FINE)) {
@@ -149,12 +144,11 @@ public class StateChangeHandler {
             final int oldCount = currentState.getMinUsedBits();
             final int newCount = reportedState.getMinUsedBits();
             log.log(Level.FINE,
-                    String.format("Altering node state to reflect that min distribution bit count has changed from %d to %d",
-                            oldCount, newCount));
+                    () -> String.format("Altering node state to reflect that min distribution bit count has changed from %d to %d", oldCount, newCount));
             eventLog.add(NodeEvent.forBaseline(node, String.format("Altered min distribution bit count from %d to %d", oldCount, newCount),
                          NodeEvent.Type.CURRENT, currentTime), isMaster);
-        } else if (log.isLoggable(Level.FINE)) {
-            log.log(Level.FINE, String.format("Not altering state of %s in cluster state because new state is too similar: %s",
+        } else {
+            log.log(Level.FINE, () -> String.format("Not altering state of %s in cluster state because new state is too similar: %s",
                     node, currentState.getTextualDifference(reportedState)));
         }
 
@@ -178,12 +172,12 @@ public class StateChangeHandler {
         }
 
         if (node.getReportedState().getState().equals(State.STOPPING)) {
-            log.log(Level.FINE, "Node " + node.getNode() + " is no longer in slobrok. Was in stopping state, so assuming it has shut down normally. Setting node down");
+            log.log(Level.FINE, () -> "Node " + node.getNode() + " is no longer in slobrok. Was in stopping state, so assuming it has shut down normally. Setting node down");
             NodeState ns = node.getReportedState().clone();
             ns.setState(State.DOWN);
             handleNewReportedNodeState(currentClusterState, node, ns.clone(), nodeListener);
         } else {
-            log.log(Level.FINE, "Node " + node.getNode() + " no longer in slobrok was in state " + node.getReportedState() + ". Waiting to see if it reappears in slobrok");
+            log.log(Level.FINE, () -> "Node " + node.getNode() + " no longer in slobrok was in state " + node.getReportedState() + ". Waiting to see if it reappears in slobrok");
         }
 
         stateMayHaveChanged = true;
@@ -205,9 +199,7 @@ public class StateChangeHandler {
         }
         stateMayHaveChanged = true;
 
-        if (log.isLoggable(Level.FINE)) {
-            log.log(Level.FINE, String.format("Got new wanted nodestate for %s: %s", node, currentState.getTextualDifference(proposedState)));
-        }
+        log.log(Level.FINE, () -> String.format("Got new wanted nodestate for %s: %s", node, currentState.getTextualDifference(proposedState)));
         // Should be checked earlier before state was set in cluster
         assert(proposedState.getState().validWantedNodeState(node.getNode().getType()));
         long timeNow = timer.getCurrentTimeInMillis();
@@ -293,11 +285,11 @@ public class StateChangeHandler {
 
         if (mayResetCrashCounterOnStableUpNode(currentTime, node, lastReportedState)) {
             node.setPrematureCrashCount(0);
-            log.log(Level.FINE, "Resetting premature crash count on node " + node + " as it has been up for a long time.");
+            log.log(Level.FINE, () -> "Resetting premature crash count on node " + node + " as it has been up for a long time.");
             triggeredAnyTimers = true;
         } else if (mayResetCrashCounterOnStableDownNode(currentTime, node, lastReportedState)) {
             node.setPrematureCrashCount(0);
-            log.log(Level.FINE, "Resetting premature crash count on node " + node + " as it has been down for a long time.");
+            log.log(Level.FINE, () -> "Resetting premature crash count on node " + node + " as it has been down for a long time.");
             triggeredAnyTimers = true;
         }
 
@@ -387,19 +379,14 @@ public class StateChangeHandler {
                                                  final NodeState reportedState,
                                                  final NodeStateOrHostInfoChangeHandler nodeListener) {
         final long timeNow = timer.getCurrentTimeInMillis();
-        if (log.isLoggable(Level.FINE)) {
-            log.log(Level.FINE, String.format("Finding new cluster state entry for %s switching state %s",
-                    node, currentState.getTextualDifference(reportedState)));
-        }
+        log.log(Level.FINE, () -> String.format("Finding new cluster state entry for %s switching state %s", node, currentState.getTextualDifference(reportedState)));
 
         if (handleReportedNodeCrashEdge(node, currentState, reportedState, nodeListener, timeNow)) {
             return;
         }
         if (initializationProgressHasIncreased(currentState, reportedState)) {
             node.setInitProgressTime(timeNow);
-            if (log.isLoggable(Level.FINEST)) {
-                log.log(Level.FINEST, "Reset initialize timer on " + node + " to " + node.getInitProgressTime());
-            }
+            log.log(Level.FINEST, () -> "Reset initialize timer on " + node + " to " + node.getInitProgressTime());
         }
         if (handleImplicitCrashEdgeFromReverseInitProgress(node, currentState, reportedState, nodeListener, timeNow)) {
             return;
@@ -454,7 +441,7 @@ public class StateChangeHandler {
         if (nodeUpToDownEdge(node, currentState, reportedState)) {
             node.setTransitionTime(timeNow);
             if (node.getUpStableStateTime() + stableStateTimePeriod > timeNow && !isControlledShutdown(reportedState)) {
-                log.log(Level.FINE, "Stable state: " + node.getUpStableStateTime() + " + " + stableStateTimePeriod + " > " + timeNow);
+                log.log(Level.FINE, () -> "Stable state: " + node.getUpStableStateTime() + " + " + stableStateTimePeriod + " > " + timeNow);
                 eventLog.add(NodeEvent.forBaseline(node,
                         String.format("Stopped or possibly crashed after %d ms, which is before " +
                                       "stable state time period. Premature crash count is now %d.",
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/DatabaseHandler.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/DatabaseHandler.java
index d19425a7c95..2bf86d7056b 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/DatabaseHandler.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/DatabaseHandler.java
@@ -56,7 +56,7 @@ public class DatabaseHandler {
     }
     private class DatabaseListener implements Database.DatabaseListener {
         public void handleZooKeeperSessionDown() {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Lost contact with zookeeper server");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Lost contact with zookeeper server");
             synchronized(monitor) {
                 lostZooKeeperConnectionEvent = true;
                 monitor.notifyAll();
@@ -66,7 +66,7 @@ public class DatabaseHandler {
         public void handleMasterData(Map<Integer, Integer> data) {
             synchronized (monitor) {
                 if (masterDataEvent != null && masterDataEvent.equals(data)) {
-                    log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": New master data was the same as the last one. Not responding to it");
+                    log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": New master data was the same as the last one. Not responding to it");
                 } else {
                     masterDataEvent = data;
                 }
@@ -153,7 +153,7 @@ public class DatabaseHandler {
             pendingStore.clearNonClusterStateFields();
         }
         pendingStore.masterVote = currentVote;
-        log.log(Level.FINE, "Cleared session metadata. Pending master vote is now " + pendingStore.masterVote);
+        log.log(Level.FINE, () -> "Cleared session metadata. Pending master vote is now " + pendingStore.masterVote);
     }
 
     public void setZooKeeperAddress(String address, Context context) {
@@ -168,7 +168,7 @@ public class DatabaseHandler {
 
     public void setZooKeeperSessionTimeout(int timeout, Context context) {
         if (timeout == zooKeeperSessionTimeout) return;
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got new ZooKeeper session timeout of " + timeout + " milliseconds.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Got new ZooKeeper session timeout of " + timeout + " milliseconds.");
         zooKeeperSessionTimeout = timeout;
         reset(context);
     }
@@ -197,7 +197,7 @@ public class DatabaseHandler {
                 database = databaseFactory.create(params);
             }
         } catch (KeeperException.NodeExistsException e) {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Cannot create ephemeral fleetcontroller node. ZooKeeper server "
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Cannot create ephemeral fleetcontroller node. ZooKeeper server "
                     + "not seen old fleetcontroller instance disappear? It already exists. Will retry later: " + e.getMessage());
         } catch (InterruptedException e) {
             throw (InterruptedException) new InterruptedException("Interrupted").initCause(e);
@@ -222,17 +222,17 @@ public class DatabaseHandler {
         boolean didWork = false;
         synchronized (monitor) {
             if (lostZooKeeperConnectionEvent) {
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": doNextZooKeeperTask(): lost connection");
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": doNextZooKeeperTask(): lost connection");
                 context.getFleetController().lostDatabaseConnection();
                 lostZooKeeperConnectionEvent = false;
                 didWork = true;
                 if (masterDataEvent != null) {
-                    log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Had new master data queued on disconnect. Removing master data event");
+                    log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Had new master data queued on disconnect. Removing master data event");
                     masterDataEvent = null;
                 }
             }
             if (masterDataEvent != null) {
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": doNextZooKeeperTask(): new master data");
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": doNextZooKeeperTask(): new master data");
                 if (!masterDataEvent.containsKey(nodeIndex)) {
                     Integer currentVote = (pendingStore.masterVote != null ? pendingStore.masterVote : currentlyStored.masterVote);
                     assert(currentVote != null);
@@ -282,10 +282,10 @@ public class DatabaseHandler {
         boolean didWork = false;
         if (pendingStore.masterVote != null) {
             didWork = true;
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Attempting to store master vote "
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Attempting to store master vote "
                     + pendingStore.masterVote + " into zookeeper.");
             if (database.storeMasterVote(pendingStore.masterVote)) {
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Managed to store master vote "
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Managed to store master vote "
                         + pendingStore.masterVote + " into zookeeper.");
                 currentlyStored.masterVote = pendingStore.masterVote;
                 pendingStore.masterVote = null;
@@ -296,7 +296,7 @@ public class DatabaseHandler {
         }
         if (pendingStore.lastSystemStateVersion != null) {
             didWork = true;
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex
                     + ": Attempting to store last system state version " + pendingStore.lastSystemStateVersion
                     + " into zookeeper.");
             if (database.storeLatestSystemStateVersion(pendingStore.lastSystemStateVersion)) {
@@ -308,7 +308,7 @@ public class DatabaseHandler {
         }
         if (pendingStore.startTimestamps != null) {
             didWork = true;
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Attempting to store "
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Attempting to store "
                     + pendingStore.startTimestamps.size() + " start timestamps into zookeeper.");
             if (database.storeStartTimestamps(pendingStore.startTimestamps)) {
                 currentlyStored.startTimestamps = pendingStore.startTimestamps;
@@ -319,7 +319,7 @@ public class DatabaseHandler {
         }
         if (pendingStore.wantedStates != null) {
             didWork = true;
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Attempting to store "
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Attempting to store "
                     + pendingStore.wantedStates.size() + " wanted states into zookeeper.");
             if (database.storeWantedStates(pendingStore.wantedStates)) {
                 currentlyStored.wantedStates = pendingStore.wantedStates;
@@ -344,7 +344,7 @@ public class DatabaseHandler {
     }
 
     public void setMasterVote(Context context, int wantedMasterCandidate) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Checking if master vote has been updated and need to be stored.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Checking if master vote has been updated and need to be stored.");
         // Schedule a write if one of the following is true:
         //   - There is already a pending vote to be written, that may have been written already without our knowledge
         //   - We don't know what is actually stored now
@@ -352,14 +352,14 @@ public class DatabaseHandler {
         if (pendingStore.masterVote != null || currentlyStored.masterVote == null
             || currentlyStored.masterVote != wantedMasterCandidate)
         {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Scheduling master vote " + wantedMasterCandidate + " to be stored in zookeeper.");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Scheduling master vote " + wantedMasterCandidate + " to be stored in zookeeper.");
             pendingStore.masterVote = wantedMasterCandidate;
             doNextZooKeeperTask(context);
         }
     }
 
     public void saveLatestSystemStateVersion(Context context, int version) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Checking if latest system state version has been updated and need to be stored.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Checking if latest system state version has been updated and need to be stored.");
         // Schedule a write if one of the following is true:
         //   - There is already a pending vote to be written, that may have been written already without our knowledge
         //   - We don't know what is actually stored now
@@ -367,14 +367,14 @@ public class DatabaseHandler {
         if (pendingStore.lastSystemStateVersion != null || currentlyStored.lastSystemStateVersion == null
             || currentlyStored.lastSystemStateVersion != version)
         {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Scheduling new last system state version " + version + " to be stored in zookeeper.");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Scheduling new last system state version " + version + " to be stored in zookeeper.");
             pendingStore.lastSystemStateVersion = version;
             doNextZooKeeperTask(context);
         }
     }
 
     public int getLatestSystemStateVersion() throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Retrieving latest system state version.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Retrieving latest system state version.");
         synchronized (databaseMonitor) {
             if (database != null && !database.isClosed()) {
                 currentlyStored.lastSystemStateVersion = database.retrieveLatestSystemStateVersion();
@@ -425,7 +425,7 @@ public class DatabaseHandler {
     }
 
     public void saveWantedStates(Context context) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Checking whether wanted states have changed compared to zookeeper version.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Checking whether wanted states have changed compared to zookeeper version.");
         Map<Node, NodeState> wantedStates = new TreeMap<>();
         for (NodeInfo info : context.getCluster().getNodeInfo()) {
             if (!info.getUserWantedState().equals(new NodeState(info.getNode().getType(), State.UP))) {
@@ -439,14 +439,14 @@ public class DatabaseHandler {
         if (pendingStore.wantedStates != null || currentlyStored.wantedStates == null
                 || !currentlyStored.wantedStates.equals(wantedStates))
         {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Scheduling new wanted states to be stored into zookeeper.");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Scheduling new wanted states to be stored into zookeeper.");
             pendingStore.wantedStates = wantedStates;
             doNextZooKeeperTask(context);
         }
     }
 
     public boolean loadWantedStates(Context context) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Retrieving node wanted states.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Retrieving node wanted states.");
         synchronized (databaseMonitor) {
             if (database != null && !database.isClosed()) {
                 currentlyStored.wantedStates = database.retrieveWantedStates();
@@ -457,7 +457,7 @@ public class DatabaseHandler {
             if (usingZooKeeper()) {
                 // We get here if the ZooKeeper client has lost the connection to ZooKeeper.
                 // TODO: Should instead fail the tick until connected!?
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Failed to retrieve wanted states from ZooKeeper. Assuming UP for all nodes.");
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Failed to retrieve wanted states from ZooKeeper. Assuming UP for all nodes.");
             }
             wantedStates = new TreeMap<>();
         }
@@ -471,7 +471,7 @@ public class DatabaseHandler {
                 context.getNodeStateUpdateListener().handleNewWantedNodeState(nodeInfo, wantedState);
                 altered = true;
             }
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Node " + node + " has wanted state " + wantedState);
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Node " + node + " has wanted state " + wantedState);
         }
 
         // Remove wanted state from any node having a wanted state set that is no longer valid
@@ -487,13 +487,13 @@ public class DatabaseHandler {
     }
 
     public void saveStartTimestamps(Context context) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Scheduling start timestamps to be stored into zookeeper.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Scheduling start timestamps to be stored into zookeeper.");
         pendingStore.startTimestamps = context.getCluster().getStartTimestamps();
         doNextZooKeeperTask(context);
     }
 
     public boolean loadStartTimestamps(ContentCluster cluster) throws InterruptedException {
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Retrieving start timestamps");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Retrieving start timestamps");
         synchronized (databaseMonitor) {
             if (database == null || database.isClosed()) {
                 return false;
@@ -509,7 +509,7 @@ public class DatabaseHandler {
         }
         for (Map.Entry<Node, Long> e : startTimestamps.entrySet()) {
             cluster.setStartTimestamp(e.getKey(), e.getValue());
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Node " + e.getKey() + " has start timestamp " + e.getValue());
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Node " + e.getKey() + " has start timestamp " + e.getValue());
         }
         return true;
     }
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/MasterDataGatherer.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/MasterDataGatherer.java
index 0f16ffbaf76..2933e353da0 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/MasterDataGatherer.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/MasterDataGatherer.java
@@ -62,10 +62,10 @@ public class MasterDataGatherer {
                 case NodeDeleted:
                         // We get this event when fleetcontrollers shut down and node in dir disappears. But it should also trigger a NodeChildrenChanged event, so
                         // ignoring this one.
-                    log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Node deleted event gotten. Ignoring it, expecting a NodeChildrenChanged event too.");
+                    log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Node deleted event gotten. Ignoring it, expecting a NodeChildrenChanged event too.");
                     break;
                 case None:
-                    log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got ZooKeeper event None.");
+                    log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Got ZooKeeper event None.");
             }
         }
     }
@@ -84,7 +84,7 @@ public class MasterDataGatherer {
                 for (String node : nodes) {
                     int index = Integer.parseInt(node);
                     nextMasterData.put(index, null);
-                    log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Attempting to fetch data in node '"
+                    log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Attempting to fetch data in node '"
                             + zooKeeperRoot + index + "' to see vote");
                     session.getData(zooKeeperRoot + "indexes/" + index, changeWatcher, nodeListener, null);
                     // Invocation of cycleCompleted() for fully accumulated election state will happen
@@ -124,7 +124,7 @@ public class MasterDataGatherer {
                     Integer value = Integer.valueOf(data);
                     if (nextMasterData.containsKey(index)) {
                         if (value.equals(nextMasterData.get(index))) {
-                            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got vote from fleetcontroller " + index + ", which already was " + value + ".");
+                            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Got vote from fleetcontroller " + index + ", which already was " + value + ".");
                         } else {
                             log.log(Level.INFO, "Fleetcontroller " + nodeIndex + ": Got vote from fleetcontroller " + index + ". Altering vote from " + nextMasterData.get(index) + " to " + value + ".");
                             nextMasterData.put(index, value);
@@ -135,12 +135,12 @@ public class MasterDataGatherer {
                 }
                 for(Integer vote : nextMasterData.values()) {
                     if (vote == null) {
-                        log.log(Level.FINEST, "Fleetcontroller " + nodeIndex + ": Still not received votes from all fleet controllers. Awaiting more responses.");
+                        log.log(Level.FINEST, () -> "Fleetcontroller " + nodeIndex + ": Still not received votes from all fleet controllers. Awaiting more responses.");
                         return;
                     }
                 }
             }
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got votes for all fleetcontrollers. Sending event with new fleet data for update");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Got votes for all fleetcontrollers. Sending event with new fleet data for update");
             cycleCompleted();
         }
     }
@@ -170,14 +170,14 @@ public class MasterDataGatherer {
         Map<Integer, Integer> copy;
         synchronized (nextMasterData) {
             if (nextMasterData.equals(masterData)) {
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": No change in master data detected, not sending it on");
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": No change in master data detected, not sending it on");
                 // for(Integer i : nextMasterData.keySet()) { System.err.println(i + " -> " + nextMasterData.get(i)); }
                 return;
             }
             masterData = new TreeMap<>(nextMasterData);
             copy = masterData;
         }
-        log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got new master data, sending it on");
+        log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Got new master data, sending it on");
         listener.handleMasterData(copy);
     }
 
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/ZooKeeperDatabase.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/ZooKeeperDatabase.java
index 5e0d050cbcf..97f2126e2ff 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/ZooKeeperDatabase.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/database/ZooKeeperDatabase.java
@@ -113,7 +113,7 @@ public class ZooKeeperDatabase extends Database {
         try{
             this.listener = zksl;
             setupRoot();
-            log.log(Level.FINEST, "Fleetcontroller " + nodeIndex + ": Asking for initial data on master election");
+            log.log(Level.FINEST, () -> "Fleetcontroller " + nodeIndex + ": Asking for initial data on master election");
             masterDataGatherer = new MasterDataGatherer(session, zooKeeperRoot, listener, nodeIndex);
             completedOk = true;
         } finally {
@@ -124,13 +124,13 @@ public class ZooKeeperDatabase extends Database {
     private void createNode(String prefix, String nodename, byte[] value) throws KeeperException, InterruptedException {
         try{
             if (session.exists(prefix + nodename, false) != null) {
-                log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Zookeeper node '" + prefix + nodename + "' already exists. Not creating it");
+                log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Zookeeper node '" + prefix + nodename + "' already exists. Not creating it");
                 return;
             }
             session.create(prefix + nodename, value, acl, CreateMode.PERSISTENT);
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Created zookeeper node '" + prefix + nodename + "'");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Created zookeeper node '" + prefix + nodename + "'");
         } catch (KeeperException.NodeExistsException e) {
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Node to create existed, "
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Node to create existed, "
                                   + "but this is normal as other nodes may create them at the same time.");
         }
     }
@@ -172,7 +172,7 @@ public class ZooKeeperDatabase extends Database {
     public void close() {
         sessionOpen = false;
         try{
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Trying to close ZooKeeper session 0x"
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Trying to close ZooKeeper session 0x"
                     + Long.toHexString(session.getSessionId()));
             session.close();
         } catch (InterruptedException e) {
@@ -262,7 +262,7 @@ public class ZooKeeperDatabase extends Database {
         }
         byte[] val = sb.toString().getBytes(utf8);
         try{
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Storing wanted states at '" + zooKeeperRoot + "wantedstates'");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Storing wanted states at '" + zooKeeperRoot + "wantedstates'");
             session.setData(zooKeeperRoot + "wantedstates", val, -1);
             return true;
         } catch (InterruptedException e) {
@@ -275,7 +275,7 @@ public class ZooKeeperDatabase extends Database {
 
     public Map<Node, NodeState> retrieveWantedStates() throws InterruptedException {
         try{
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Fetching wanted states at '" + zooKeeperRoot + "wantedstates'");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Fetching wanted states at '" + zooKeeperRoot + "wantedstates'");
             Stat stat = new Stat();
             byte[] data = session.getData(zooKeeperRoot + "wantedstates", false, stat);
             Map<Node, NodeState> wanted = new TreeMap<>();
@@ -313,7 +313,7 @@ public class ZooKeeperDatabase extends Database {
         }
         byte val[] = sb.toString().getBytes(utf8);
         try{
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Storing start timestamps at '" + zooKeeperRoot + "starttimestamps");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Storing start timestamps at '" + zooKeeperRoot + "starttimestamps");
             session.setData(zooKeeperRoot + "starttimestamps", val, -1);
             return true;
         } catch (InterruptedException e) {
@@ -327,7 +327,7 @@ public class ZooKeeperDatabase extends Database {
     @Override
     public Map<Node, Long> retrieveStartTimestamps() throws InterruptedException {
         try{
-            log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Fetching start timestamps at '" + zooKeeperRoot + "starttimestamps'");
+            log.log(Level.FINE, () -> "Fleetcontroller " + nodeIndex + ": Fetching start timestamps at '" + zooKeeperRoot + "starttimestamps'");
             Stat stat = new Stat();
             byte[] data = session.getData(zooKeeperRoot + "starttimestamps", false, stat);
             Map<Node, Long> wanted = new TreeMap<Node, Long>();
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 dcd7a176aa7..d5ec5751bec 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
@@ -119,7 +119,7 @@ public class SetNodeStateRequest extends Request<SetResponse> {
         NodeStateChangeChecker.Result result = cluster.calculateEffectOfNewState(
                 node, currentClusterState, condition, wantedState, newWantedState, inMasterMoratorium);
 
-        log.log(Level.FINE, "node=" + node +
+        log.log(Level.FINE, () -> "node=" + node +
                 " current-cluster-state=" + currentClusterState + // Includes version in output format
                 " condition=" + condition +
                 " wanted-state=" + wantedState +
diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RpcServer.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RpcServer.java
index 3a432e57f1f..73597e995d4 100644
--- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RpcServer.java
+++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RpcServer.java
@@ -97,13 +97,13 @@ public class RpcServer {
 
     public void connect() throws ListenFailedException, UnknownHostException {
         disconnect();
-        log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": Connecting RPC server.");
+        log.log(Level.FINE, () -> "Fleetcontroller " + fleetControllerIndex + ": Connecting RPC server.");
         if (supervisor != null) disconnect();
         supervisor = new Supervisor(new Transport("rpc" + port)).useSmallBuffers();
         addMethods();
-        log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": Attempting to bind to port " + port);
+        log.log(Level.FINE, () -> "Fleetcontroller " + fleetControllerIndex + ": Attempting to bind to port " + port);
         acceptor = supervisor.listen(new Spec(port));
-        log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": RPC server listening to port " + acceptor.port());
+        log.log(Level.FINE, () -> "Fleetcontroller " + fleetControllerIndex + ": RPC server listening to port " + acceptor.port());
         StringBuffer slobroks = new StringBuffer("(");
         for (String s : slobrokConnectionSpecs) {
             slobroks.append(" ").append(s);
@@ -123,7 +123,7 @@ public class RpcServer {
 
     public void disconnect() {
         if (register != null) {
-            log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": Disconnecting RPC server.");
+            log.log(Level.FINE, () -> "Fleetcontroller " + fleetControllerIndex + ": Disconnecting RPC server.");
             register.shutdown();
             register = null;
         }
diff --git a/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/DummyVdsNode.java b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/DummyVdsNode.java
index b54d816308b..92158692a20 100644
--- a/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/DummyVdsNode.java
+++ b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/DummyVdsNode.java
@@ -85,7 +85,7 @@ public class DummyVdsNode {
 
     private final Thread messageResponder = new Thread() {
         public void run() {
-            log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": starting message reponder thread");
+            log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": starting message reponder thread");
             while (true) {
                 synchronized (timer) {
                     if (isInterrupted()) break;
@@ -93,7 +93,7 @@ public class DummyVdsNode {
                     for (Iterator<Req> it = waitingRequests.iterator(); it.hasNext(); ) {
                         Req r = it.next();
                         if (r.timeout <= currentTime) {
-                            log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": Responding to node state request at time " + currentTime);
+                            log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": Responding to node state request at time " + currentTime);
                             r.request.returnValues().add(new StringValue(nodeState.serialize()));
                             if (r.request.methodName().equals("getnodestate3")) {
                                 r.request.returnValues().add(new StringValue("No host info in dummy implementation"));
@@ -110,7 +110,7 @@ public class DummyVdsNode {
                     }
                 }
             }
-            log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": shut down message reponder thread");
+            log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": shut down message reponder thread");
         }
     };
 
@@ -172,7 +172,7 @@ public class DummyVdsNode {
     void disconnectBreakConnection() { disconnect(true, FleetControllerTest.timeoutMS, false); }
     void disconnectAsShutdown() { disconnect(true, FleetControllerTest.timeoutMS, true); }
     private void disconnect(boolean waitForPendingNodeStateRequest, long timeoutms, boolean setStoppingStateFirst) {
-        log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": Breaking connection." + (waitForPendingNodeStateRequest ? " Waiting for pending state first." : ""));
+        log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": Breaking connection." + (waitForPendingNodeStateRequest ? " Waiting for pending state first." : ""));
         if (waitForPendingNodeStateRequest) {
             this.waitForPendingGetNodeStateRequest(timeoutms);
         }
@@ -191,7 +191,7 @@ public class DummyVdsNode {
         acceptor.shutdown().join();
         supervisor.transport().shutdown().join();
         supervisor = null;
-        log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": Done breaking connection.");
+        log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": Done breaking connection.");
     }
 
     public String toString() {
@@ -237,24 +237,24 @@ public class DummyVdsNode {
     private void waitForPendingGetNodeStateRequest(long timeout) {
         long startTime = System.currentTimeMillis();
         long endTime = startTime + timeout;
-        log.log(Level.FINE, "Dummy node " + this + " waiting for pending node state request.");
+        log.log(Level.FINE, () -> "Dummy node " + this + " waiting for pending node state request.");
         while (true) {
             synchronized(timer) {
                 if (!waitingRequests.isEmpty()) {
-                    log.log(Level.FINE, "Dummy node " + this + " has pending request, returning.");
+                    log.log(Level.FINE, () -> "Dummy node " + this + " has pending request, returning.");
                     return;
                 }
-                try{
+                try {
                     log.log(Level.FINE, "Dummy node " + this + " waiting " + (endTime - startTime) + " ms for pending request.");
                     timer.wait(endTime - startTime);
                 } catch (InterruptedException e) { /* ignore */ }
-                log.log(Level.FINE, "Dummy node " + this + " woke up to recheck.");
+                log.log(Level.FINE, () -> "Dummy node " + this + " woke up to recheck.");
             }
             startTime = System.currentTimeMillis();
             if (startTime >= endTime) {
-                log.log(Level.FINE, "Dummy node " + this + " timeout passed. Don't have pending request.");
+                log.log(Level.FINE, () -> "Dummy node " + this + " timeout passed. Don't have pending request.");
                 if (!waitingRequests.isEmpty()) {
-                    log.log(Level.FINE, "Dummy node " + this + ". Non-empty set of waiting requests");
+                    log.log(Level.FINE, () -> "Dummy node " + this + ". Non-empty set of waiting requests");
                 }
                 throw new IllegalStateException("Timeout. No pending get node state request pending after waiting " + timeout + " milliseconds.");
             }
@@ -263,7 +263,7 @@ public class DummyVdsNode {
 
     void replyToPendingNodeStateRequests() {
         for(Req req : waitingRequests) {
-            log.log(Level.FINE, "Dummy node " + this + " answering pending node state request.");
+            log.log(Level.FINE, () -> "Dummy node " + this + " answering pending node state request.");
             req.request.returnValues().add(new StringValue(nodeState.serialize()));
             if (req.request.methodName().equals("getnodestate3")) {
                 req.request.returnValues().add(new StringValue(hostInfo));
@@ -275,7 +275,7 @@ public class DummyVdsNode {
     }
 
     public void setNodeState(NodeState state, String hostInfo) {
-        log.log(Level.FINE, "Dummy node " + this + " got new state: " + state);
+        log.log(Level.FINE, () -> "Dummy node " + this + " got new state: " + state);
         synchronized(timer) {
             this.nodeState = state;
             this.hostInfo = hostInfo;
@@ -394,7 +394,7 @@ public class DummyVdsNode {
 
     private void rpc_storageConnect(Request req) {
         synchronized(timer) {
-            log.log(Level.FINEST, "Dummy node " + this + " got old type handle connect message.");
+            log.log(Level.FINEST, () -> "Dummy node " + this + " got old type handle connect message.");
             req.returnValues().add(new Int32Value(0));
             negotiatedHandle = true;
         }
@@ -407,7 +407,7 @@ public class DummyVdsNode {
                 return;
             }
             String stateString = nodeState.serialize(-1, true);
-            log.log(Level.FINE, "Dummy node " + this + " got old type get node state request, answering: " + stateString);
+            log.log(Level.FINE, () -> "Dummy node " + this + " got old type get node state request, answering: " + stateString);
             req.returnValues().add(new Int32Value(1));
             req.returnValues().add(new StringValue(""));
             req.returnValues().add(new StringValue(stateString));
@@ -419,7 +419,7 @@ public class DummyVdsNode {
         for (Iterator<Req> it = waitingRequests.iterator(); it.hasNext(); ) {
              Req r = it.next();
              if (r.request.parameters().size() > 2 && r.request.parameters().get(2).asInt32() == index) {
-                 log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": Responding to node state reply from controller " + index + " as we received new one");
+                 log.log(Level.FINE, () -> "Dummy node " + DummyVdsNode.this.toString() + ": Responding to node state reply from controller " + index + " as we received new one");
                  r.request.returnValues().add(new StringValue(nodeState.serialize()));
                  r.request.returnValues().add(new StringValue("No host info from dummy implementation"));
                  r.request.returnRequest();
@@ -432,7 +432,7 @@ public class DummyVdsNode {
     }
 
     private void rpc_getNodeState2(Request req) {
-        log.log(Level.FINE, "Dummy node " + this + ": Got " + req.methodName() + " request");
+        log.log(Level.FINE, () -> "Dummy node " + this + ": Got " + req.methodName() + " request");
         try{
             String oldState = req.parameters().get(0).asString();
             int timeout = req.parameters().get(1).asInt32();
@@ -444,14 +444,14 @@ public class DummyVdsNode {
                 boolean sentReply = sendGetNodeStateReply(index);
                 NodeState givenState = (oldState.equals("unknown") ? null : NodeState.deserialize(type, oldState));
                 if (givenState != null && (givenState.equals(nodeState) || sentReply)) {
-                    log.log(Level.FINE, "Dummy node " + this + ": Has same state as reported " + givenState + ". Queing request. Timeout is " + timeout + " ms. "
+                    log.log(Level.FINE, () -> "Dummy node " + this + ": Has same state as reported " + givenState + ". Queing request. Timeout is " + timeout + " ms. "
                             + "Will be answered at time " + (timer.getCurrentTimeInMillis() + timeout * 800l / 1000));
                     req.detach();
                     waitingRequests.add(new Req(req, timer.getCurrentTimeInMillis() + timeout * 800l / 1000));
-                    log.log(Level.FINE, "Dummy node " + this + " has now " + waitingRequests.size() + " entries and is " + (waitingRequests.isEmpty() ? "empty" : "not empty"));
+                    log.log(Level.FINE, () -> "Dummy node " + this + " has now " + waitingRequests.size() + " entries and is " + (waitingRequests.isEmpty() ? "empty" : "not empty"));
                     timer.notifyAll();
                 } else {
-                    log.log(Level.FINE, "Dummy node " + this + ": Request had " + (givenState == null ? "no state" : "different state(" + givenState +")") + ". Answering with " + nodeState);
+                    log.log(Level.FINE, () -> "Dummy node " + this + ": Request had " + (givenState == null ? "no state" : "different state(" + givenState +")") + ". Answering with " + nodeState);
                     req.returnValues().add(new StringValue(nodeState.serialize()));
                     if (req.methodName().equals("getnodestate3")) {
                         req.returnValues().add(new StringValue("Dummy node host info"));
@@ -513,7 +513,7 @@ public class DummyVdsNode {
             }
             req.returnValues().add(new Int32Value(1));
             req.returnValues().add(new StringValue("OK"));
-            log.log(Level.FINE, "Dummy node " + this + ": Got new system state (through old setsystemstate call) " + newState);
+            log.log(Level.FINE, () -> "Dummy node " + this + ": Got new system state (through old setsystemstate call) " + newState);
         } catch (Exception e) {
             log.log(Level.SEVERE, "Dummy node " + this + ": An error occurred when answering setsystemstate request: " + e.getMessage());
             e.printStackTrace(System.err);
@@ -537,7 +537,7 @@ public class DummyVdsNode {
                 }
                 timer.notifyAll();
             }
-            log.log(Level.FINE, "Dummy node " + this + ": Got new system state " + newState);
+            log.log(Level.FINE, () -> "Dummy node " + this + ": Got new system state " + newState);
         } catch (Exception e) {
             log.log(Level.SEVERE, "Dummy node " + this + ": An error occurred when answering setsystemstate request: " + e.getMessage());
             e.printStackTrace(System.err);
@@ -560,7 +560,7 @@ public class DummyVdsNode {
                 }
                 timer.notifyAll();
             }
-            log.log(Level.FINE, "Dummy node " + this + ": Got new cluster state " + stateBundle);
+            log.log(Level.FINE, () -> "Dummy node " + this + ": Got new cluster state " + stateBundle);
         } catch (Exception e) {
             log.log(Level.SEVERE, "Dummy node " + this + ": An error occurred when answering setdistributionstates request: " + e.getMessage());
             e.printStackTrace(System.err);
@@ -587,7 +587,7 @@ public class DummyVdsNode {
                             "actual %d), not marking version as active", this, activateVersion, actualVersion));
                 }
             }
-            log.log(Level.FINE, "Dummy node " + this + ": Activating cluster state version " + activateVersion);
+            log.log(Level.FINE, () -> "Dummy node " + this + ": Activating cluster state version " + activateVersion);
         } catch (Exception e) {
             log.log(Level.SEVERE, "Dummy node " + this + ": An error occurred when answering activate_cluster_state_version request: " + e.getMessage());
             e.printStackTrace(System.err);
diff --git a/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FakeTimer.java b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FakeTimer.java
index 3f9ebaf319c..fe4ecde95b5 100644
--- a/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FakeTimer.java
+++ b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FakeTimer.java
@@ -29,7 +29,7 @@ public class FakeTimer implements Timer {
     public synchronized void advanceTime(long time) {
         long currentTime = getCurrentTimeInMillis();
         this.currentTime += time;
-        log.log(Level.FINE, "Time advanced by " + time + " ms. Time increased from " + currentTime + " to " + (currentTime + time));
+        log.log(Level.FINE, () -> "Time advanced by " + time + " ms. Time increased from " + currentTime + " to " + (currentTime + time));
         notifyAll();
     }