diff options
146 files changed, 573 insertions, 704 deletions
diff --git a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/IdentityProviderRequestHandler.java b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/IdentityProviderRequestHandler.java index fe6fa0baf2d..afb3b1211a4 100644 --- a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/IdentityProviderRequestHandler.java +++ b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/IdentityProviderRequestHandler.java @@ -67,7 +67,7 @@ public class IdentityProviderRequestHandler extends RestApiRequestHandler<Identi } private InstanceConfirmation confirmInstance(RestApi.RequestContext context, InstanceConfirmation instanceConfirmation) { - log.log(Level.FINE, instanceConfirmation.toString()); + log.log(Level.FINE, () -> instanceConfirmation.toString()); if (!instanceValidator.isValidInstance(instanceConfirmation)) { log.log(Level.SEVERE, "Invalid instance: " + instanceConfirmation); throw new RestApiException.Forbidden("Instance is invalid"); @@ -76,7 +76,7 @@ public class IdentityProviderRequestHandler extends RestApiRequestHandler<Identi } private InstanceConfirmation confirmInstanceRefresh(RestApi.RequestContext context, InstanceConfirmation instanceConfirmation) { - log.log(Level.FINE, instanceConfirmation.toString()); + log.log(Level.FINE, () -> instanceConfirmation.toString()); if (!instanceValidator.isValidRefresh(instanceConfirmation)) { log.log(Level.SEVERE, "Invalid instance refresh: " + instanceConfirmation); throw new RestApiException.Forbidden("Instance is invalid"); 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..da115e56fbb 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,8 @@ 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); + if (log.isLoggable(Level.FINE)) + log.log(Level.FINE, "Unknown exception thrown for request " + httpRequest.getRequest() + ": " + hiddenMessage); } TimeZone tz = TimeZone.getTimeZone("UTC"); @@ -1093,7 +1093,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 +1127,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(); } diff --git a/config-application-package/src/main/java/com/yahoo/config/application/OverrideProcessor.java b/config-application-package/src/main/java/com/yahoo/config/application/OverrideProcessor.java index 35584bf9608..d2a3fd8c161 100644 --- a/config-application-package/src/main/java/com/yahoo/config/application/OverrideProcessor.java +++ b/config-application-package/src/main/java/com/yahoo/config/application/OverrideProcessor.java @@ -54,7 +54,7 @@ class OverrideProcessor implements PreProcessor { } public Document process(Document input) throws TransformerException { - log.log(Level.FINE, "Preprocessing overrides with " + environment + "." + region); + log.log(Level.FINE, () -> "Preprocessing overrides with " + environment + "." + region); Document ret = Xml.copyDocument(input); Element root = ret.getDocumentElement(); applyOverrides(root, Context.empty()); diff --git a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationFile.java b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationFile.java index 31349967462..5753945133c 100644 --- a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationFile.java +++ b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationFile.java @@ -41,7 +41,7 @@ public class FilesApplicationFile extends ApplicationFile { @Override public ApplicationFile delete() { - log.log(Level.FINE, "Delete " + file); + log.log(Level.FINE, () -> "Delete " + file); if (file.isDirectory() && !listFiles().isEmpty()) { throw new RuntimeException("files. Can't delete, directory not empty: " + this + "(" + listFiles() + ")." + listFiles().size()); } @@ -154,7 +154,7 @@ public class FilesApplicationFile extends ApplicationFile { private void writeMetaFile(String data, String status) throws IOException { File metaDir = createMetaDir(); - log.log(Level.FINE, "meta dir=" + metaDir); + log.log(Level.FINE, () -> "meta dir=" + metaDir); File metaFile = new File(metaDir + "/" + getPath().getName()); if (status == null) { status = ApplicationFile.ContentStatusNew; @@ -174,7 +174,7 @@ public class FilesApplicationFile extends ApplicationFile { private File createMetaDir() { File metaDir = getMetaDir(); if (!metaDir.exists()) { - log.log(Level.FINE, "Creating meta dir " + metaDir); + log.log(Level.FINE, () -> "Creating meta dir " + metaDir); metaDir.mkdirs(); } return metaDir; @@ -188,7 +188,7 @@ public class FilesApplicationFile extends ApplicationFile { public MetaData getMetaData() { File metaDir = getMetaDir(); File metaFile = new File(metaDir + "/" + getPath().getName()); - log.log(Level.FINE, "Getting metadata for " + metaFile); + log.log(Level.FINE, () -> "Getting metadata for " + metaFile); if (metaFile.exists()) { try { return mapper.readValue(metaFile, MetaData.class); diff --git a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationPackage.java b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationPackage.java index 2f9793112b6..da5bff984db 100644 --- a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationPackage.java +++ b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/FilesApplicationPackage.java @@ -294,7 +294,7 @@ public class FilesApplicationPackage implements ApplicationPackage { String dir = include.getAttribute(IncludeDirs.DIR); validateIncludeDir(dir); IncludeDirs.validateFilesInIncludedDir(dir, include.getParentNode(), this); - log.log(Level.FINE, "Adding user include dir '" + dir + "'"); + log.log(Level.FINE, () -> "Adding user include dir '" + dir + "'"); userIncludeDirs.add(dir); } @@ -368,7 +368,7 @@ public class FilesApplicationPackage implements ApplicationPackage { private void addAllDefsFromConfigDir(Map<ConfigDefinitionKey, UnparsedConfigDefinition> defs, File configDefsDir) { if (! configDefsDir.isDirectory()) return; - log.log(Level.FINE, "Getting all config definitions from '" + configDefsDir + "'"); + log.log(Level.FINE, () -> "Getting all config definitions from '" + configDefsDir + "'"); for (File def : configDefsDir.listFiles((File dir, String name) -> name.matches(".*\\.def"))) { String[] nv = def.getName().split("\\.def"); ConfigDefinitionKey key; diff --git a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/SchemaValidators.java b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/SchemaValidators.java index 28f74b4adc0..6d7fb398608 100644 --- a/config-application-package/src/main/java/com/yahoo/config/model/application/provider/SchemaValidators.java +++ b/config-application-package/src/main/java/com/yahoo/config/model/application/provider/SchemaValidators.java @@ -110,10 +110,10 @@ public class SchemaValidators { if (uris == null) throw new IllegalArgumentException("Could not find XML schemas "); File tmpDir = createTempDirectory(tmpBase.toPath(), "vespa").toFile(); - log.log(Level.FINE, "Will save all XML schemas for " + vespaVersion + " to " + tmpDir); + log.log(Level.FINE, () -> "Will save all XML schemas for " + vespaVersion + " to " + tmpDir); while (uris.hasMoreElements()) { URL u = uris.nextElement(); - log.log(Level.FINE, "uri for resource 'schema'=" + u.toString()); + log.log(Level.FINE, () -> "uri for resource 'schema'=" + u.toString()); // TODO: When is this the case? Remove? if ("jar".equals(u.getProtocol())) { JarURLConnection jarConnection = (JarURLConnection) u.openConnection(); @@ -127,7 +127,7 @@ public class SchemaValidators { jarFile.close(); } else if ("bundle".equals(u.getProtocol())) { Bundle bundle = getBundle(schemaValidatorClass); - log.log(Level.FINE, "bundle=" + bundle); + log.log(Level.FINE, () -> "bundle=" + bundle); // TODO: Hack to handle cases where bundle=null (which seems to always be the case with config-model-fat-amended.jar) if (bundle == null) { String pathPrefix = getDefaults().underVespaHome("share/vespa/schema/"); @@ -135,11 +135,10 @@ public class SchemaValidators { // Fallback to path without version if path with version does not exist if (! schemaPath.exists()) schemaPath = new File(pathPrefix); - log.log(Level.FINE, "Using schemas found in " + schemaPath); + log.log(Level.FINE, "Using schemas found in %s", schemaPath); copySchemas(schemaPath, tmpDir); } else { - log.log(Level.FINE, String.format("Saving schemas for model bundle %s:%s", bundle.getSymbolicName(), bundle - .getVersion())); + log.log(Level.FINE, () -> String.format("Saving schemas for model bundle %s:%s", bundle.getSymbolicName(), bundle.getVersion())); for (Enumeration<URL> entries = bundle.findEntries("schema", "*.rnc", true); entries.hasMoreElements(); ) { diff --git a/config-model/src/main/java/com/yahoo/config/model/ConfigModelRepo.java b/config-model/src/main/java/com/yahoo/config/model/ConfigModelRepo.java index 454da0d657a..557df4bd106 100644 --- a/config-model/src/main/java/com/yahoo/config/model/ConfigModelRepo.java +++ b/config-model/src/main/java/com/yahoo/config/model/ConfigModelRepo.java @@ -266,7 +266,7 @@ public class ConfigModelRepo implements ConfigModelRepoAdder, Serializable, Iter // TODO: Doctoring on the XML is the wrong level for this. We should be able to mark a model as default instead -Jon private static Element getImplicitAdmin(DeployState deployState) throws IOException, SAXException { String defaultAdminElement = deployState.isHosted() ? getImplicitAdminV4() : getImplicitAdminV2(); - log.log(Level.FINE, "No <admin> defined, using " + defaultAdminElement); + log.log(Level.FINE, () -> "No <admin> defined, using " + defaultAdminElement); return XmlHelper.getDocumentBuilder().parse(new InputSource(new StringReader(defaultAdminElement))).getDocumentElement(); } diff --git a/config-model/src/main/java/com/yahoo/config/model/admin/AdminModel.java b/config-model/src/main/java/com/yahoo/config/model/admin/AdminModel.java index ec1038c67db..59aa7e48639 100644 --- a/config-model/src/main/java/com/yahoo/config/model/admin/AdminModel.java +++ b/config-model/src/main/java/com/yahoo/config/model/admin/AdminModel.java @@ -81,7 +81,7 @@ public class AdminModel extends ConfigModel { new BuilderV4().doBuild(model, adminElement, modelContext); return; } - AbstractConfigProducer parent = modelContext.getParentProducer(); + AbstractConfigProducer<?> parent = modelContext.getParentProducer(); ModelContext.Properties properties = modelContext.getDeployState().getProperties(); DomAdminV2Builder domBuilder = new DomAdminV2Builder(modelContext.getApplicationType(), modelContext.getDeployState().getFileRegistry(), diff --git a/config-model/src/main/java/com/yahoo/vespa/model/PortFinder.java b/config-model/src/main/java/com/yahoo/vespa/model/PortFinder.java index 968f8399e4b..a3d0d2777ab 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/PortFinder.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/PortFinder.java @@ -41,7 +41,7 @@ public class PortFinder { String key = request.key(); if (byKeys.containsKey(key)) { int port = byKeys.get(key).port; - log.log(Level.FINE, "Re-using port "+port+" for allocation " + request + " on " + host); + log.log(Level.FINE, () -> "Re-using port "+port+" for allocation " + request + " on " + host); return port; } int port = request.port; diff --git a/config-model/src/main/java/com/yahoo/vespa/model/VespaModel.java b/config-model/src/main/java/com/yahoo/vespa/model/VespaModel.java index 44bade4cd84..d78a69b4802 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/VespaModel.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/VespaModel.java @@ -407,7 +407,7 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri */ protected void checkId(String configId) { if ( ! id2producer.containsKey(configId)) { - log.log(Level.FINE, "Invalid config id: " + configId); + log.log(Level.FINE, () -> "Invalid config id: " + configId); } } diff --git a/config-model/src/main/java/com/yahoo/vespa/model/admin/Admin.java b/config-model/src/main/java/com/yahoo/vespa/model/admin/Admin.java index efae00096df..2b850d8f3eb 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/admin/Admin.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/admin/Admin.java @@ -15,6 +15,7 @@ import com.yahoo.vespa.model.ConfigProxy; import com.yahoo.vespa.model.ConfigSentinel; import com.yahoo.vespa.model.HostResource; import com.yahoo.vespa.model.Logd; +import com.yahoo.vespa.model.admin.clustercontroller.ClusterControllerContainer; import com.yahoo.vespa.model.admin.clustercontroller.ClusterControllerContainerCluster; import com.yahoo.vespa.model.admin.metricsproxy.MetricsProxyContainer; import com.yahoo.vespa.model.admin.metricsproxy.MetricsProxyContainerCluster; @@ -27,6 +28,7 @@ import com.yahoo.vespa.model.filedistribution.FileDistributor; import java.io.Serializable; import java.util.ArrayList; +import java.util.Collection; import java.util.Collections; import java.util.List; import java.util.Optional; @@ -142,8 +144,22 @@ public class Admin extends AbstractConfigProducer<Admin> implements Serializable public ClusterControllerContainerCluster getClusterControllers() { return clusterControllers; } - public void setClusterControllers(ClusterControllerContainerCluster clusterControllers) { + public void setClusterControllers(ClusterControllerContainerCluster clusterControllers, DeployLogger deployLogger) { this.clusterControllers = clusterControllers; + if (isHostedVespa) + addSlobroks(createSlobroksOn(clusterControllers, deployLogger)); + } + + private List<Slobrok> createSlobroksOn(ClusterControllerContainerCluster clusterControllers, DeployLogger deployLogger) { + List<Slobrok> slobroks = new ArrayList<>(); + int index = this.slobroks.size(); + for (ClusterControllerContainer clusterController : clusterControllers.getContainers()) { + Slobrok slobrok = new Slobrok(this, index++); + slobrok.setHostResource(clusterController.getHostResource()); + slobroks.add(slobrok); + slobrok.initService(deployLogger); + } + return slobroks; } public Optional<LogserverContainerCluster> getLogServerContainerCluster() { return logServerContainerCluster; } diff --git a/config-model/src/main/java/com/yahoo/vespa/model/admin/Slobrok.java b/config-model/src/main/java/com/yahoo/vespa/model/admin/Slobrok.java index 43f02f8b6d4..eed886b707f 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/admin/Slobrok.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/admin/Slobrok.java @@ -22,7 +22,7 @@ public class Slobrok extends AbstractService implements StateserverConfig.Produc } /** - * @param parent The parent ConfigProducer. + * @param parent the parent ConfigProducer. * @param index unique index for all slobroks */ public Slobrok(AbstractConfigProducer parent, int index) { diff --git a/config-model/src/main/java/com/yahoo/vespa/model/application/validation/RankSetupValidator.java b/config-model/src/main/java/com/yahoo/vespa/model/application/validation/RankSetupValidator.java index 776ee675ffd..7049213ddab 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/application/validation/RankSetupValidator.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/application/validation/RankSetupValidator.java @@ -99,11 +99,11 @@ public class RankSetupValidator extends Validator { // Give up, don't say same error msg repeatedly deleteTempDir(tempDir); } - log.log(Level.FINE, String.format("Validating %s for %s, %s took %s ms", - sdName, - searchCluster, - configId, - Duration.between(start, Instant.now()).toMillis())); + log.log(Level.FINE, () -> String.format("Validating %s for %s, %s took %s ms", + sdName, + searchCluster, + configId, + Duration.between(start, Instant.now()).toMillis())); return ret; } catch (IllegalArgumentException e) { deleteTempDir(tempDir); diff --git a/config-model/src/main/java/com/yahoo/vespa/model/builder/UserConfigBuilder.java b/config-model/src/main/java/com/yahoo/vespa/model/builder/UserConfigBuilder.java index 3390eea21bc..4606d9aa885 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/builder/UserConfigBuilder.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/builder/UserConfigBuilder.java @@ -26,7 +26,7 @@ public class UserConfigBuilder { if (producerSpec == null) { log.log(Level.FINEST, "In getUserConfigs. producerSpec is null"); } - log.log(Level.FINE, "getUserConfigs for " + producerSpec); + log.log(Level.FINE, () -> "getUserConfigs for " + producerSpec); for (Element configE : XML.getChildren(producerSpec, "config")) { buildElement(configE, builderMap, configDefinitionStore, deployLogger); } diff --git a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV2Builder.java b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV2Builder.java index d6e419cf63f..a1329b2a5b4 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV2Builder.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV2Builder.java @@ -46,7 +46,8 @@ public class DomAdminV2Builder extends DomAdminBuilderBase { admin.addConfigservers(configservers); admin.addSlobroks(getSlobroks(deployState, admin, XML.getChild(adminE, "slobroks"))); if ( ! admin.multitenant()) - admin.setClusterControllers(addConfiguredClusterControllers(deployState, admin, adminE)); + admin.setClusterControllers(addConfiguredClusterControllers(deployState, admin, adminE), + deployState.getDeployLogger()); ModelElement adminElement = new ModelElement(adminE); addLogForwarders(adminElement.child("logforwarding"), admin); diff --git a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV4Builder.java b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV4Builder.java index f7b838de911..a0673824907 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV4Builder.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/DomAdminV4Builder.java @@ -13,6 +13,7 @@ import com.yahoo.vespa.model.admin.Logserver; import com.yahoo.vespa.model.admin.LogserverContainer; import com.yahoo.vespa.model.admin.LogserverContainerCluster; import com.yahoo.vespa.model.admin.Slobrok; +import com.yahoo.vespa.model.admin.clustercontroller.ClusterControllerContainer; import com.yahoo.vespa.model.container.Container; import com.yahoo.vespa.model.container.ContainerModel; import org.w3c.dom.Element; @@ -62,10 +63,14 @@ public class DomAdminV4Builder extends DomAdminBuilderBase { private void assignSlobroks(DeployLogger deployLogger, NodesSpecification nodesSpecification, Admin admin) { if (nodesSpecification.isDedicated()) { - createSlobroks(deployLogger, admin, allocateHosts(admin.hostSystem(), "slobroks", nodesSpecification)); + createSlobroks(deployLogger, + admin, + allocateHosts(admin.hostSystem(), "slobroks", nodesSpecification)); } - else { - createSlobroks(deployLogger, admin, pickContainerHostsForSlobrok(nodesSpecification.minResources().nodes(), 2)); + else { // TODO: Remove + createSlobroks(deployLogger, + admin, + pickContainerHostsForSlobrok(nodesSpecification.minResources().nodes(), 2)); } } diff --git a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/VespaDomBuilder.java b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/VespaDomBuilder.java index e65fd863d7d..df4cb06ec47 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/VespaDomBuilder.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/VespaDomBuilder.java @@ -136,7 +136,7 @@ public class VespaDomBuilder extends VespaModelBuilder { UserConfigRepo userConfigs = UserConfigBuilder.build(producerSpec, deployState, deployState.getDeployLogger()); // TODO: must be made to work: //userConfigs.applyWarnings(child); - log.log(Level.FINE, "Adding user configs " + userConfigs + " for " + producerSpec); + log.log(Level.FINE, () -> "Adding user configs " + userConfigs + " for " + producerSpec); child.mergeUserConfigs(userConfigs); } diff --git a/config-model/src/main/java/com/yahoo/vespa/model/content/cluster/ContentCluster.java b/config-model/src/main/java/com/yahoo/vespa/model/content/cluster/ContentCluster.java index d9bd413f053..f6a45842bd9 100644 --- a/config-model/src/main/java/com/yahoo/vespa/model/content/cluster/ContentCluster.java +++ b/config-model/src/main/java/com/yahoo/vespa/model/content/cluster/ContentCluster.java @@ -302,7 +302,8 @@ public class ContentCluster extends AbstractConfigProducer implements host, "cluster-controllers", true, - deployState)); + deployState), + deployState.getDeployLogger()); } clusterControllers = admin.getClusterControllers(); } @@ -318,7 +319,8 @@ public class ContentCluster extends AbstractConfigProducer implements hosts, "cluster-controllers", false, - deployState)); + deployState), + deployState.getDeployLogger()); } clusterControllers = admin.getClusterControllers(); } @@ -351,7 +353,8 @@ public class ContentCluster extends AbstractConfigProducer implements hosts, "cluster-controllers", true, - context.getDeployState())); + context.getDeployState()), + deployState.getDeployLogger()); } return admin.getClusterControllers(); } diff --git a/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java b/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java index caa5357febe..10019b00f61 100644 --- a/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java +++ b/config-model/src/test/java/com/yahoo/config/model/provision/ModelProvisioningTest.java @@ -39,6 +39,7 @@ import org.junit.Ignore; import org.junit.Test; import java.io.StringReader; +import java.util.HashSet; import java.util.List; import java.util.Map; import java.util.Optional; @@ -491,9 +492,12 @@ public class ModelProvisioningTest { // Check admin clusters Admin admin = model.getAdmin(); + Set<HostResource> clusterControllerHosts = admin.getClusterControllers().getContainers() + .stream().map(cc -> cc.getHostResource()).collect(Collectors.toSet()); Set<HostResource> slobrokHosts = admin.getSlobroks().stream().map(Slobrok::getHost).collect(Collectors.toSet()); - assertEquals(3, slobrokHosts.size()); - assertTrue("Slobroks are assigned from container nodes", containerHosts.containsAll(slobrokHosts)); + assertEquals(6, slobrokHosts.size()); + assertTrue("Slobroks are assigned from container and cluster controller nodes", + union(containerHosts, clusterControllerHosts).containsAll(slobrokHosts)); assertTrue("Logserver is assigned from container nodes", containerHosts.contains(admin.getLogserver().getHost())); assertEquals("No in-cluster config servers in a hosted environment", 0, admin.getConfigservers().size()); assertEquals("Dedicated admin cluster controllers when hosted", 3, admin.getClusterControllers().getContainers().size()); @@ -596,9 +600,12 @@ public class ModelProvisioningTest { // Check admin clusters Admin admin = model.getAdmin(); + Set<HostResource> clusterControllerHosts = admin.getClusterControllers().getContainers() + .stream().map(cc -> cc.getHostResource()).collect(Collectors.toSet()); Set<HostResource> slobrokHosts = admin.getSlobroks().stream().map(Slobrok::getHost).collect(Collectors.toSet()); - assertEquals(3, slobrokHosts.size()); - assertTrue("Slobroks are assigned from container nodes", containerHosts.containsAll(slobrokHosts)); + assertEquals(6, slobrokHosts.size()); + assertTrue("Slobroks are assigned from container and cluster controller nodes", + union(containerHosts, clusterControllerHosts).containsAll(slobrokHosts)); assertTrue("Logserver is assigned from container nodes", containerHosts.contains(admin.getLogserver().getHost())); assertEquals("No in-cluster config servers in a hosted environment", 0, admin.getConfigservers().size()); assertEquals(3, admin.getClusterControllers().getContainers().size()); @@ -1495,7 +1502,7 @@ public class ModelProvisioningTest { tester.addHosts(6); VespaModel model = tester.createModel(services, true); assertEquals(6, model.getRoot().hostSystem().getHosts().size()); - assertEquals(2, model.getAdmin().getSlobroks().size()); + assertEquals(5, model.getAdmin().getSlobroks().size()); assertEquals(2, model.getContainerClusters().get("foo").getContainers().size()); assertEquals(1, model.getContentClusters().get("bar").getRootGroup().countNodes()); } @@ -2020,4 +2027,11 @@ public class ModelProvisioningTest { assertProvisioned(nodeCount, id, null, type, model); } + private Set<HostResource> union(Set<HostResource> a, Set<HostResource> b) { + Set<HostResource> union = new HashSet<>(); + union.addAll(a); + union.addAll(b); + return union; + } + } diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ConfigProxyRpcServer.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ConfigProxyRpcServer.java index fbc10c772d7..3700dee92e3 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ConfigProxyRpcServer.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ConfigProxyRpcServer.java @@ -50,7 +50,7 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer public void run() { try { Acceptor acceptor = supervisor.listen(spec); - log.log(Level.FINE, "Ready for requests on " + spec); + log.log(Level.FINE, () -> "Ready for requests on " + spec); supervisor.transport().join(); acceptor.shutdown().join(); } catch (ListenFailedException e) { @@ -284,7 +284,7 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer } else if (ProxyServer.configOrGenerationHasChanged(config, request)) { returnOkResponse(request, config); } else { - log.log(Level.FINEST, "No new config for " + request.getShortDescription() + ", not sending response"); + log.log(Level.FINEST, () -> "No new config for " + request.getShortDescription() + ", not sending response"); } } catch (Exception e) { e.printStackTrace(); diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCache.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCache.java index ac6fac3b16c..86f2022fa82 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCache.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCache.java @@ -109,16 +109,15 @@ public class MemoryCache { } private void writeConfigToFile(RawConfig config, String path) { - String filename = null; + String filename = path + File.separator + createCacheFileName(config); Writer writer = null; try { - filename = path + File.separator + createCacheFileName(config); if (log.isLoggable(Level.FINE)) { log.log(Level.FINE, "Writing '" + config.getKey() + "' to '" + filename + "'"); } final Payload payload = config.getPayload(); long protocolVersion = 3; - log.log(Level.FINE, "Writing config '" + config + "' to file '" + filename + "' with protocol version " + protocolVersion); + log.log(Level.FINE, () -> "Writing config '" + config + "' to file '" + filename + "' with protocol version " + protocolVersion); writer = IOUtils.createWriter(filename, "UTF-8", false); // First three lines are meta-data about config as comment lines, fourth line is empty diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ProxyServer.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ProxyServer.java index ccd53cf8491..047cec87ed7 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ProxyServer.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/ProxyServer.java @@ -57,7 +57,7 @@ public class ProxyServer implements Runnable { ProxyServer(Spec spec, ConfigSourceSet source, MemoryCache memoryCache, ConfigSourceClient configClient) { this.configSource = source; supervisor = new Supervisor(new Transport("proxy-server", JRT_TRANSPORT_THREADS)).useSmallBuffers(); - log.log(Level.FINE, "Using config source '" + source); + log.log(Level.FINE, () -> "Using config source '" + source); this.memoryCache = memoryCache; this.rpcServer = createRpcServer(spec); this.configClient = (configClient == null) ? createRpcClient(rpcServer, source, memoryCache) : configClient; diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/CachedFilesMaintainer.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/CachedFilesMaintainer.java index 247ef8a4dbf..27790eedec7 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/CachedFilesMaintainer.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/CachedFilesMaintainer.java @@ -63,7 +63,7 @@ class CachedFilesMaintainer implements Runnable { File[] files = directory.listFiles(); if (files != null) filesOnDisk.addAll(Arrays.stream(files).map(File::getName).collect(Collectors.toSet())); - log.log(Level.FINE, "Files on disk (in " + directory + "): " + filesOnDisk); + log.log(Level.FINE, () -> "Files on disk (in " + directory + "): " + filesOnDisk); Set<String> filesToDelete = filesOnDisk .stream() diff --git a/config/src/main/java/com/yahoo/config/subscription/impl/FileConfigSubscription.java b/config/src/main/java/com/yahoo/config/subscription/impl/FileConfigSubscription.java index 365f6a4d4c5..ce375f9fdbf 100644 --- a/config/src/main/java/com/yahoo/config/subscription/impl/FileConfigSubscription.java +++ b/config/src/main/java/com/yahoo/config/subscription/impl/FileConfigSubscription.java @@ -38,12 +38,12 @@ public class FileConfigSubscription<T extends ConfigInstance> extends ConfigSubs public boolean nextConfig(long timeout) { if (!file.exists() && !file.isFile()) throw new IllegalArgumentException("Not a file: "+file); if (checkReloaded()) { - log.log(FINE, "User forced config reload at " + System.currentTimeMillis()); + log.log(FINE, () -> "User forced config reload at " + System.currentTimeMillis()); // User forced reload setConfigIfChanged(updateConfig()); ConfigState<T> configState = getConfigState(); - log.log(FINE, "Config updated at " + System.currentTimeMillis() + ", changed: " + configState.isConfigChanged()); - log.log(FINE, "Config: " + configState.getConfig().toString()); + log.log(FINE, () -> "Config updated at " + System.currentTimeMillis() + ", changed: " + configState.isConfigChanged()); + log.log(FINE, () -> "Config: " + configState.getConfig().toString()); return true; } if (file.lastModified()!=ts) { diff --git a/configserver-client/src/main/java/ai/vespa/hosted/client/AbstractConfigServerClient.java b/configserver-client/src/main/java/ai/vespa/hosted/client/AbstractConfigServerClient.java index 2e5e445d63a..81970d47bc7 100644 --- a/configserver-client/src/main/java/ai/vespa/hosted/client/AbstractConfigServerClient.java +++ b/configserver-client/src/main/java/ai/vespa/hosted/client/AbstractConfigServerClient.java @@ -71,7 +71,7 @@ public abstract class AbstractConfigServerClient implements ConfigServerClient { log.log(WARNING, "Cannot retry " + request + " as entity is not repeatable"); break; } - log.log(FINE, request + " failed; will retry", e.getCause()); + log.log(FINE, e.getCause(), () -> request + " failed; will retry"); } } if (thrown != null) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/ApplicationRepository.java b/configserver/src/main/java/com/yahoo/vespa/config/server/ApplicationRepository.java index 536d8894526..9c6786886ef 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/ApplicationRepository.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/ApplicationRepository.java @@ -462,12 +462,12 @@ public class ApplicationRepository implements com.yahoo.config.provision.Deploye static void checkIfActiveHasChanged(Session session, Session activeSession, boolean ignoreStaleSessionFailure) { long activeSessionAtCreate = session.getActiveSessionAtCreate(); - log.log(Level.FINE, activeSession.logPre() + "active session id at create time=" + activeSessionAtCreate); + log.log(Level.FINE, () -> activeSession.logPre() + "active session id at create time=" + activeSessionAtCreate); if (activeSessionAtCreate == 0) return; // No active session at create time long sessionId = session.getSessionId(); long activeSessionSessionId = activeSession.getSessionId(); - log.log(Level.FINE, activeSession.logPre() + "sessionId=" + sessionId + + log.log(Level.FINE, () -> activeSession.logPre() + "sessionId=" + sessionId + ", current active session=" + activeSessionSessionId); if (activeSession.isNewerThan(activeSessionAtCreate) && activeSessionSessionId != sessionId) { @@ -579,17 +579,17 @@ public class ApplicationRepository implements com.yahoo.config.provision.Deploye } public List<String> deleteUnusedFiledistributionReferences(File fileReferencesPath, Duration keepFileReferences) { - log.log(Level.FINE, "Keep unused file references for " + keepFileReferences); + log.log(Level.FINE, () -> "Keep unused file references for " + keepFileReferences); if (!fileReferencesPath.isDirectory()) throw new RuntimeException(fileReferencesPath + " is not a directory"); Set<String> fileReferencesInUse = getFileReferencesInUse(); - log.log(Level.FINE, "File references in use : " + fileReferencesInUse); + log.log(Level.FINE, () -> "File references in use : " + fileReferencesInUse); List<String> candidates = sortedUnusedFileReferences(fileReferencesPath, fileReferencesInUse, keepFileReferences); // Do not delete the newest ones List<String> fileReferencesToDelete = candidates.subList(0, Math.max(0, candidates.size() - 5)); if (fileReferencesToDelete.size() > 0) { - log.log(Level.FINE, "Will delete file references not in use: " + fileReferencesToDelete); + log.log(Level.FINE, () -> "Will delete file references not in use: " + fileReferencesToDelete); fileReferencesToDelete.forEach(fileReference -> { File file = new File(fileReferencesPath, fileReference); if ( ! IOUtils.recursiveDeleteDir(file)) @@ -619,7 +619,7 @@ public class ApplicationRepository implements com.yahoo.config.provision.Deploye private List<String> sortedUnusedFileReferences(File fileReferencesPath, Set<String> fileReferencesInUse, Duration keepFileReferences) { Set<String> fileReferencesOnDisk = getFileReferencesOnDisk(fileReferencesPath); - log.log(Level.FINE, "File references on disk (in " + fileReferencesPath + "): " + fileReferencesOnDisk); + log.log(Level.FINE, () -> "File references on disk (in " + fileReferencesPath + "): " + fileReferencesOnDisk); Instant instant = Instant.now().minus(keepFileReferences); return fileReferencesOnDisk .stream() diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerBootstrap.java b/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerBootstrap.java index 8a7738bc672..62f3e40cb50 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerBootstrap.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerBootstrap.java @@ -98,7 +98,7 @@ public class ConfigServerBootstrap extends AbstractComponent implements Runnable this.exitIfRedeployingApplicationsFails = exitIfRedeployingApplicationsFails; rpcServerExecutor = Executors.newSingleThreadExecutor(new DaemonThreadFactory("config server RPC server")); - log.log(Level.FINE, "Bootstrap mode: " + mode + ", VIP status mode: " + vipStatusMode); + log.log(Level.FINE, () -> "Bootstrap mode: " + mode + ", VIP status mode: " + vipStatusMode); initializing(vipStatusMode); switch (mode) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerDB.java b/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerDB.java index c788b73720d..8594c7857a9 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerDB.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/ConfigServerDB.java @@ -68,10 +68,10 @@ public class ConfigServerDB { for (String pluginDirectory : pluginDirectories) { bundles.addAll(Bundle.getBundles(new File(pluginDirectory))); } - log.log(Level.FINE, "Found " + bundles.size() + " bundles"); + log.log(Level.FINE, () -> "Found " + bundles.size() + " bundles"); List<Bundle> addedBundles = new ArrayList<>(); for (Bundle bundle : bundles) { - log.log(Level.FINE, "Bundle in " + bundle.getFile().getAbsolutePath() + " appears to contain " + bundle.getDefEntries().size() + " entries"); + log.log(Level.FINE, () -> "Bundle in " + bundle.getFile().getAbsolutePath() + " appears to contain " + bundle.getDefEntries().size() + " entries"); configDefinitionDir.addConfigDefinitionsFromBundle(bundle, addedBundles); addedBundles.add(bundle); } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/application/Application.java b/configserver/src/main/java/com/yahoo/vespa/config/server/application/Application.java index 8e98bf5884b..baded957475 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/application/Application.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/application/Application.java @@ -105,16 +105,12 @@ public class Application implements ModelResult { defMd5 = ConfigUtils.getDefMd5(req.getDefContent().asList()); } ConfigCacheKey cacheKey = new ConfigCacheKey(configKey, defMd5); - if (logDebug()) { - debug("Resolving config " + cacheKey); - } + log.log(Level.FINE, () -> TenantRepository.logPre(getId()) + ("Resolving config " + cacheKey)); if (useCache(req)) { ConfigResponse config = cache.get(cacheKey); if (config != null) { - if (logDebug()) { - debug("Found config " + cacheKey + " in cache"); - } + log.log(Level.FINE, () -> TenantRepository.logPre(getId()) + ("Found config " + cacheKey + " in cache")); metricUpdater.incrementProcTime(System.currentTimeMillis() - start); return config; } @@ -125,9 +121,7 @@ public class Application implements ModelResult { metricUpdater.incrementFailedRequests(); throw new UnknownConfigDefinitionException("Unable to find config definition for '" + configKey.getNamespace() + "." + configKey.getName()); } - if (logDebug()) { - debug("Resolving " + configKey + " with config definition " + def); - } + log.log(Level.FINE, () -> TenantRepository.logPre(getId()) + ("Resolving " + configKey + " with config definition " + def)); ConfigInstance.Builder builder; ConfigPayload payload; @@ -174,27 +168,15 @@ public class Application implements ModelResult { return !request.noCache(); } - private boolean logDebug() { - return log.isLoggable(Level.FINE); - } - - private void debug(String message) { - log.log(Level.FINE, TenantRepository.logPre(getId()) + message); - } - private ConfigDefinition getTargetDef(GetConfigRequest req) { ConfigKey<?> configKey = req.getConfigKey(); DefContent def = req.getDefContent(); ConfigDefinitionKey configDefinitionKey = new ConfigDefinitionKey(configKey.getName(), configKey.getNamespace()); if (def.isEmpty()) { - if (logDebug()) { - debug("No config schema in request for " + configKey); - } + log.log(Level.FINE, () -> TenantRepository.logPre(getId()) + ("No config schema in request for " + configKey)); return cache.getDef(configDefinitionKey); } else { - if (logDebug()) { - debug("Got config schema from request, length:" + def.asList().size() + " : " + configKey); - } + log.log(Level.FINE, () -> TenantRepository.logPre(getId()) + ("Got config schema from request, length:" + def.asList().size() + " : " + configKey)); return new ConfigDefinition(configKey.getName(), def.asStringArray()); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/application/CompressedApplicationInputStream.java b/configserver/src/main/java/com/yahoo/vespa/config/server/application/CompressedApplicationInputStream.java index dae5c6aecef..858731b5a89 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/application/CompressedApplicationInputStream.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/application/CompressedApplicationInputStream.java @@ -89,23 +89,23 @@ public class CompressedApplicationInputStream implements AutoCloseable { } private void decompressInto(File application) throws IOException { - log.log(Level.FINE, "Application is in " + application.getAbsolutePath()); + log.log(Level.FINE, () -> "Application is in " + application.getAbsolutePath()); int entries = 0; ArchiveEntry entry; while ((entry = ais.getNextEntry()) != null) { - log.log(Level.FINE, "Unpacking " + entry.getName()); + log.log(Level.FINE, "Unpacking %s", entry.getName()); File outFile = new File(application, entry.getName()); // FIXME/TODO: write more tests that break this logic. I have a feeling it is not very robust. if (entry.isDirectory()) { if (!(outFile.exists() && outFile.isDirectory())) { - log.log(Level.FINE, "Creating dir: " + outFile.getAbsolutePath()); + log.log(Level.FINE, () -> "Creating dir: " + outFile.getAbsolutePath()); boolean res = outFile.mkdirs(); if (!res) { log.log(Level.WARNING, "Could not create dir " + entry.getName()); } } } else { - log.log(Level.FINE, "Creating output file: " + outFile.getAbsolutePath()); + log.log(Level.FINE, () -> "Creating output file: " + outFile.getAbsolutePath()); // Create parent dir if necessary String parent = outFile.getParent(); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/application/PermanentApplicationPackage.java b/configserver/src/main/java/com/yahoo/vespa/config/server/application/PermanentApplicationPackage.java index ac994e8405d..a028f92d681 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/application/PermanentApplicationPackage.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/application/PermanentApplicationPackage.java @@ -25,7 +25,7 @@ public class PermanentApplicationPackage { File app = new File(getDefaults().underVespaHome(config.applicationDirectory())); applicationPackage = Optional.ofNullable(app.exists() ? FilesApplicationPackage.fromFile(app) : null); if (applicationPackage.isPresent()) { - log.log(Level.FINE, "Detected permanent application package in '" + + log.log(Level.FINE, () -> "Detected permanent application package in '" + getDefaults().underVespaHome(config.applicationDirectory()) + "'. This might add extra services to config models"); } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/application/TenantApplications.java b/configserver/src/main/java/com/yahoo/vespa/config/server/application/TenantApplications.java index eb179d2d9aa..dd514e0d843 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/application/TenantApplications.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/application/TenantApplications.java @@ -184,7 +184,7 @@ public class TenantApplications implements RequestHandler, HostValidator<Applica /* A new application is added when a session is added, @see {@link com.yahoo.vespa.config.server.session.SessionRepository#childEvent(CuratorFramework, PathChildrenCacheEvent)} */ ApplicationId applicationId = ApplicationId.fromSerializedForm(Path.fromString(event.getData().getPath()).getName()); - log.log(Level.FINE, TenantRepository.logPre(applicationId) + "Application added: " + applicationId); + log.log(Level.FINE, () -> TenantRepository.logPre(applicationId) + "Application added: " + applicationId); break; // Event CHILD_REMOVED will be triggered on all config servers if deleteApplication() above is called on one of them case CHILD_REMOVED: @@ -241,7 +241,7 @@ public class TenantApplications implements RequestHandler, HostValidator<Applica // (when getting event from zookeeper to remove application, // the lock should be held by the thread that causes the event to happen) public void removeApplication(ApplicationId applicationId) { - log.log(Level.FINE, "Removing application " + applicationId); + log.log(Level.FINE, () -> "Removing application " + applicationId); if (exists(applicationId)) { log.log(Level.INFO, "Tried removing application " + applicationId + ", but it seems to have been deployed again"); return; @@ -491,7 +491,7 @@ public class TenantApplications implements RequestHandler, HostValidator<Applica private void logBarrierCompleted(List<String> respondents, Instant startTime) { Duration duration = Duration.between(startTime, Instant.now()); Level level = (duration.minus(Duration.ofSeconds(5))).isNegative() ? Level.FINE : Level.INFO; - log.log(level, barrierCompletedMessage(respondents, duration)); + log.log(level, () -> barrierCompletedMessage(respondents, duration)); } private String barrierCompletedMessage(List<String> respondents, Duration duration) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDirectory.java b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDirectory.java index 07a686a63bd..f7ba895666b 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDirectory.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDirectory.java @@ -80,7 +80,7 @@ public class FileDirectory { if (file.isDirectory()) { return Files.walk(file.toPath(), 100).map(path -> { try { - log.log(Level.FINE, "Calculating hash for '" + path + "'"); + log.log(Level.FINE, () -> "Calculating hash for '" + path + "'"); return hash(path.toFile(), hasher); } catch (IOException e) { log.log(Level.WARNING, "Failed getting hash from '" + path + "'"); @@ -141,15 +141,15 @@ public class FileDirectory { File destination = new File(tempDestinationDir.toFile(), source.getName()); if (!destinationDir.exists()) { destinationDir.mkdir(); - log.log(Level.FINE, "file reference ' " + reference.value() + "', source: " + source.getAbsolutePath() ); + log.log(Level.FINE, () -> "file reference ' " + reference.value() + "', source: " + source.getAbsolutePath() ); if (source.isDirectory()) { - log.log(Level.FINE, "Copying source " + source.getAbsolutePath() + " to " + destination.getAbsolutePath()); + log.log(Level.FINE, () -> "Copying source " + source.getAbsolutePath() + " to " + destination.getAbsolutePath()); IOUtils.copyDirectory(source, destination, -1); } else { copyFile(source, destination); } if (!destinationDir.exists()) { - log.log(Level.FINE, "Moving from " + tempDestinationDir + " to " + destinationDir.getAbsolutePath()); + log.log(Level.FINE, () -> "Moving from " + tempDestinationDir + " to " + destinationDir.getAbsolutePath()); if ( ! tempDestinationDir.toFile().renameTo(destinationDir)) { log.log(Level.WARNING, "Failed moving '" + tempDestinationDir.toFile().getAbsolutePath() + "' to '" + destination.getAbsolutePath() + "'."); } @@ -166,7 +166,7 @@ public class FileDirectory { private void logfileInfo(File file ) throws IOException { BasicFileAttributes basicFileAttributes = Files.readAttributes(file.toPath(), BasicFileAttributes.class); - log.log(Level.FINE, "Adding file " + file.getAbsolutePath() + " (created " + basicFileAttributes.creationTime() + + log.log(Level.FINE, () -> "Adding file " + file.getAbsolutePath() + " (created " + basicFileAttributes.creationTime() + ", modified " + basicFileAttributes.lastModifiedTime() + ", size " + basicFileAttributes.size() + ")"); } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDistributionImpl.java b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDistributionImpl.java index 56bdeab76b2..2eebbfa4acf 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDistributionImpl.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileDistributionImpl.java @@ -49,7 +49,7 @@ public class FileDistributionImpl implements FileDistribution, RequestWaiter { Request request = new Request("filedistribution.setFileReferencesToDownload"); request.setContext(target); request.parameters().add(new StringArray(fileReferences.stream().map(FileReference::value).toArray(String[]::new))); - log.log(Level.FINE, "Executing " + request.methodName() + " against " + target); + log.log(Level.FINE, () -> "Executing " + request.methodName() + " against " + target); target.invokeAsync(request, rpcTimeout, this); } @@ -58,7 +58,7 @@ public class FileDistributionImpl implements FileDistribution, RequestWaiter { public void handleRequestDone(Request req) { Target target = (Target) req.getContext(); if (req.isError()) { - log.log(Level.FINE, req.methodName() + " failed for " + target + ": " + req.errorCode() + " (" + req.errorMessage() + ")"); + log.log(Level.FINE, () -> req.methodName() + " failed for " + target + ": " + req.errorCode() + " (" + req.errorMessage() + ")"); } if (target != null) target.close(); } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileServer.java b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileServer.java index 66f886a8fcc..c123a0c058f 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileServer.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/filedistribution/FileServer.java @@ -100,7 +100,7 @@ public class FileServer { try { return root.getFile(reference).exists(); } catch (IllegalArgumentException e) { - log.log(Level.FINE, "Failed locating file reference '" + reference + "' with error " + e.toString()); + log.log(Level.FINE, () -> "Failed locating file reference '" + reference + "' with error " + e.toString()); } return false; } @@ -130,7 +130,7 @@ public class FileServer { try { target.receive(fileData, new ReplayStatus(success ? 0 : 1, success ? "OK" : errorDescription)); - log.log(Level.FINE, "Done serving file reference '" + reference.value() + "' with file '" + file.getAbsolutePath() + "'"); + log.log(Level.FINE, () -> "Done serving file reference '" + reference.value() + "' with file '" + file.getAbsolutePath() + "'"); } catch (Exception e) { log.log(Level.WARNING, "Failed serving file reference '" + reference.value() + "': " + Exceptions.toMessageString(e)); } finally { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpGetConfigHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpGetConfigHandler.java index 7458c82942f..b6f2c2e0919 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpGetConfigHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpGetConfigHandler.java @@ -41,7 +41,7 @@ public class HttpGetConfigHandler extends HttpHandler { } private ConfigResponse resolveConfig(HttpConfigRequest request) { - log.log(Level.FINE, "nocache=" + request.noCache()); + log.log(Level.FINE, () -> "nocache=" + request.noCache()); ConfigResponse config = requestHandler.resolveConfig(ApplicationId.defaultId(), request, Optional.empty()); if (config == null) HttpConfigRequest.throwModelNotReady(); return config; diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpHandler.java index e92eb52028b..78a7b8aaa8f 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/HttpHandler.java @@ -32,7 +32,7 @@ public class HttpHandler extends LoggingRequestHandler { @Override public HttpResponse handle(HttpRequest request) { - log.log(Level.FINE, request.getMethod() + " " + request.getUri().toString()); + log.log(Level.FINE, () -> request.getMethod() + " " + request.getUri().toString()); try { switch (request.getMethod()) { case POST: diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/http/SessionContentStatusListResponse.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/SessionContentStatusListResponse.java index 08cda869111..860189a171c 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/SessionContentStatusListResponse.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/SessionContentStatusListResponse.java @@ -25,7 +25,7 @@ class SessionContentStatusListResponse extends SlimeJsonResponse { element.setString("status", f.getMetaData().getStatus()); element.setString("md5", f.getMetaData().getMd5()); element.setString("name", urlBase + f.getPath()); - log.log(Level.FINE, "Adding file " + urlBase + f.getPath()); + log.log(Level.FINE, () -> "Adding file " + urlBase + f.getPath()); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/http/TesterClient.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/TesterClient.java index 4292a0806c2..43552d317cd 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/TesterClient.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/TesterClient.java @@ -65,7 +65,7 @@ public class TesterClient { } private HttpResponse execute(HttpUriRequest request, String messageIfRequestFails) { - logger.log(Level.FINE, "Sending request to tester container " + request.getURI().toString()); + logger.log(Level.FINE, () -> "Sending request to tester container " + request.getURI().toString()); try { return new ProxyResponse(httpClient.execute(request)); } catch (IOException e) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HttpGetConfigHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HttpGetConfigHandler.java index b4ce833cb75..1787431e841 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HttpGetConfigHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HttpGetConfigHandler.java @@ -41,7 +41,7 @@ public class HttpGetConfigHandler extends HttpHandler { } private ConfigResponse resolveConfig(HttpConfigRequest request, RequestHandler requestHandler) { - log.log(Level.FINE, "nocache=" + request.noCache()); + log.log(Level.FINE, () -> "nocache=" + request.noCache()); ConfigResponse config = requestHandler.resolveConfig(request.getApplicationId(), request, Optional.empty()); if (config == null) HttpConfigRequest.throwModelNotReady(); return config; diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ActivatedModelsBuilder.java b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ActivatedModelsBuilder.java index da720ca8cb9..5c0207878f1 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ActivatedModelsBuilder.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ActivatedModelsBuilder.java @@ -102,8 +102,8 @@ public class ActivatedModelsBuilder extends ModelsBuilder<Application> { Version wantedNodeVespaVersion, Optional<AllocatedHosts> ignored // Ignored since we have this in the app package for activated models ) { - log.log(Level.FINE, String.format("Loading model version %s for session %s application %s", - modelFactory.version(), applicationGeneration, applicationId)); + log.log(Level.FINE, () -> String.format("Loading model version %s for session %s application %s", + modelFactory.version(), applicationGeneration, applicationId)); ModelContext.Properties modelContextProperties = createModelContextProperties(applicationId); Provisioned provisioned = new Provisioned(); ModelContext modelContext = new ModelContextImpl( diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ModelsBuilder.java b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ModelsBuilder.java index b80037eef56..227e9c6a977 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ModelsBuilder.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/ModelsBuilder.java @@ -81,7 +81,7 @@ public abstract class ModelsBuilder<MODELRESULT extends ModelResult> { SettableOptional<AllocatedHosts> allocatedHosts, Instant now) { Instant start = Instant.now(); - log.log(Level.FINE, "Will build models for " + applicationId); + log.log(Level.FINE, () -> "Will build models for " + applicationId); Set<Version> versions = modelFactoryRegistry.allVersions(); // If the application specifies a major, skip models on a newer major @@ -133,7 +133,7 @@ public abstract class ModelsBuilder<MODELRESULT extends ModelResult> { } } } - log.log(Level.FINE, "Done building models for " + applicationId + ". Built models for versions " + + log.log(Level.FINE, () -> "Done building models for " + applicationId + ". Built models for versions " + allApplicationModels.stream() .map(result -> result.getModel().version()) .map(Version::toFullString) diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/PreparedModelsBuilder.java b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/PreparedModelsBuilder.java index 4dd3171fbf1..7a0a261c7ad 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/PreparedModelsBuilder.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/modelfactory/PreparedModelsBuilder.java @@ -91,7 +91,7 @@ public class PreparedModelsBuilder extends ModelsBuilder<PreparedModelsBuilder.P Version wantedNodeVespaVersion, Optional<AllocatedHosts> allocatedHosts) { Version modelVersion = modelFactory.version(); - log.log(Level.FINE, "Building model " + modelVersion + " for " + applicationId); + log.log(Level.FINE, () -> "Building model " + modelVersion + " for " + applicationId); // Use empty on non-hosted systems, use already allocated hosts if available, create connection to a host provisioner otherwise Provisioned provisioned = new Provisioned(); @@ -117,13 +117,13 @@ public class PreparedModelsBuilder extends ModelsBuilder<PreparedModelsBuilder.P private ModelCreateResult createAndValidateModel(ModelFactory modelFactory, ApplicationId applicationId, Version modelVersion, ModelContext modelContext) { log.log(properties.zone().system().isCd() ? Level.INFO : Level.FINE, - "Create and validate model " + modelVersion + " for " + applicationId + ", previous model is " + + () -> "Create and validate model " + modelVersion + " for " + applicationId + ", previous model is " + modelOf(modelVersion).map(Model::version).map(Version::toFullString).orElse("non-existing")); ValidationParameters validationParameters = new ValidationParameters(params.ignoreValidationErrors() ? IgnoreValidationErrors.TRUE : IgnoreValidationErrors.FALSE); ModelCreateResult result = modelFactory.createAndValidateModel(modelContext, validationParameters); validateModelHosts(hostValidator, applicationId, result.getModel()); - log.log(Level.FINE, "Done building model " + modelVersion + " for " + applicationId); + log.log(Level.FINE, () -> "Done building model " + modelVersion + " for " + applicationId); params.getTimeoutBudget().assertNotTimedOut(() -> "prepare timed out after building model " + modelVersion + " (timeout " + params.getTimeoutBudget().timeout() + "): " + applicationId); return result; diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/monitoring/Metrics.java b/configserver/src/main/java/com/yahoo/vespa/config/server/monitoring/Metrics.java index e3516535b46..dca58665f57 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/monitoring/Metrics.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/monitoring/Metrics.java @@ -57,7 +57,7 @@ public class Metrics extends AbstractComponent implements MetricUpdaterFactory, procTimeCounter = createCounter("procTime", statistics); if (createZkMetricUpdater) { - log.log(Level.FINE, "Metric update interval is " + healthMonitorConfig.snapshot_interval() + " seconds"); + log.log(Level.FINE, () -> "Metric update interval is " + healthMonitorConfig.snapshot_interval() + " seconds"); long intervalMs = (long) (healthMonitorConfig.snapshot_interval() * 1000); executorService = Optional.of(new ScheduledThreadPoolExecutor(1, new DaemonThreadFactory("configserver-metrics"))); executorService.get().scheduleAtFixedRate(this, 20000, intervalMs, TimeUnit.MILLISECONDS); @@ -130,9 +130,9 @@ public class Metrics extends AbstractComponent implements MetricUpdaterFactory, @Override public void run() { for (MetricUpdater metricUpdater : metricUpdaters.values()) { - log.log(Level.FINE, "Running metric updater for static values for " + metricUpdater.getDimensions()); + log.log(Level.FINE, () -> "Running metric updater for static values for " + metricUpdater.getDimensions()); for (Map.Entry<String, Number> fixedMetric : metricUpdater.getStaticMetrics().entrySet()) { - log.log(Level.FINE, "Setting " + fixedMetric.getKey()); + log.log(Level.FINE, () -> "Setting " + fixedMetric.getKey()); metric.set(fixedMetric.getKey(), fixedMetric.getValue(), metricUpdater.getMetricContext()); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/DelayedConfigResponses.java b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/DelayedConfigResponses.java index 9820eac2f30..960efc876ee 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/DelayedConfigResponses.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/DelayedConfigResponses.java @@ -171,7 +171,7 @@ public class DelayedConfigResponses { */ final void delayResponse(JRTServerConfigRequest request, GetConfigContext context) { if (request.isDelayedResponse()) { - log.log(Level.FINE, context.logPre()+"Request already delayed"); + log.log(Level.FINE, () -> context.logPre()+"Request already delayed"); } else { createQueueIfNotExists(context); BlockingQueue<DelayedConfigResponse> delayedResponsesQueue = delayedResponses.get(context.applicationId()); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/GetConfigProcessor.java b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/GetConfigProcessor.java index 010640b967f..637fc421457 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/GetConfigProcessor.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/GetConfigProcessor.java @@ -49,7 +49,7 @@ class GetConfigProcessor implements Runnable { Request req = request.getRequest(); if (req.isError()) { Level logLevel = (req.errorCode() == ErrorCode.APPLICATION_NOT_LOADED) ? Level.FINE : Level.INFO; - log.log(logLevel, logPre + req.errorMessage()); + log.log(logLevel, () -> logPre + req.errorMessage()); } rpcServer.respond(request); } @@ -177,7 +177,7 @@ class GetConfigProcessor implements Runnable { private void debugLog(Trace trace, String message) { if (logDebug(trace)) { - log.log(Level.FINE, logPre + message); + log.log(Level.FINE, () -> logPre + message); trace.trace(RpcServer.TRACELEVEL_DEBUG, logPre + message); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/RpcServer.java b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/RpcServer.java index 370ae72bbbd..5b9b3077008 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/RpcServer.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/RpcServer.java @@ -280,7 +280,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { responsesSent++; } } else { - log.log(Level.FINE, logPre + "Timer already cancelled or finished or never scheduled"); + log.log(Level.FINE, () -> logPre + "Timer already cancelled or finished or never scheduled"); } } @@ -292,7 +292,8 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { } } - log.log(Level.FINE, logPre + "Finished reloading " + responsesSent + " requests"); + if (log.isLoggable(Level.FINE)) + log.log(Level.FINE, logPre + "Finished reloading " + responsesSent + " requests"); } private void logRequestDebug(Level level, String message, JRTServerConfigRequest request) { @@ -303,7 +304,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { @Override public void hostsUpdated(ApplicationId applicationId, Collection<String> newHosts) { - log.log(Level.FINE, "Updating hosts in tenant host registry '" + hostRegistry + "' with " + newHosts); + log.log(Level.FINE, () -> "Updating hosts in tenant host registry '" + hostRegistry + "' with " + newHosts); hostRegistry.update(applicationId, newHosts); } @@ -338,7 +339,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { if (GetConfigProcessor.logDebug(trace)) { String message = "Did not find tenant for host '" + hostname + "', using " + TenantName.defaultName(); log.log(Level.FINE, message); - log.log(Level.FINE, "hosts in host registry: " + hostRegistry.getAllHosts()); + log.log(Level.FINE, () -> "hosts in host registry: " + hostRegistry.getAllHosts()); trace.trace(6, message); } return Optional.empty(); @@ -424,7 +425,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { @Override public void onTenantDelete(TenantName tenant) { - log.log(Level.FINE, TenantRepository.logPre(tenant) + + log.log(Level.FINE, () -> TenantRepository.logPre(tenant) + "Tenant deleted, removing request handler and cleaning host registry"); tenants.remove(tenant); hostRegistry.removeHostsForKey(tenant); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionRepository.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionRepository.java index 181ed880fd7..cb46d65c4c5 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionRepository.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionRepository.java @@ -457,9 +457,9 @@ public class SessionRepository { void confirmUpload(Session session) { CompletionWaiter waiter = session.getSessionZooKeeperClient().getUploadWaiter(); long sessionId = session.getSessionId(); - log.log(Level.FINE, "Notifying upload waiter for session " + sessionId); + log.log(Level.FINE, () -> "Notifying upload waiter for session " + sessionId); notifyCompletion(waiter); - log.log(Level.FINE, "Done notifying upload for session " + sessionId); + log.log(Level.FINE, () -> "Done notifying upload for session " + sessionId); } void notifyCompletion(CompletionWaiter completionWaiter) { @@ -476,7 +476,7 @@ public class SessionRepository { KeeperException.NodeExistsException.class); Class<? extends Throwable> exceptionClass = e.getCause().getClass(); if (acceptedExceptions.contains(exceptionClass)) - log.log(Level.FINE, "Not able to notify completion for session (" + completionWaiter + ")," + + log.log(Level.FINE, () -> "Not able to notify completion for session (" + completionWaiter + ")," + " node " + (exceptionClass.equals(KeeperException.NoNodeException.class) ? "has been deleted" : "already exists")); @@ -726,7 +726,7 @@ public class SessionRepository { } catch (IllegalArgumentException e) { // We cannot be guaranteed that the file reference exists (it could be that it has not // been downloaded yet), and e.g when bootstrapping we cannot throw an exception in that case - log.log(Level.FINE, "File reference for session id " + sessionId + ": " + fileReference + " not found in " + fileDirectory); + log.log(Level.FINE, () -> "File reference for session id " + sessionId + ": " + fileReference + " not found in " + fileDirectory); return; } ApplicationId applicationId = sessionZKClient.readApplicationId() diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionStateWatcher.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionStateWatcher.java index b27cdbdc341..880519b3d61 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionStateWatcher.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionStateWatcher.java @@ -91,8 +91,9 @@ public class SessionStateWatcher { ChildData node = fileCache.getCurrentData(); if (node != null) { newStatus = Status.parse(Utf8.toString(node.getData())); - log.log(Level.FINE, session.logPre() + "Session change: Session " - + session.getSessionId() + " changed status to " + newStatus.name()); + if (log.isLoggable(Level.FINE)) + log.log(Level.FINE, session.logPre() + "Session change: Session " + + session.getSessionId() + " changed status to " + newStatus.name()); sessionStatusChanged(newStatus); } } catch (Exception e) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRepository.java b/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRepository.java index 52d1484897c..1c1d2534341 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRepository.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRepository.java @@ -318,7 +318,7 @@ public class TenantRepository { if (tenants.containsKey(tenantName)) return getTenant(tenantName); Instant start = Instant.now(); - log.log(Level.FINE, "Adding tenant '" + tenantName); + log.log(Level.FINE, () -> "Adding tenant '" + tenantName); TenantApplications applicationRepo = new TenantApplications(tenantName, curator, diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/InitializedCounter.java b/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/InitializedCounter.java index 6a1eaba34a6..216c9edd0d0 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/InitializedCounter.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/InitializedCounter.java @@ -27,7 +27,7 @@ public class InitializedCounter { } private void initializeCounterValue(Long latestSessionId) { - log.log(Level.FINE, "path=" + sessionsDirPath + ", current=" + latestSessionId); + log.log(Level.FINE, () -> "path=" + sessionsDirPath + ", current=" + latestSessionId); if (latestSessionId != null) { counter.initialize(latestSessionId); } else { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/ZKApplicationFile.java b/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/ZKApplicationFile.java index e598a73ebfb..2a933ddf3e5 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/ZKApplicationFile.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/zookeeper/ZKApplicationFile.java @@ -148,7 +148,7 @@ class ZKApplicationFile extends ApplicationFile { StringWriter writer = new StringWriter(); try { mapper.writeValue(writer, new MetaData(status, input == null ? "" : ConfigUtils.getMd5(input))); - log.log(Level.FINE, "Writing meta file to " + metaPath); + log.log(Level.FINE, () -> "Writing meta file to " + metaPath); zkApp.putData(metaPath, writer.toString()); } catch (IOException e) { throw new RuntimeException("Error writing meta file to " + metaPath, e); @@ -157,7 +157,7 @@ class ZKApplicationFile extends ApplicationFile { public MetaData getMetaData() { String metaPath = getZKPath(getMetaPath()); - log.log(Level.FINE, "Getting metadata for " + metaPath); + log.log(Level.FINE, () -> "Getting metadata for " + metaPath); if (!zkApp.exists(getZKPath(path))) { if (zkApp.exists(metaPath)) { return getMetaDataFromZk(metaPath); diff --git a/container-core/src/main/java/com/yahoo/container/core/config/HandlersConfigurerDi.java b/container-core/src/main/java/com/yahoo/container/core/config/HandlersConfigurerDi.java index 236602b7767..9f6f5cf7ea1 100644 --- a/container-core/src/main/java/com/yahoo/container/core/config/HandlersConfigurerDi.java +++ b/container-core/src/main/java/com/yahoo/container/core/config/HandlersConfigurerDi.java @@ -176,7 +176,7 @@ public class HandlersConfigurerDi { ComponentRegistry<RequestHandler> requestHandlerRegistry, ComponentRegistry<ClientProvider> clientProviderRegistry, ComponentRegistry<ServerProvider> serverProviderRegistry) { - log.log(Level.FINE, "RegistriesHack.init " + System.identityHashCode(this)); + log.log(Level.FINE, () -> "RegistriesHack.init " + System.identityHashCode(this)); vespaContainer.setComponentRegistry(allComponents); vespaContainer.setRequestHandlerRegistry(requestHandlerRegistry); diff --git a/container-core/src/main/java/com/yahoo/container/di/ConfigRetriever.java b/container-core/src/main/java/com/yahoo/container/di/ConfigRetriever.java index a7ff6c46a8b..33771bd0c1e 100644 --- a/container-core/src/main/java/com/yahoo/container/di/ConfigRetriever.java +++ b/container-core/src/main/java/com/yahoo/container/di/ConfigRetriever.java @@ -64,7 +64,7 @@ public final class ConfigRetriever { throw new IllegalArgumentException( "Component config keys [" + componentConfigKeys + "] overlaps with bootstrap config keys [" + bootstrapKeys + "]"); } - log.log(FINE, "getConfigsOnce: " + componentConfigKeys); + log.log(FINE, () -> "getConfigsOnce: " + componentConfigKeys); Set<ConfigKey<? extends ConfigInstance>> allKeys = new HashSet<>(componentConfigKeys); allKeys.addAll(bootstrapKeys); @@ -75,20 +75,20 @@ public final class ConfigRetriever { private Optional<ConfigSnapshot> getConfigsOptional(long leastGeneration, boolean isInitializing) { long newestComponentGeneration = componentSubscriber.waitNextGeneration(isInitializing); - log.log(FINE, "getConfigsOptional: new component generation: " + newestComponentGeneration); + log.log(FINE, () -> "getConfigsOptional: new component generation: " + newestComponentGeneration); // leastGeneration is only used to ensure newer generation when the previous generation was invalidated due to an exception if (newestComponentGeneration < leastGeneration) { return Optional.empty(); } else if (bootstrapSubscriber.generation() < newestComponentGeneration) { long newestBootstrapGeneration = bootstrapSubscriber.waitNextGeneration(isInitializing); - log.log(FINE, "getConfigsOptional: new bootstrap generation: " + bootstrapSubscriber.generation()); + log.log(FINE, () -> "getConfigsOptional: new bootstrap generation: " + bootstrapSubscriber.generation()); Optional<ConfigSnapshot> bootstrapConfig = bootstrapConfigIfChanged(); if (bootstrapConfig.isPresent()) { return bootstrapConfig; } else { if (newestBootstrapGeneration == newestComponentGeneration) { - log.log(FINE, "Got new components configs with unchanged bootstrap configs."); + log.log(FINE, () -> "Got new components configs with unchanged bootstrap configs."); return componentsConfigIfChanged(); } else { // This should not be a normal case, and hence a warning to allow investigation. @@ -131,7 +131,7 @@ public final class ConfigRetriever { componentSubscriber.close(); componentSubscriberKeys = keys; try { - log.log(FINE, "Setting up new component subscriber for keys: " + keys); + log.log(FINE, () -> "Setting up new component subscriber for keys: " + keys); componentSubscriber = subscribe.apply(keys); } catch (Throwable e) { log.log(Level.WARNING, "Failed setting up subscriptions for component configs: " + e.getMessage()); diff --git a/container-core/src/main/java/com/yahoo/container/di/Container.java b/container-core/src/main/java/com/yahoo/container/di/Container.java index 82c7f65bc2a..a91aa6eb588 100644 --- a/container-core/src/main/java/com/yahoo/container/di/Container.java +++ b/container-core/src/main/java/com/yahoo/container/di/Container.java @@ -95,8 +95,9 @@ public class Container { while (true) { snapshot = configurer.getConfigs(graph.configKeys(), leastGeneration, isInitializing); - log.log(FINE, String.format("createNewGraph:\n" + "graph.configKeys = %s\n" + "graph.generation = %s\n" + "snapshot = %s\n", - graph.configKeys(), graph.generation(), snapshot)); + if (log.isLoggable(FINE)) + log.log(FINE, String.format("createNewGraph:\n" + "graph.configKeys = %s\n" + "graph.generation = %s\n" + "snapshot = %s\n", + graph.configKeys(), graph.generation(), snapshot)); if (snapshot instanceof BootstrapConfigs) { if (getBootstrapGeneration() <= previousConfigGeneration) { @@ -104,7 +105,7 @@ public class Container { "Got bootstrap configs out of sequence for old config generation %d.\n" + "Previous config generation is %d", getBootstrapGeneration(), previousConfigGeneration)); } - log.log(FINE, "Got new bootstrap generation\n" + configGenerationsString()); + log.log(FINE, () -> "Got new bootstrap generation\n" + configGenerationsString()); if (graph.generation() == 0) { platformBundles = getConfig(platformBundlesConfigKey, snapshot.configs()).bundlePaths(); @@ -123,7 +124,7 @@ public class Container { break; } } - log.log(FINE, "Got components configs,\n" + configGenerationsString()); + log.log(FINE, () -> "Got components configs,\n" + configGenerationsString()); return createAndConfigureComponentsGraph(snapshot.configs(), fallbackInjector); } diff --git a/container-core/src/main/java/com/yahoo/container/di/componentgraph/cycle/CycleFinder.java b/container-core/src/main/java/com/yahoo/container/di/componentgraph/cycle/CycleFinder.java index 327949bb8d0..3aa8ae56817 100644 --- a/container-core/src/main/java/com/yahoo/container/di/componentgraph/cycle/CycleFinder.java +++ b/container-core/src/main/java/com/yahoo/container/di/componentgraph/cycle/CycleFinder.java @@ -58,7 +58,7 @@ public class CycleFinder<T> { if (visitDepthFirst(vertex, new ArrayList<>(singletonList(vertex)))) { if (cycle == null) throw new IllegalStateException("Null cycle - this should never happen"); if (cycle.isEmpty()) throw new IllegalStateException("Empty cycle - this should never happen"); - log.log(FINE, "Cycle detected: " + cycle); + log.log(FINE, () -> "Cycle detected: " + cycle); return cycle; } } @@ -68,7 +68,7 @@ public class CycleFinder<T> { private boolean visitDepthFirst(T vertex, List<T> path) { colors.put(vertex, GRAY); - log.log(FINE, "Vertex start " + vertex + " - colors: " + colors + " - path: " + path); + log.log(FINE, () -> "Vertex start " + vertex + " - colors: " + colors + " - path: " + path); for (T adjacent : graph.getAdjacent(vertex)) { path.add(adjacent); if (colors.get(adjacent) == GRAY) { @@ -81,7 +81,7 @@ public class CycleFinder<T> { path.remove(adjacent); } colors.put(vertex, BLACK); - log.log(FINE, "Vertex end " + vertex + " - colors: " + colors + " - path: " + path); + log.log(FINE, () -> "Vertex end " + vertex + " - colors: " + colors + " - path: " + path); return false; } diff --git a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyConnectionLogger.java b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyConnectionLogger.java index e7cdb13425f..bbeccb61c8a 100644 --- a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyConnectionLogger.java +++ b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyConnectionLogger.java @@ -153,7 +153,8 @@ class JettyConnectionLogger extends AbstractLifeCycle implements Connection.List public void onResponseBegin(Request request) { handleListenerInvocation("HttpChannel.Listener", "onResponseBegin", "%h", List.of(request), () -> { SocketChannelEndPoint endpoint = findUnderlyingSocketEndpoint(request.getHttpChannel().getEndPoint()); - ConnectionInfo info = Objects.requireNonNull(connectionInfo.get(IdentityKey.of(endpoint))); + ConnectionInfo info = connectionInfo.get(IdentityKey.of(endpoint)); + if (info == null) return; // Connection closed before response started - observed during Jetty server shutdown info.incrementResponses(); }); } diff --git a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java index 65dc1052a78..ba9f1804d34 100644 --- a/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java +++ b/container-search/src/main/java/com/yahoo/search/handler/SearchHandler.java @@ -190,7 +190,7 @@ public class SearchHandler extends LoggingRequestHandler { long numQueriesToTraceOnDebugAfterStartup, Optional<String> hostResponseHeaderKey) { super(executor, metric, true); - log.log(Level.FINE, "SearchHandler.init " + System.identityHashCode(this)); + log.log(Level.FINE, () -> "SearchHandler.init " + System.identityHashCode(this)); this.queryProfileRegistry = queryProfileRegistry; this.executionFactory = executionFactory; diff --git a/container-search/src/main/java/com/yahoo/search/query/rewrite/RewriterUtils.java b/container-search/src/main/java/com/yahoo/search/query/rewrite/RewriterUtils.java index d66aff7bcd7..af73e905f20 100644 --- a/container-search/src/main/java/com/yahoo/search/query/rewrite/RewriterUtils.java +++ b/container-search/src/main/java/com/yahoo/search/query/rewrite/RewriterUtils.java @@ -289,7 +289,7 @@ public class RewriterUtils { * @param msg Log message */ public static void log(Logger logger, String msg) { - logger.log(Level.FINE, logger.getName() + ": " + msg); + logger.log(Level.FINE, () -> logger.getName() + ": " + msg); } /** @@ -303,7 +303,7 @@ public class RewriterUtils { if(query!=null) { query.trace(logger.getName() + ": " + msg, true, TRACELEVEL); } - logger.log(Level.FINE, logger.getName() + ": " + msg); + logger.log(Level.FINE, () -> logger.getName() + ": " + msg); } /** diff --git a/container-search/src/main/java/com/yahoo/vespa/streamingvisitors/VdsVisitor.java b/container-search/src/main/java/com/yahoo/vespa/streamingvisitors/VdsVisitor.java index ef0a60c76c0..7d7b78f7153 100644 --- a/container-search/src/main/java/com/yahoo/vespa/streamingvisitors/VdsVisitor.java +++ b/container-search/src/main/java/com/yahoo/vespa/streamingvisitors/VdsVisitor.java @@ -331,8 +331,8 @@ class VdsVisitor extends VisitorDataHandler implements Visitor { public void doSearch() throws InterruptedException, ParseException, TimeoutException { VisitorSession session = visitorSessionFactory.createVisitorSession(params); try { - if ( !session.waitUntilDone(query.getTimeout())) { - log.log(Level.FINE, "Visitor returned from waitUntilDone without being completed for " + query + " with selection " + params.getDocumentSelection()); + if ( ! session.waitUntilDone(query.getTimeout())) { + log.log(Level.FINE, () -> "Visitor returned from waitUntilDone without being completed for " + query + " with selection " + params.getDocumentSelection()); session.abort(); throw new TimeoutException("Query timed out in " + VdsStreamingSearcher.class.getName()); } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/athenz/impl/AthenzFacade.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/athenz/impl/AthenzFacade.java index 3c035ef01ec..073451f6309 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/athenz/impl/AthenzFacade.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/athenz/impl/AthenzFacade.java @@ -270,7 +270,7 @@ public class AthenzFacade implements AccessControl { } public List<AthenzDomain> getDomainList(String prefix) { - log.log(Level.FINE, String.format("getDomainList(prefix=%s)", prefix)); + log.log(Level.FINE, "getDomainList(prefix=%s)", prefix); return zmsClient.getDomainList(prefix); } @@ -290,7 +290,7 @@ public class AthenzFacade implements AccessControl { } private static void log(String format, Object... args) { - log.log(Level.FINE, String.format(format, args)); + log.log(Level.FINE, format, args); } private String resourceStringPrefix(AthenzDomain tenantDomain) { diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/DeploymentTrigger.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/DeploymentTrigger.java index c602ebd856a..53e88a9a5ac 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/DeploymentTrigger.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/DeploymentTrigger.java @@ -162,7 +162,7 @@ public class DeploymentTrigger { /** Attempts to trigger the given job. */ public void trigger(Job job) { - log.log(Level.FINE, "Triggering " + job); + log.log(Level.FINE, () -> "Triggering " + job); applications().lockApplicationOrThrow(TenantAndApplicationId.from(job.applicationId()), application -> { jobs.start(job.applicationId(), job.jobType, job.versions); applications().store(application.with(job.applicationId().instance(), instance -> diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceForwarder.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceForwarder.java index 4f36e713ba4..d9928bffba4 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceForwarder.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceForwarder.java @@ -78,7 +78,7 @@ public class NameServiceForwarder { "requests. This likely means that the name service is not successfully " + "executing requests"); } - log.log(Level.FINE, "Queueing name service request: " + request); + log.log(Level.FINE, () -> "Queueing name service request: " + request); db.writeNameServiceQueue(queue.with(request, priority).last(maxQueuedRequests)); } } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/ContactInformationMaintainer.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/ContactInformationMaintainer.java index d6733955967..7b846fa288c 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/ContactInformationMaintainer.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/ContactInformationMaintainer.java @@ -39,13 +39,13 @@ public class ContactInformationMaintainer extends ControllerMaintainer { TenantController tenants = controller().tenants(); boolean success = true; for (Tenant tenant : tenants.asList()) { - log.log(FINE, "Updating contact information for " + tenant); + log.log(FINE, () -> "Updating contact information for " + tenant); try { switch (tenant.type()) { case athenz: tenants.lockIfPresent(tenant.name(), LockedTenant.Athenz.class, lockedTenant -> { Contact contact = contactRetriever.getContact(lockedTenant.get().propertyId()); - log.log(FINE, "Contact found for " + tenant + " was " + + log.log(FINE, () -> "Contact found for " + tenant + " was " + (Optional.of(contact).equals(tenant.contact()) ? "un" : "") + "changed"); tenants.store(lockedTenant.with(contact)); }); diff --git a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java index c9b3c4f9b4a..830d66d38f5 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java @@ -200,7 +200,7 @@ public class DocumentProcessingHandler extends AbstractRequestHandler { @Override public void run() { - log.log(Level.FINE, "Submitting after having waited " + delay + " ms in LATER queue: " + processingTask); + log.log(Level.FINE, () -> "Submitting after having waited " + delay + " ms in LATER queue: " + processingTask); processingTask.submit(); } } diff --git a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java index 8b330c13dff..5d5f63d3958 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java @@ -112,8 +112,7 @@ public class DocumentProcessingTask implements Runnable { } else { location = "no processing instance"; } - String errorMsg = processing + " failed, " + location; - log.log(Level.FINE, "Time is up for '" + errorMsg + "'."); + log.log(Level.FINE, () -> "Time is up for '" + processing + " failed, " + location + "'."); requestContext.processingFailed(RequestContext.ErrorCode.ERROR_PROCESSING_FAILURE, "Time is up."); return progress; } @@ -203,7 +202,7 @@ public class DocumentProcessingTask implements Runnable { if (exception != null) { StringWriter backtrace = new StringWriter(); exception.printStackTrace(new PrintWriter(backtrace)); - log.log(Level.FINE, "Failed to process " + processing + ": " + backtrace.toString()); + log.log(Level.FINE, () -> "Failed to process " + processing + ": " + backtrace); } } diff --git a/docproc/src/main/java/com/yahoo/docproc/util/JoinerDocumentProcessor.java b/docproc/src/main/java/com/yahoo/docproc/util/JoinerDocumentProcessor.java index 406fc9a6db9..a91565dcd9c 100644 --- a/docproc/src/main/java/com/yahoo/docproc/util/JoinerDocumentProcessor.java +++ b/docproc/src/main/java/com/yahoo/docproc/util/JoinerDocumentProcessor.java @@ -59,7 +59,7 @@ public class JoinerDocumentProcessor extends DocumentProcessor { if (op instanceof DocumentPut) { innerDocuments.add(((DocumentPut)op).getDocument()); } else { - log.log(Level.FINE, "Skipping: " + op); + log.log(Level.FINE, () -> "Skipping: " + op); } } processing.getDocumentOperations().clear(); diff --git a/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java b/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java index dfc36bfb641..43e9c95fc1d 100644 --- a/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java +++ b/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java @@ -42,8 +42,8 @@ public class SplitterDocumentProcessor extends DocumentProcessor { public Progress process(Processing processing) { if (processing.getDocumentOperations().size() != 1) { //we were given more than one document, return - log.log(Level.FINE, "More than one document given, returning. (Was given " - + processing.getDocumentOperations().size() + " documents)."); + log.log(Level.FINE, () -> "More than one document given, returning. (Was given " + + processing.getDocumentOperations().size() + " documents)."); return Progress.DONE; } @@ -57,15 +57,15 @@ public class SplitterDocumentProcessor extends DocumentProcessor { Array<Document> innerDocuments = (Array<Document>) outerDoc.getFieldValue(arrayFieldName); if (innerDocuments == null) { //the document does not have the field, return - log.log(Level.FINE, "The given Document does not have a field value for field " - + arrayFieldName + ", returning. (Was given " + outerDoc + ")."); + log.log(Level.FINE, () -> "The given Document does not have a field value for field " + + arrayFieldName + ", returning. (Was given " + outerDoc + ")."); return Progress.DONE; } if (innerDocuments.size() == 0) { //the array is empty, return - log.log(Level.FINE, "The given Document does not have any elements in array field " - + arrayFieldName + ", returning. (Was given " + outerDoc + ")."); + log.log(Level.FINE, () -> "The given Document does not have any elements in array field " + + arrayFieldName + ", returning. (Was given " + outerDoc + ")."); return Progress.DONE; } diff --git a/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java b/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java index ec17e5e37e4..285f3e83602 100644 --- a/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java +++ b/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java @@ -96,7 +96,7 @@ public class IndexingProcessor extends DocumentProcessor { log.log(Level.FINE, "Processing document '%s'.", prev.getId()); Document next = script.execute(adapterFactory, prev.getDocument()); if (next == null) { - log.log(Level.FINE, "Document '" + prev.getId() + "' produced no output."); + log.log(Level.FINE, "Document '%s' produced no output.", prev.getId()); return; } @@ -113,7 +113,7 @@ public class IndexingProcessor extends DocumentProcessor { log.log(Level.FINE, "Processing update '%s'.", prev.getId()); DocumentUpdate next = script.execute(adapterFactory, prev); if (next == null) { - log.log(Level.FINE, "Update '" + prev.getId() + "' produced no output."); + log.log(Level.FINE, "Update '%s' produced no output.", prev.getId()); return; } next.setCondition(prev.getCondition()); diff --git a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorDestinationSession.java b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorDestinationSession.java index ae0a89664a5..521908d661c 100644 --- a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorDestinationSession.java +++ b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorDestinationSession.java @@ -56,7 +56,7 @@ public class MessageBusVisitorDestinationSession implements VisitorDestinationSe public void ack(AckToken token) { try { - log.log(Level.FINE, "Sending ack " + token.ackObject); + log.log(Level.FINE, () -> "Sending ack " + token.ackObject); session.reply((Reply) token.ackObject); } catch (Exception e) { e.printStackTrace(); diff --git a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorSession.java b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorSession.java index 88ef67e1854..248fcf7a624 100755 --- a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorSession.java +++ b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/MessageBusVisitorSession.java @@ -405,7 +405,7 @@ public class MessageBusVisitorSession implements VisitorSession { synchronized (progress.getToken()) { this.startTimeNanos = clock.monotonicNanoTime(); if (progress.getIterator().isDone()) { - log.log(Level.FINE, sessionName + ": progress token indicates " + + log.log(Level.FINE, () -> sessionName + ": progress token indicates " + "session is done before it could even start; no-op"); return; } @@ -433,7 +433,7 @@ public class MessageBusVisitorSession implements VisitorSession { * successful, will be equal to newState. */ private StateDescription transitionTo(StateDescription newState) { - log.log(Level.FINE, sessionName + ": attempting transition to state " + newState); + log.log(Level.FINE, () -> sessionName + ": attempting transition to state " + newState); switch (newState.getState()) { case WORKING: assert(state.getState() == State.NOT_STARTED); @@ -450,7 +450,7 @@ public class MessageBusVisitorSession implements VisitorSession { default: com.yahoo.protect.Process.logAndDie("Invalid target transition state: " + newState); } - log.log(Level.FINE, "Session '" + sessionName + "' is now in state " + state); + log.log(Level.FINE, () -> "Session '" + sessionName + "' is now in state " + state); return state; } @@ -500,7 +500,7 @@ public class MessageBusVisitorSession implements VisitorSession { // If no cluster route has been set by user arguments, attempt to retrieve it from mbus config. if (params.getRoute() == null || !params.getRoute().hasHops()) { params.setRoute(getClusterRoute(routingTable)); - log.log(Level.FINE, "No route specified; resolved implicit " + + log.log(Level.FINE, () -> "No route specified; resolved implicit " + "storage cluster: " + params.getRoute().toString()); } } @@ -650,7 +650,7 @@ public class MessageBusVisitorSession implements VisitorSession { VisitorIterator.BucketProgress bucket = progress.getIterator().getNext(); Result result = sender.send(createMessage(bucket)); if (result.isAccepted()) { - log.log(Level.FINE, sessionName + ": sent CreateVisitor for bucket " + + log.log(Level.FINE, () -> sessionName + ": sent CreateVisitor for bucket " + bucket.getSuperbucket() + " with progress " + bucket.getProgress()); ++pendingMessageCount; } else { @@ -690,7 +690,7 @@ public class MessageBusVisitorSession implements VisitorSession { private void markSessionCompleted() { // 'done' is only ever written when token mutex is held, so safe to check // outside of completionMonitor lock. - log.log(Level.FINE, "Visitor session '" + sessionName + "' has completed"); + log.log(Level.FINE, () -> "Visitor session '" + sessionName + "' has completed"); if (params.getLocalDataHandler() != null) { params.getLocalDataHandler().onDone(); } @@ -904,7 +904,7 @@ public class MessageBusVisitorSession implements VisitorSession { progress.getIterator().update(bucket, subProgress); String message = getErrorMessage(reply.getError(0)); - log.log(Level.FINE, sessionName + ": received error reply for bucket " + + log.log(Level.FINE, () -> sessionName + ": received error reply for bucket " + bucket + " with message '" + message + "'"); if (isFatalError(reply)) { @@ -1029,7 +1029,7 @@ public class MessageBusVisitorSession implements VisitorSession { BucketId superbucket = msg.getBuckets().get(0); BucketId subBucketProgress = reply.getLastBucket(); - log.log(Level.FINE, sessionName + ": received CreateVisitorReply for bucket " + + log.log(Level.FINE, () -> sessionName + ": received CreateVisitorReply for bucket " + superbucket + " with progress " + subBucketProgress); progress.getIterator().update(superbucket, subBucketProgress); @@ -1051,7 +1051,7 @@ public class MessageBusVisitorSession implements VisitorSession { int newMaxBuckets = Math.max(Math.min((int)(params.getMaxBucketsPerVisitor() * params.getDynamicMaxBucketsIncreaseFactor()), 128), 1); params.setMaxBucketsPerVisitor(newMaxBuckets); - log.log(Level.FINE, sessionName + ": increasing max buckets per visitor to " + log.log(Level.FINE, () -> sessionName + ": increasing max buckets per visitor to " + params.getMaxBucketsPerVisitor()); } } @@ -1061,7 +1061,7 @@ public class MessageBusVisitorSession implements VisitorSession { ClusterState newState = new ClusterState(reply.getSystemState()); int stateBits = newState.getDistributionBitCount(); if (stateBits != progress.getIterator().getDistributionBitCount()) { - log.log(Level.FINE, "System state changed; now at " + + log.log(Level.FINE, () -> "System state changed; now at " + stateBits + " distribution bits"); // Update the internal state of the visitor iterator. If we're increasing // the number of distribution bits, this may lead to splitting of pending @@ -1150,7 +1150,7 @@ public class MessageBusVisitorSession implements VisitorSession { @Override public void destroy() { - log.log(Level.FINE, sessionName + ": synchronous destroy() called"); + log.log(Level.FINE, () -> sessionName + ": synchronous destroy() called"); try { synchronized (progress.getToken()) { synchronized (completionMonitor) { @@ -1178,7 +1178,7 @@ public class MessageBusVisitorSession implements VisitorSession { } catch (Exception e) { log.log(Level.SEVERE, "Caught exception destroying communication interfaces", e); } - log.log(Level.FINE, sessionName + ": synchronous destroy() done"); + log.log(Level.FINE, () -> sessionName + ": synchronous destroy() done"); } } } diff --git a/fileacquirer/src/main/java/com/yahoo/filedistribution/fileacquirer/FileAcquirerImpl.java b/fileacquirer/src/main/java/com/yahoo/filedistribution/fileacquirer/FileAcquirerImpl.java index 6f104ad6fc5..19aa1cc7e44 100644 --- a/fileacquirer/src/main/java/com/yahoo/filedistribution/fileacquirer/FileAcquirerImpl.java +++ b/fileacquirer/src/main/java/com/yahoo/filedistribution/fileacquirer/FileAcquirerImpl.java @@ -60,7 +60,7 @@ class FileAcquirerImpl implements FileAcquirer { logWarning(); target.close(); } else { - log.log(Level.FINE, "Successfully connected to '" + spec + "', this = " + System.identityHashCode(this)); + log.log(Level.FINE, () -> "Successfully connected to '" + spec + "', this = " + System.identityHashCode(this)); pauseTime = 0; logCount = 0; return; @@ -152,7 +152,7 @@ class FileAcquirerImpl implements FileAcquirer { request.parameters().add(new StringValue(fileReference.value())); double rpcTimeout = Math.min(timer.timeLeft(TimeUnit.SECONDS), 60.0); - log.log(Level.FINE, "InvokeSync waitFor " + fileReference + " with " + rpcTimeout + " seconds timeout"); + log.log(Level.FINE, () -> "InvokeSync waitFor " + fileReference + " with " + rpcTimeout + " seconds timeout"); target.invokeSync(request, rpcTimeout); if (request.checkReturnTypes("s")) { diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java index 30c1d7cd673..1bc44e0bed2 100644 --- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java +++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java @@ -195,7 +195,7 @@ public class FileReceiver { } catch (FileAlreadyExistsException e) { // Don't fail if it already exists (we might get the file from several config servers when retrying, servers are down etc. // so it might be written already). Delete temp file/dir in that case, to avoid filling the disk. - log.log(Level.FINE, "Failed moving file '" + tempFile.getAbsolutePath() + "' to '" + destination.getAbsolutePath() + + log.log(Level.FINE, () -> "Failed moving file '" + tempFile.getAbsolutePath() + "' to '" + destination.getAbsolutePath() + "', '" + destination.getAbsolutePath() + "' already exists"); deleteFileOrDirectory(tempFile); } catch (IOException e) { diff --git a/jrt/src/com/yahoo/jrt/slobrok/api/Register.java b/jrt/src/com/yahoo/jrt/slobrok/api/Register.java index 0da390f8bf6..b498e0b028c 100644 --- a/jrt/src/com/yahoo/jrt/slobrok/api/Register.java +++ b/jrt/src/com/yahoo/jrt/slobrok/api/Register.java @@ -213,7 +213,7 @@ public class Register { log.log(Level.WARNING, logMessagePrefix() + " failed: " + req.errorMessage()); } } else { - log.log(logOnSuccess ? Level.INFO : Level.FINE, logMessagePrefix() + " completed successfully"); + log.log(logOnSuccess ? Level.INFO : Level.FINE, () -> logMessagePrefix() + " completed successfully"); backOff.reset(); } req = null; diff --git a/logserver/src/main/java/com/yahoo/logserver/handlers/archive/ArchiverHandler.java b/logserver/src/main/java/com/yahoo/logserver/handlers/archive/ArchiverHandler.java index ee8c6e36cb8..021517f1cdc 100644 --- a/logserver/src/main/java/com/yahoo/logserver/handlers/archive/ArchiverHandler.java +++ b/logserver/src/main/java/com/yahoo/logserver/handlers/archive/ArchiverHandler.java @@ -211,12 +211,12 @@ public class ArchiverHandler extends AbstractLogHandler { // ensure that root dir exists if (root.isDirectory()) { - log.log(Level.FINE, "Using " + absoluteRootDir + " as root"); + log.log(Level.FINE, () -> "Using " + absoluteRootDir + " as root"); } else { if (! root.mkdirs()) { log.log(Level.SEVERE, "Unable to create directory " + absoluteRootDir); } else { - log.log(Level.FINE, "Created root at " + absoluteRootDir); + log.log(Level.FINE, () -> "Created root at " + absoluteRootDir); } } filesArchived = new FilesArchived(root); diff --git a/logserver/src/main/java/com/yahoo/logserver/handlers/archive/LogWriter.java b/logserver/src/main/java/com/yahoo/logserver/handlers/archive/LogWriter.java index e9d0ffc35b8..0d69131ff52 100644 --- a/logserver/src/main/java/com/yahoo/logserver/handlers/archive/LogWriter.java +++ b/logserver/src/main/java/com/yahoo/logserver/handlers/archive/LogWriter.java @@ -66,7 +66,7 @@ public class LogWriter { // if file does not exist we have a winner if (! f.exists()) { - log.log(Level.FINE, "nextWriter, new file: " + name); + log.log(Level.FINE, () -> "nextWriter, new file: " + name); currentFile = f; bytesWritten = 0; return new FileWriter(f, true); diff --git a/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java b/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java index d955a1a3d34..184d95dcd1d 100644 --- a/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java +++ b/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java @@ -58,11 +58,10 @@ public class SendProxy implements MessageHandler, ReplyHandler { } else { Trace trace = msg.getTrace(); if (logTrace) { - if (reply.hasErrors()) { - log.log(Level.FINE, "Trace for reply with error(s):\n" + reply.getTrace()); - } else if (log.isLoggable(Level.FINEST)) { - log.log(Level.FINEST, "Trace for reply:\n" + reply.getTrace()); - } + if (reply.hasErrors()) + log.log(Level.FINE, () -> "Trace for reply with error(s):\n" + reply.getTrace()); + else + log.log(Level.FINEST, () -> "Trace for reply:\n" + reply.getTrace()); Trace empty = new Trace(); trace.swap(empty); } else if (trace.getLevel() > 0) { diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcConnector.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcConnector.java index 6eb35b78f14..9d93b440a1d 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcConnector.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcConnector.java @@ -31,7 +31,7 @@ public class RpcConnector extends AbstractComponent { Spec spec = new Spec(config.port()); try { acceptor = supervisor.listen(spec); - log.log(FINE, "Listening on " + spec.host() + ":" + acceptor.port()); + log.log(FINE, () -> "Listening on " + spec.host() + ":" + acceptor.port()); } catch (ListenFailedException e) { stop(); log.log(INFO, "Failed listening at " + spec.host() + ":" + spec.port()); diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcServer.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcServer.java index 79af500cde7..ee3cddf3fcb 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcServer.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/rpc/RpcServer.java @@ -146,7 +146,7 @@ public class RpcServer { void setExtraMetrics(Request req) { String metricsJson = req.parameters().get(0).asString(); - log.log(FINE, "setExtraMetrics called with argument: " + metricsJson); + log.log(FINE, () -> "setExtraMetrics called with argument: " + metricsJson); withExceptionHandling(req, () -> metricsManager.setExtraMetrics(toMetricsPackets(metricsJson))); } diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/ConfigSentinelClient.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/ConfigSentinelClient.java index a017b968e08..ab05e778ea6 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/ConfigSentinelClient.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/ConfigSentinelClient.java @@ -59,7 +59,7 @@ public class ConfigSentinelClient extends AbstractComponent { synchronized void ping(VespaService s) { List<VespaService> services = new ArrayList<>(); services.add(s); - log.log(Level.FINE, "Ping for service " + s); + log.log(Level.FINE, () -> "Ping for service " + s); try { setStatus(services); } catch (Exception e) { @@ -93,7 +93,7 @@ public class ConfigSentinelClient extends AbstractComponent { //from the sentinel for (VespaService s : services) { if ((!s.getServiceName().equals("configserver")) && !updatedServices.contains(s)) { - log.log(Level.FINE,"Service " + s + " is no longer found with sentinel - setting alive = false"); + log.log(Level.FINE, () -> "Service " + s + " is no longer found with sentinel - setting alive = false"); s.setAlive(false); } } diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/HttpMetricFetcher.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/HttpMetricFetcher.java index 333d8696413..b4c116d1903 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/HttpMetricFetcher.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/HttpMetricFetcher.java @@ -51,11 +51,11 @@ public abstract class HttpMetricFetcher { String u = "http://localhost:" + port + path; this.url = URI.create(u); - log.log(Level.FINE, "Fetching metrics from " + u + " with timeout " + CONNECTION_TIMEOUT); + log.log(Level.FINE, () -> "Fetching metrics from " + u + " with timeout " + CONNECTION_TIMEOUT); } InputStream getJson() throws IOException,InterruptedException, ExecutionException { - log.log(Level.FINE, "Connecting to url " + url + " for service '" + service + "'"); + log.log(Level.FINE, () -> "Connecting to url " + url + " for service '" + service + "'"); Future<Message<HttpResponse, InputStream>> response = httpClient.execute( new BasicRequestProducer(Method.GET, url), new BasicResponseConsumer<>(new AbstractClassicEntityConsumer<>(BUFFER_SIZE, Runnable::run) { diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/RemoteHealthMetricFetcher.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/RemoteHealthMetricFetcher.java index 2ebf5b2532c..09087c32914 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/RemoteHealthMetricFetcher.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/RemoteHealthMetricFetcher.java @@ -66,7 +66,7 @@ public class RemoteHealthMetricFetcher extends HttpMetricFetcher { return HealthMetric.get(code, message); } catch (IOException e) { - log.log(Level.FINE, "Failed to parse json response from metrics page:" + e + ":" + data); + log.log(Level.FINE, () -> "Failed to parse json response from metrics page:" + e + ":" + data); return HealthMetric.getUnknown("Not able to parse json from status page"); } } diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/SystemPoller.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/SystemPoller.java index 05e65449163..5d119fc30e6 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/SystemPoller.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/SystemPoller.java @@ -99,7 +99,7 @@ public class SystemPoller { return; } - log.log(Level.FINE, "Monitoring system metrics for " + services.size() + " services"); + log.log(Level.FINE, () -> "Monitoring system metrics for " + services.size() + " services"); long sysJiffies = getNormalizedSystemJiffies(); for (VespaService s : services) { @@ -110,10 +110,10 @@ public class SystemPoller { } Metrics metrics = new Metrics(); - log.log(Level.FINE, "Current size of system metrics for service " + s + " is " + metrics.size()); + log.log(Level.FINE, () -> "Current size of system metrics for service " + s + " is " + metrics.size()); long[] size = getMemoryUsage(s); - log.log(Level.FINE, "Updating memory metric for service " + s); + log.log(Level.FINE, () -> "Updating memory metric for service " + s); metrics.add(new Metric("memory_virt", size[memoryTypeVirtual], startTime / 1000)); metrics.add(new Metric("memory_rss", size[memoryTypeResident], startTime / 1000)); @@ -150,7 +150,7 @@ public class SystemPoller { try { in = new BufferedReader(new FileReader("/proc/" + pid + "/stat")); } catch (FileNotFoundException ex) { - log.log(Level.FINE, "Unable to find pid " + pid + " in proc directory, for service " + service.getInstanceName()); + log.log(Level.FINE, () -> "Unable to find pid " + pid + " in proc directory, for service " + service.getInstanceName()); service.setAlive(false); return 0; } diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/VespaServices.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/VespaServices.java index 71f8a5f2b21..b0ea7e709a1 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/VespaServices.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/service/VespaServices.java @@ -48,12 +48,12 @@ public class VespaServices { private List<VespaService> createServices(VespaServicesConfig servicesConfig, String monitoringSystemName) { List<VespaService> services = new ArrayList<>(); for (Service s : servicesConfig.service()) { - log.log(FINE, "Creating service " + s.name()); + log.log(FINE, () -> "Creating service " + s.name()); VespaService vespaService = VespaService.create(s.name(), s.configId(), s.port(), monitoringSystemName, createServiceDimensions(s)); services.add(vespaService); } - log.log(FINE, "Created new services: " + services.size()); + log.log(FINE, () -> "Created new services: " + services.size()); return services; } diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/NoSuchNodeException.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/NoSuchNodeException.java index 697d0d053a1..658a024e3f6 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/NoSuchNodeException.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/NoSuchNodeException.java @@ -6,7 +6,7 @@ package com.yahoo.vespa.hosted.provision; * * @author musum */ -public class NoSuchNodeException extends RuntimeException { +public class NoSuchNodeException extends IllegalArgumentException { public NoSuchNodeException(String message) { super(message); } diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/node/Nodes.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/node/Nodes.java index b9602ef0ad4..266855002ea 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/node/Nodes.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/node/Nodes.java @@ -18,7 +18,6 @@ import com.yahoo.vespa.hosted.provision.NodeMutex; import com.yahoo.vespa.hosted.provision.maintenance.NodeFailer; import com.yahoo.vespa.hosted.provision.node.filter.StateFilter; import com.yahoo.vespa.hosted.provision.persistence.CuratorDatabaseClient; -import com.yahoo.vespa.hosted.provision.restapi.NotFoundException; import java.time.Clock; import java.time.Duration; @@ -167,8 +166,10 @@ public class Nodes { nodesToAdd.add(node); } - List<Node> resultingNodes = db.addNodesInState(IP.Config.verify(nodesToAdd, list(lock)), Node.State.provisioned, agent); - db.removeNodes(nodesToRemove); + NestedTransaction transaction = new NestedTransaction(); + List<Node> resultingNodes = db.addNodesInState(IP.Config.verify(nodesToAdd, list(lock)), Node.State.provisioned, agent, transaction); + db.removeNodes(nodesToRemove, transaction); + transaction.commit(); return resultingNodes; } } @@ -192,9 +193,7 @@ public class Nodes { } public Node setReady(String hostname, Agent agent, String reason) { - Node nodeToReady = node(hostname).orElseThrow(() -> - new NoSuchNodeException("Could not move " + hostname + " to ready: Node not found")); - + Node nodeToReady = requireNode(hostname); if (nodeToReady.state() == Node.State.ready) return nodeToReady; return setReady(List.of(nodeToReady), agent, reason).get(0); } @@ -323,7 +322,7 @@ public class Nodes { } public Node fail(String hostname, boolean keepAllocation, Agent agent, String reason) { - return move(hostname, keepAllocation, Node.State.failed, agent, Optional.of(reason)); + return move(hostname, Node.State.failed, agent, keepAllocation, Optional.of(reason)); } /** @@ -338,7 +337,7 @@ public class Nodes { List<Node> changed = performOn(children, (node, lock) -> failOrMark(node, agent, reason, lock)); if (children.state(Node.State.active).isEmpty()) - changed.add(move(hostname, true, Node.State.failed, agent, Optional.of(reason))); + changed.add(move(hostname, Node.State.failed, agent, true, Optional.of(reason))); else changed.addAll(performOn(NodeList.of(node(hostname).orElseThrow()), (node, lock) -> failOrMark(node, agent, reason, lock))); @@ -350,9 +349,8 @@ public class Nodes { node = node.withWantToFail(true, agent, clock.instant()); write(node, lock); return node; - } - else { - return move(node, Node.State.failed, agent, Optional.of(reason)); + } else { + return move(node.hostname(), Node.State.failed, agent, true, Optional.of(reason)); } } @@ -370,7 +368,7 @@ public class Nodes { } public Node park(String hostname, boolean keepAllocation, Agent agent, String reason, NestedTransaction transaction) { - return move(hostname, keepAllocation, Node.State.parked, agent, Optional.of(reason), transaction); + return move(hostname, Node.State.parked, agent, keepAllocation, Optional.of(reason), transaction); } /** @@ -389,68 +387,63 @@ public class Nodes { * @throws NoSuchNodeException if the node is not found */ public Node reactivate(String hostname, Agent agent, String reason) { - return move(hostname, true, Node.State.active, agent, Optional.of(reason)); + return move(hostname, Node.State.active, agent, true, Optional.of(reason)); } /** * Moves a host to breakfixed state, removing any children. */ public List<Node> breakfixRecursively(String hostname, Agent agent, String reason) { - Node node = node(hostname).orElseThrow(() -> new NoSuchNodeException("Could not breakfix " + hostname + ": Node not found")); + Node node = requireNode(hostname); try (Mutex lock = lockUnallocated()) { requireBreakfixable(node); - List<Node> removed = removeChildren(node, false); - removed.add(move(node, Node.State.breakfixed, agent, Optional.of(reason))); + NestedTransaction transaction = new NestedTransaction(); + List<Node> removed = removeChildren(node, false, transaction); + removed.add(move(node.hostname(), Node.State.breakfixed, agent, true, Optional.of(reason), transaction)); + transaction.commit(); return removed; } } private List<Node> moveRecursively(String hostname, Node.State toState, Agent agent, Optional<String> reason) { + NestedTransaction transaction = new NestedTransaction(); List<Node> moved = list().childrenOf(hostname).asList().stream() - .map(child -> move(child, toState, agent, reason)) + .map(child -> move(child.hostname(), toState, agent, true, reason, transaction)) .collect(Collectors.toList()); - - moved.add(move(hostname, true, toState, agent, reason)); - return moved; - } - - private Node move(String hostname, boolean keepAllocation, Node.State toState, Agent agent, Optional<String> reason) { - NestedTransaction transaction = new NestedTransaction(); - Node moved = move(hostname, keepAllocation, toState, agent, reason, transaction); + moved.add(move(hostname, toState, agent, true, reason, transaction)); transaction.commit(); return moved; } - private Node move(String hostname, boolean keepAllocation, Node.State toState, Agent agent, Optional<String> reason, - NestedTransaction transaction) { - Node node = node(hostname).orElseThrow(() -> new NoSuchNodeException("Could not move " + hostname + " to " + toState + ": Node not found")); - if (!keepAllocation && node.allocation().isPresent()) { - node = node.withoutAllocation(); - } - - return move(node, toState, agent, reason, transaction); - } - - private Node move(Node node, Node.State toState, Agent agent, Optional<String> reason) { + /** Move a node to given state */ + private Node move(String hostname, Node.State toState, Agent agent, boolean keepAllocation, Optional<String> reason) { NestedTransaction transaction = new NestedTransaction(); - Node moved = move(node, toState, agent, reason, transaction); + Node moved = move(hostname, toState, agent, keepAllocation, reason, transaction); transaction.commit(); return moved; } - private Node move(Node node, Node.State toState, Agent agent, Optional<String> reason, NestedTransaction transaction) { - if (toState == Node.State.active && node.allocation().isEmpty()) - illegal("Could not set " + node + " active. It has no allocation."); - - // TODO: Work out a safe lock acquisition strategy for moves, e.g. migrate to lockNode. - try (Mutex lock = lock(node)) { + /** Move a node to given state as part of a transaction */ + private Node move(String hostname, Node.State toState, Agent agent, boolean keepAllocation, Optional<String> reason, NestedTransaction transaction) { + // TODO: Work out a safe lock acquisition strategy for moves. Lock is only held while adding operations to + // transaction, but lock must also be held while committing + try (NodeMutex lock = lockAndGetRequired(hostname)) { + Node node = lock.node(); if (toState == Node.State.active) { + if (node.allocation().isEmpty()) illegal("Could not set " + node + " active: It has no allocation"); + if (!keepAllocation) illegal("Could not set " + node + " active: Requested to discard allocation"); for (Node currentActive : list(Node.State.active).owner(node.allocation().get().owner())) { if (node.allocation().get().membership().cluster().equals(currentActive.allocation().get().membership().cluster()) && node.allocation().get().membership().index() == currentActive.allocation().get().membership().index()) illegal("Could not set " + node + " active: Same cluster and index as " + currentActive); } } + if (!keepAllocation && node.allocation().isPresent()) { + node = node.withoutAllocation(); + } + if (toState == Node.State.deprovisioned) { + node = node.with(IP.Config.EMPTY); + } return db.writeTo(toState, List.of(node), agent, reason, transaction).get(0); } } @@ -460,7 +453,7 @@ public class Nodes { * containers this will remove the node from node repository, otherwise the node will be moved to state ready. */ public Node markNodeAvailableForNewAllocation(String hostname, Agent agent, String reason) { - Node node = node(hostname).orElseThrow(() -> new NotFoundException("No node with hostname '" + hostname + "'")); + Node node = requireNode(hostname); if (node.flavor().getType() == Flavor.Type.DOCKER_CONTAINER && node.type() == NodeType.tenant) { if (node.state() != Node.State.dirty) illegal("Cannot make " + node + " available for new allocation as it is not in state [dirty]"); @@ -483,30 +476,29 @@ public class Nodes { * @return a List of all the nodes that have been removed or (for hosts) deprovisioned */ public List<Node> removeRecursively(String hostname) { - Node node = node(hostname).orElseThrow(() -> new NotFoundException("No node with hostname '" + hostname + "'")); + Node node = requireNode(hostname); return removeRecursively(node, false); } public List<Node> removeRecursively(Node node, boolean force) { try (Mutex lock = lockUnallocated()) { requireRemovable(node, false, force); - - if (node.type().isHost()) { - List<Node> removed = removeChildren(node, force); - if (zone.getCloud().dynamicProvisioning()) - db.removeNodes(List.of(node)); - else { - node = node.with(IP.Config.EMPTY); - move(node, Node.State.deprovisioned, Agent.system, Optional.empty()); + NestedTransaction transaction = new NestedTransaction(); + final List<Node> removed; + if (!node.type().isHost()) { + removed = List.of(node); + db.removeNodes(removed, transaction); + } else { + removed = removeChildren(node, force, transaction); + if (zone.getCloud().dynamicProvisioning()) { + db.removeNodes(List.of(node), transaction); + } else { + move(node.hostname(), Node.State.deprovisioned, Agent.system, false, Optional.empty(), transaction); } removed.add(node); - return removed; - } - else { - List<Node> removed = List.of(node); - db.removeNodes(removed); - return removed; } + transaction.commit(); + return removed; } } @@ -514,13 +506,15 @@ public class Nodes { public void forget(Node node) { if (node.state() != Node.State.deprovisioned) throw new IllegalArgumentException(node + " must be deprovisioned before it can be forgotten"); - db.removeNodes(List.of(node)); + NestedTransaction transaction = new NestedTransaction(); + db.removeNodes(List.of(node), transaction); + transaction.commit(); } - private List<Node> removeChildren(Node node, boolean force) { + private List<Node> removeChildren(Node node, boolean force, NestedTransaction transaction) { List<Node> children = list().childrenOf(node).asList(); children.forEach(child -> requireRemovable(child, true, force)); - db.removeNodes(children); + db.removeNodes(children, transaction); return new ArrayList<>(children); } @@ -776,18 +770,22 @@ public class Nodes { /** Returns the unallocated/application lock, and the node acquired under that lock. */ public NodeMutex lockAndGetRequired(Node node) { - return lockAndGet(node).orElseThrow(() -> new IllegalArgumentException("No such node: " + node.hostname())); + return lockAndGet(node).orElseThrow(() -> new NoSuchNodeException("No node with hostname '" + node.hostname() + "'")); } /** Returns the unallocated/application lock, and the node acquired under that lock. */ public NodeMutex lockAndGetRequired(String hostname) { - return lockAndGet(hostname).orElseThrow(() -> new IllegalArgumentException("No such node: " + hostname)); + return lockAndGet(hostname).orElseThrow(() -> new NoSuchNodeException("No node with hostname '" + hostname + "'")); } private Mutex lock(Node node) { return node.allocation().isPresent() ? lock(node.allocation().get().owner()) : lockUnallocated(); } + private Node requireNode(String hostname) { + return node(hostname).orElseThrow(() -> new NoSuchNodeException("No node with hostname '" + hostname + "'")); + } + private void illegal(String message) { throw new IllegalArgumentException(message); } diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/CuratorDatabaseClient.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/CuratorDatabaseClient.java index 2d8ab74ce71..d1f881f8b7a 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/CuratorDatabaseClient.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/CuratorDatabaseClient.java @@ -110,8 +110,7 @@ public class CuratorDatabaseClient { } /** Adds a set of nodes. Rollbacks/fails transaction if any node is not in the expected state. */ - public List<Node> addNodesInState(List<Node> nodes, Node.State expectedState, Agent agent) { - NestedTransaction transaction = new NestedTransaction(); + public List<Node> addNodesInState(List<Node> nodes, Node.State expectedState, Agent agent, NestedTransaction transaction) { CuratorTransaction curatorTransaction = db.newCuratorTransactionIn(transaction); for (Node node : nodes) { if (node.state() != expectedState) @@ -120,7 +119,6 @@ public class CuratorDatabaseClient { node = node.with(node.history().recordStateTransition(null, expectedState, agent, clock.instant())); curatorTransaction.add(CuratorOperations.create(toPath(node).getAbsolute(), nodeSerializer.toJson(node))); } - transaction.commit(); for (Node node : nodes) log.log(Level.INFO, "Added " + node); @@ -128,21 +126,20 @@ public class CuratorDatabaseClient { return nodes; } - /** - * Removes multiple nodes in a single transaction. - * - * @param nodes list of the nodes to remove - */ - public void removeNodes(List<Node> nodes) { + public List<Node> addNodesInState(List<Node> nodes, Node.State expectedState, Agent agent) { NestedTransaction transaction = new NestedTransaction(); + List<Node> writtenNodes = addNodesInState(nodes, expectedState, agent, transaction); + transaction.commit(); + return writtenNodes; + } + /** Removes given nodes in transaction */ + public void removeNodes(List<Node> nodes, NestedTransaction transaction) { for (Node node : nodes) { Path path = toPath(node.state(), node.hostname()); CuratorTransaction curatorTransaction = db.newCuratorTransactionIn(transaction); curatorTransaction.add(CuratorOperations.delete(path.getAbsolute())); } - - transaction.commit(); nodes.forEach(node -> log.log(Level.INFO, "Removed node " + node.hostname() + " in state " + node.state())); } diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/InfraDeployerImpl.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/InfraDeployerImpl.java index 1b98514e3a8..738a7e5ad4a 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/InfraDeployerImpl.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/InfraDeployerImpl.java @@ -107,7 +107,7 @@ public class InfraDeployerImpl implements InfraDeployer { prepare(); if (hostSpecs.isEmpty()) { - logger.log(Level.FINE, "No nodes to provision for " + application.getCapacity().type() + ", removing application"); + logger.log(Level.FINE, () -> "No nodes to provision for " + application.getCapacity().type() + ", removing application"); removeApplication(application.getApplicationId()); } else { NestedTransaction nestedTransaction = new NestedTransaction(); diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisioner.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisioner.java index f53eb189ec1..e665ace6334 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisioner.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisioner.java @@ -182,7 +182,7 @@ public class LoadBalancerProvisioner { : loadBalancer.get().state(); newLoadBalancer = loadBalancer.get().with(instance).with(state, now); if (loadBalancer.get().state() != newLoadBalancer.state()) { - log.log(Level.FINE, "Moving " + newLoadBalancer.id() + " to state " + newLoadBalancer.state()); + log.log(Level.FINE, () -> "Moving " + newLoadBalancer.id() + " to state " + newLoadBalancer.state()); } } @@ -209,7 +209,7 @@ public class LoadBalancerProvisioner { private Optional<LoadBalancerInstance> provisionInstance(LoadBalancerId id, Set<Real> reals, Optional<LoadBalancer> currentLoadBalancer) { if (hasReals(currentLoadBalancer, reals)) return currentLoadBalancer.get().instance(); - log.log(Level.FINE, "Creating " + id + ", targeting: " + reals); + log.log(Level.FINE, () -> "Creating " + id + ", targeting: " + reals); try { return Optional.of(service.create(new LoadBalancerSpec(id.application(), id.cluster(), reals), allowEmptyReals(currentLoadBalancer))); diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/restapi/NotFoundException.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/restapi/NotFoundException.java index 664aad939f2..1b74ba31d00 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/restapi/NotFoundException.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/restapi/NotFoundException.java @@ -6,7 +6,7 @@ package com.yahoo.vespa.hosted.provision.restapi; * * @author bratseth */ -public class NotFoundException extends RuntimeException { +class NotFoundException extends RuntimeException { public NotFoundException(String message) { super(message); } diff --git a/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisionerTest.java b/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisionerTest.java index eb3bdff484d..bdc3bdfd816 100644 --- a/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisionerTest.java +++ b/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/provisioning/LoadBalancerProvisionerTest.java @@ -11,6 +11,7 @@ import com.yahoo.config.provision.HostSpec; import com.yahoo.config.provision.NodeResources; import com.yahoo.config.provision.NodeType; import com.yahoo.config.provision.exception.LoadBalancerServiceException; +import com.yahoo.transaction.NestedTransaction; import com.yahoo.vespa.flags.InMemoryFlagSource; import com.yahoo.vespa.hosted.provision.Node; import com.yahoo.vespa.hosted.provision.NodeList; @@ -175,7 +176,9 @@ public class LoadBalancerProvisionerTest { // Application is removed, nodes are deleted and load balancer is deactivated tester.remove(app1); - tester.nodeRepository().database().removeNodes(tester.nodeRepository().nodes().list().nodeType(NodeType.tenant).asList()); + NestedTransaction transaction = new NestedTransaction(); + tester.nodeRepository().database().removeNodes(tester.nodeRepository().nodes().list().nodeType(NodeType.tenant).asList(), transaction); + transaction.commit(); assertTrue("Nodes are deleted", tester.nodeRepository().nodes().list().nodeType(NodeType.tenant).isEmpty()); assertSame("Load balancer is deactivated", LoadBalancer.State.inactive, lb.get().state()); diff --git a/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/restapi/NodesV2ApiTest.java b/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/restapi/NodesV2ApiTest.java index 81ae6651d25..d152cbaf5db 100644 --- a/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/restapi/NodesV2ApiTest.java +++ b/node-repository/src/test/java/com/yahoo/vespa/hosted/provision/restapi/NodesV2ApiTest.java @@ -458,7 +458,7 @@ public class NodesV2ApiTest { // Attempt to fail and ready an allocated node without going through dirty tester.assertResponse(new Request("http://localhost:8080/nodes/v2/state/failed/node-does-not-exist", new byte[0], Request.Method.PUT), - 404, "{\"error-code\":\"NOT_FOUND\",\"message\":\"Could not move node-does-not-exist to failed: Node not found\"}"); + 404, "{\"error-code\":\"NOT_FOUND\",\"message\":\"No node with hostname 'node-does-not-exist'\"}"); // Attempt to fail and ready an allocated node without going through dirty assertResponse(new Request("http://localhost:8080/nodes/v2/state/failed/host1.yahoo.com", @@ -515,7 +515,7 @@ public class NodesV2ApiTest { // Attempt to set nonexisting node to active tester.assertResponse(new Request("http://localhost:8080/nodes/v2/state/active/host2.yahoo.com", new byte[0], Request.Method.PUT), 404, - "{\"error-code\":\"NOT_FOUND\",\"message\":\"Could not move host2.yahoo.com to active: Node not found\"}"); + "{\"error-code\":\"NOT_FOUND\",\"message\":\"No node with hostname 'host2.yahoo.com'\"}"); // Attempt to POST duplicate nodes tester.assertResponse(new Request("http://localhost:8080/nodes/v2/node", diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostRequestHandler.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostRequestHandler.java index 7b28925205f..4b8b295964a 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostRequestHandler.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostRequestHandler.java @@ -90,10 +90,10 @@ public class HostRequestHandler extends RestApiRequestHandler<HostRequestHandler applicationUri.toString(), hostServices); } catch (UncheckedTimeoutException e) { - log.log(Level.FINE, "Failed to get host " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to get host " + hostName + ": " + e.getMessage()); throw restApiExceptionFromTimeout("getHost", hostName, e); } catch (HostNameNotFoundException e) { - log.log(Level.FINE, "Host not found: " + hostName); + log.log(Level.FINE, () -> "Host not found: " + hostName); throw new RestApiException.NotFound(e); } } @@ -116,10 +116,10 @@ public class HostRequestHandler extends RestApiRequestHandler<HostRequestHandler try { orchestrator.setNodeStatus(hostName, state); } catch (HostNameNotFoundException e) { - log.log(Level.FINE, "Host not found: " + hostName); + log.log(Level.FINE, () -> "Host not found: " + hostName); throw new RestApiException.NotFound(e); } catch (UncheckedTimeoutException e) { - log.log(Level.FINE, "Failed to patch " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to patch " + hostName + ": " + e.getMessage()); throw restApiExceptionFromTimeout("patch", hostName, e); } catch (OrchestrationException e) { String message = "Failed to set " + hostName + " to " + state + ": " + e.getMessage(); @@ -150,13 +150,13 @@ public class HostRequestHandler extends RestApiRequestHandler<HostRequestHandler try { orchestrator.suspend(hostName); } catch (HostNameNotFoundException e) { - log.log(Level.FINE, "Host not found: " + hostName); + log.log(Level.FINE, () -> "Host not found: " + hostName); throw new RestApiException.NotFound(e); } catch (UncheckedTimeoutException e) { - log.log(Level.FINE, "Failed to suspend " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to suspend " + hostName + ": " + e.getMessage()); throw restApiExceptionFromTimeout("suspend", hostName, e); } catch (HostStateChangeDeniedException e) { - log.log(Level.FINE, "Failed to suspend " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to suspend " + hostName + ": " + e.getMessage()); throw restApiExceptionWithDenialReason("suspend", hostName, e); } return new UpdateHostResponse(hostName.s(), null); @@ -173,13 +173,13 @@ public class HostRequestHandler extends RestApiRequestHandler<HostRequestHandler try { orchestrator.resume(hostName); } catch (HostNameNotFoundException e) { - log.log(Level.FINE, "Host not found: " + hostName); + log.log(Level.FINE, () -> "Host not found: " + hostName); throw new RestApiException.NotFound(e); } catch (UncheckedTimeoutException e) { - log.log(Level.FINE, "Failed to resume " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to resume " + hostName + ": " + e.getMessage()); throw restApiExceptionFromTimeout("resume", hostName, e); } catch (HostStateChangeDeniedException e) { - log.log(Level.FINE, "Failed to resume " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, () -> "Failed to resume " + hostName + ": " + e.getMessage()); throw restApiExceptionWithDenialReason("resume", hostName, e); } return new UpdateHostResponse(hostName.s(), null); diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionRequestHandler.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionRequestHandler.java index 73859f385e1..d2fdf70df19 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionRequestHandler.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionRequestHandler.java @@ -54,21 +54,21 @@ public class HostSuspensionRequestHandler extends RestApiRequestHandler<HostSusp try { orchestrator.suspendAll(parentHostname, hostnames); } catch (BatchHostStateChangeDeniedException e) { - log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, e, () -> "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname); throw createRestApiException(e.getMessage(), Response.Status.CONFLICT, e); } catch (UncheckedTimeoutException e) { - log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, e, () -> "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname); throw createRestApiException(e.getMessage(), Response.Status.CONFLICT, e); } catch (BatchHostNameNotFoundException e) { - log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, e, () -> "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname); // Note that we're returning BAD_REQUEST instead of NOT_FOUND because the resource identified // by the URL path was found. It's one of the hostnames in the request it failed to find. throw createRestApiException(e.getMessage(), Response.Status.BAD_REQUEST, e); } catch (BatchInternalErrorException e) { - log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, e, () -> "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname); throw createRestApiException(e.getMessage(), Response.Status.INTERNAL_SERVER_ERROR, e); } - log.log(Level.FINE, "Suspended " + hostnames + " with parent " + parentHostname); + log.log(Level.FINE, () -> "Suspended " + hostnames + " with parent " + parentHostname); return BatchOperationResult.successResult(); } diff --git a/searchcore/src/vespa/searchcore/proton/server/feedhandler.cpp b/searchcore/src/vespa/searchcore/proton/server/feedhandler.cpp index e4d2d3b3f16..bd7e57dc56e 100644 --- a/searchcore/src/vespa/searchcore/proton/server/feedhandler.cpp +++ b/searchcore/src/vespa/searchcore/proton/server/feedhandler.cpp @@ -779,9 +779,7 @@ FeedHandler::sync() FeedHandler::RPC::Result FeedHandler::receive(const Packet &packet) { - // Called directly when replaying transaction log - // (by fnet thread). Called via DocumentDB::recoverPacket() when - // recovering from another node. + // Called directly when replaying transaction log (by fnet thread). FeedStateSP state = getFeedState(); auto wrap = make_shared<PacketWrapper>(packet, _tlsReplayProgress.get()); state->receive(wrap, _writeService.master()); diff --git a/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.cpp b/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.cpp index 552d2b84179..6066fef68d8 100644 --- a/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.cpp +++ b/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.cpp @@ -369,8 +369,9 @@ StoreOnlyFeedView::handleUpdate(FeedToken token, const UpdateOperation &updOp) internalUpdate(std::move(token), updOp); } -void StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, - FutureStream futureStream, OnOperationDoneType onDone) +void +StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, + FutureStream futureStream, OnOperationDoneType onDone) { summaryExecutor().execute( makeLambdaTask([serialNum, lid, futureStream = std::move(futureStream), trackerToken = _pendingLidsForDocStore.produce(lid), onDone, this] () mutable { @@ -383,7 +384,20 @@ void StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, })); } -void StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, Document::SP doc, OnOperationDoneType onDone) +void +StoreOnlyFeedView::putSummaryNoop(SerialNum serialNum, Lid lid, + FutureStream futureStream, OnOperationDoneType onDone) +{ + summaryExecutor().execute( + makeLambdaTask([serialNum, lid, futureStream = std::move(futureStream), onDone] () mutable { + (void) onDone; + vespalib::nbostream os = futureStream.get(); + (void) os; + })); +} + +void +StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, Document::SP doc, OnOperationDoneType onDone) { summaryExecutor().execute( makeLambdaTask([serialNum, doc = std::move(doc), trackerToken = _pendingLidsForDocStore.produce(lid), onDone, lid, this] { @@ -392,7 +406,8 @@ void StoreOnlyFeedView::putSummary(SerialNum serialNum, Lid lid, Document::SP do _summaryAdapter->put(serialNum, lid, *doc); })); } -void StoreOnlyFeedView::removeSummary(SerialNum serialNum, Lid lid, OnWriteDoneType onDone) { +void +StoreOnlyFeedView::removeSummary(SerialNum serialNum, Lid lid, OnWriteDoneType onDone) { summaryExecutor().execute( makeLambdaTask([serialNum, lid, onDone, trackerToken = _pendingLidsForDocStore.produce(lid), this] { (void) onDone; @@ -400,7 +415,9 @@ void StoreOnlyFeedView::removeSummary(SerialNum serialNum, Lid lid, OnWriteDoneT _summaryAdapter->remove(serialNum, lid); })); } -void StoreOnlyFeedView::heartBeatSummary(SerialNum serialNum) { + +void +StoreOnlyFeedView::heartBeatSummary(SerialNum serialNum) { summaryExecutor().execute( makeLambdaTask([serialNum, this] { _summaryAdapter->heartBeat(serialNum); @@ -467,14 +484,17 @@ StoreOnlyFeedView::internalUpdate(FeedToken token, const UpdateOperation &updOp) } PromisedStream promisedStream; FutureStream futureStream = promisedStream.get_future(); - if (useDocumentStore(serialNum)) { + bool useDocStore = useDocumentStore(serialNum); + if (useDocStore) { putSummary(serialNum, lid, std::move(futureStream), onWriteDone); + } else { + putSummaryNoop(serialNum, lid, std::move(futureStream), onWriteDone); } _writeService.shared().execute(makeLambdaTask( - [upd = updOp.getUpdate(), serialNum, lid, onWriteDone, promisedDoc = std::move(promisedDoc), + [upd = updOp.getUpdate(), useDocStore, lid, onWriteDone, promisedDoc = std::move(promisedDoc), promisedStream = std::move(promisedStream), this]() mutable { - makeUpdatedDocument(serialNum, lid, *upd, onWriteDone, + makeUpdatedDocument(useDocStore, lid, *upd, onWriteDone, std::move(promisedDoc), std::move(promisedStream)); })); updateAttributes(serialNum, lid, std::move(futureDoc), onWriteDone); @@ -482,15 +502,15 @@ StoreOnlyFeedView::internalUpdate(FeedToken token, const UpdateOperation &updOp) } void -StoreOnlyFeedView::makeUpdatedDocument(SerialNum serialNum, Lid lid, const DocumentUpdate & update, +StoreOnlyFeedView::makeUpdatedDocument(bool useDocStore, Lid lid, const DocumentUpdate & update, OnOperationDoneType onWriteDone, PromisedDoc promisedDoc, PromisedStream promisedStream) { Document::UP prevDoc = _summaryAdapter->get(lid, *_repo); Document::UP newDoc; vespalib::nbostream newStream(12345); - assert(!onWriteDone->hasToken() || useDocumentStore(serialNum)); - if (useDocumentStore(serialNum)) { + assert(!onWriteDone->hasToken() || useDocStore); + if (useDocStore) { assert(prevDoc); } if (!prevDoc) { @@ -502,14 +522,14 @@ StoreOnlyFeedView::makeUpdatedDocument(SerialNum serialNum, Lid lid, const Docum } else { if (update.getId() == prevDoc->getId()) { newDoc = std::move(prevDoc); - if (useDocumentStore(serialNum)) { + if (useDocStore) { update.applyTo(*newDoc); newDoc->serialize(newStream); } } else { // Replaying, document removed and lid reused before summary // was flushed. - assert(!onWriteDone->hasToken() && !useDocumentStore(serialNum)); + assert(!onWriteDone->hasToken() && !useDocStore); } } promisedDoc.set_value(std::move(newDoc)); diff --git a/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.h b/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.h index c8d23b1ab58..7f1876cbbdf 100644 --- a/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.h +++ b/searchcore/src/vespa/searchcore/proton/server/storeonlyfeedview.h @@ -156,6 +156,7 @@ private: return _writeService.summary(); } void putSummary(SerialNum serialNum, Lid lid, FutureStream doc, OnOperationDoneType onDone); + void putSummaryNoop(SerialNum serialNum, Lid lid, FutureStream doc, OnOperationDoneType onDone); void putSummary(SerialNum serialNum, Lid lid, DocumentSP doc, OnOperationDoneType onDone); void removeSummary(SerialNum serialNum, Lid lid, OnWriteDoneType onDone); void heartBeatSummary(SerialNum serialNum); @@ -184,7 +185,7 @@ private: IPendingLidTracker::Token get_pending_lid_token(const DocumentOperation &op); - void makeUpdatedDocument(SerialNum serialNum, Lid lid, const DocumentUpdate & update, OnOperationDoneType onWriteDone, + void makeUpdatedDocument(bool useDocStore, Lid lid, const DocumentUpdate & update, OnOperationDoneType onWriteDone, PromisedDoc promisedDoc, PromisedStream promisedStream); protected: diff --git a/service-monitor/src/main/java/com/yahoo/vespa/service/duper/DuperModel.java b/service-monitor/src/main/java/com/yahoo/vespa/service/duper/DuperModel.java index c9df077aeef..d4cb1e6a480 100644 --- a/service-monitor/src/main/java/com/yahoo/vespa/service/duper/DuperModel.java +++ b/service-monitor/src/main/java/com/yahoo/vespa/service/duper/DuperModel.java @@ -95,7 +95,7 @@ public class DuperModel { } else { logPrefix = isComplete ? "Reactivated application " : "Rebootstrapped application "; } - logger.log(Level.FINE, logPrefix + id.toFullString()); + logger.log(Level.FINE, () -> logPrefix + id.toFullString()); updateHostnameVsIdMaps(applicationInfo, id); @@ -110,7 +110,7 @@ public class DuperModel { ApplicationInfo application = applicationsById.remove(applicationId); if (application != null) { - logger.log(Level.FINE, "Removed application " + applicationId.toFullString()); + logger.log(Level.FINE, () -> "Removed application " + applicationId.toFullString()); listeners.forEach(listener -> listener.applicationRemoved(applicationId)); } } diff --git a/service-monitor/src/main/java/com/yahoo/vespa/service/slobrok/SlobrokMonitorManagerImpl.java b/service-monitor/src/main/java/com/yahoo/vespa/service/slobrok/SlobrokMonitorManagerImpl.java index b2696f8573f..2cc3359d449 100644 --- a/service-monitor/src/main/java/com/yahoo/vespa/service/slobrok/SlobrokMonitorManagerImpl.java +++ b/service-monitor/src/main/java/com/yahoo/vespa/service/slobrok/SlobrokMonitorManagerImpl.java @@ -145,7 +145,7 @@ public class SlobrokMonitorManagerImpl implements SlobrokApi, MonitorManager { case "storagenode": return Optional.of("storage/cluster." + configId.s()); default: - logger.log(Level.FINE, "Unknown service type " + serviceType.s() + + logger.log(Level.FINE, () -> "Unknown service type " + serviceType.s() + " with config id " + configId.s()); return Optional.empty(); } diff --git a/staging_vespalib/src/vespa/vespalib/encoding/base64.cpp b/staging_vespalib/src/vespa/vespalib/encoding/base64.cpp index c0b767c33a1..5dfe9d27839 100644 --- a/staging_vespalib/src/vespa/vespalib/encoding/base64.cpp +++ b/staging_vespalib/src/vespa/vespalib/encoding/base64.cpp @@ -19,7 +19,7 @@ static const char base64Chars[] = "ABCDEFGHIJKLMNOPQRSTUVWXYZ" // Set -1 for illegal chars that will cause an error. // Set -2 for illegal chars that will be ignored. (whitespace " \r\t\f\n") -static const char base64Backwards[] = { +static const signed char base64Backwards[] = { -1, -1, -1, -1, -1, -1, -1, -1, -1, -2, -2, -1, -2, -2, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, -2, -1, -1, -1, -1, -1, -1, -1, -1, -1, -1, 62, -1, -1, -1, 63, @@ -119,7 +119,7 @@ Base64::decode(const char* inBuffer, int inLen, char* outBuffer, int outLen) int readbytes = 0; int num_valid_chars = 0; const char* thischar = inBuffer; - char curchar; + signed char curchar; int curOut = 0; char tmp = 0; diff --git a/storage/src/tests/distributor/distributortestutil.cpp b/storage/src/tests/distributor/distributortestutil.cpp index 43870dd2c3e..bdd953b6206 100644 --- a/storage/src/tests/distributor/distributortestutil.cpp +++ b/storage/src/tests/distributor/distributortestutil.cpp @@ -357,7 +357,7 @@ DistributorTestUtil::distributor_component() { return _distributor->distributor_component(); } -storage::distributor::DistributorOperationContext& +storage::distributor::DistributorStripeOperationContext& DistributorTestUtil::operation_context() { return _distributor->distributor_component(); } diff --git a/storage/src/tests/distributor/distributortestutil.h b/storage/src/tests/distributor/distributortestutil.h index ddf153a1406..b845456e873 100644 --- a/storage/src/tests/distributor/distributortestutil.h +++ b/storage/src/tests/distributor/distributortestutil.h @@ -21,7 +21,7 @@ class StripeBucketDBUpdater; class Distributor; class DistributorBucketSpace; class DistributorBucketSpaceRepo; -class DistributorOperationContext; +class DistributorStripeOperationContext; class DistributorStripe; class DistributorStripeComponent; class ExternalOperationHandler; @@ -116,7 +116,7 @@ public: IdealStateManager& getIdealStateManager(); ExternalOperationHandler& getExternalOperationHandler(); storage::distributor::DistributorStripeComponent& distributor_component(); - storage::distributor::DistributorOperationContext& operation_context(); + storage::distributor::DistributorStripeOperationContext& operation_context(); Distributor& getDistributor() { return *_distributor; diff --git a/storage/src/vespa/storage/distributor/bucketdbupdater.cpp b/storage/src/vespa/storage/distributor/bucketdbupdater.cpp index f328b599604..90d3d24c240 100644 --- a/storage/src/vespa/storage/distributor/bucketdbupdater.cpp +++ b/storage/src/vespa/storage/distributor/bucketdbupdater.cpp @@ -40,12 +40,9 @@ BucketDBUpdater::BucketDBUpdater(DistributorStripeInterface& owner, // FIXME STR _node_ctx(_distributor_component), _op_ctx(_distributor_component), _distributor_interface(_distributor_component.getDistributor()), - _delayed_requests(), - _sent_messages(), _pending_cluster_state(), _history(), _sender(sender), - _enqueued_rechecks(), _outdated_nodes_map(), _transition_timer(_node_ctx.clock()), _stale_reads_enabled(false) @@ -77,21 +74,13 @@ BucketDBUpdater::bootstrap_distribution_config(std::shared_ptr<const lib::Distri // ... need to take a guard if so, so can probably not be done at ctor time..? } -// TODO STRIPE what to do with merge guards... // FIXME what about bucket DB replica update timestamp allocations?! Replace with u64 counter..? // Must at the very least ensure we use stripe-local TS generation for DB inserts...! i.e. no global TS // Or do we have to touch these at all here? Just defer all this via stripe interface? void BucketDBUpdater::flush() { - for (auto & entry : _sent_messages) { - // Cannot sendDown MergeBucketReplies during flushing, since - // all lower links have been closed - if (entry.second._mergeReplyGuard) { - entry.second._mergeReplyGuard->resetReply(); - } - } - _sent_messages.clear(); + // TODO STRIPE: Consider if this must flush_and_close() all stripes } void @@ -114,33 +103,6 @@ BucketDBUpdater::has_pending_cluster_state() const } void -BucketDBUpdater::send_request_bucket_info( - uint16_t node, - const document::Bucket& bucket, - const std::shared_ptr<MergeReplyGuard>& mergeReplyGuard) -{ - if (!_op_ctx.storage_node_is_up(bucket.getBucketSpace(), node)) { - return; - } - - std::vector<document::BucketId> buckets; - buckets.push_back(bucket.getBucketId()); - - auto msg = std::make_shared<api::RequestBucketInfoCommand>(bucket.getBucketSpace(), buckets); - - LOG(debug, "Sending request bucket info command %" PRIu64 " for bucket %s to node %u", - msg->getMsgId(), bucket.toString().c_str(), node); - - msg->setPriority(50); - msg->setAddress(_node_ctx.node_address(node)); - - _sent_messages[msg->getMsgId()] = - BucketRequest(node, _op_ctx.generate_unique_timestamp(), - bucket, mergeReplyGuard); - _sender.sendCommand(msg); -} - -void BucketDBUpdater::remove_superfluous_buckets( StripeAccessGuard& guard, const lib::ClusterStateBundle& new_state, @@ -339,51 +301,6 @@ BucketDBUpdater::onActivateClusterStateVersion(const std::shared_ptr<api::Activa return false; } -// TODO remove entirely from this abstraction level? -BucketDBUpdater::MergeReplyGuard::~MergeReplyGuard() -{ - if (_reply) { - _distributor_interface.handleCompletedMerge(_reply); - } -} - -bool -BucketDBUpdater::onMergeBucketReply( - const std::shared_ptr<api::MergeBucketReply>& reply) -{ - auto replyGuard = std::make_shared<MergeReplyGuard>(_distributor_interface, reply); - - // In case the merge was unsuccessful somehow, or some nodes weren't - // actually merged (source-only nodes?) we request the bucket info of the - // bucket again to make sure it's ok. - for (uint32_t i = 0; i < reply->getNodes().size(); i++) { - send_request_bucket_info(reply->getNodes()[i].index, - reply->getBucket(), - replyGuard); - } - - return true; -} - -void -BucketDBUpdater::send_all_queued_bucket_rechecks() -{ - LOG(spam, "Sending %zu queued bucket rechecks previously received " - "via NotifyBucketChange commands", - _enqueued_rechecks.size()); - - for (const auto & entry :_enqueued_rechecks) { - send_request_bucket_info(entry.node, entry.bucket, std::shared_ptr<MergeReplyGuard>()); - } - _enqueued_rechecks.clear(); -} - -bool sort_pred(const BucketListMerger::BucketEntry& left, - const BucketListMerger::BucketEntry& right) -{ - return left.first < right.first; -} - bool BucketDBUpdater::onRequestBucketInfoReply( const std::shared_ptr<api::RequestBucketInfoReply>& repl) @@ -418,17 +335,6 @@ BucketDBUpdater::resend_delayed_messages() if (_pending_cluster_state) { _pending_cluster_state->resendDelayedMessages(); } - if (_delayed_requests.empty()) { - return; // Don't fetch time if not needed - } - framework::MilliSecTime currentTime(_node_ctx.clock()); - while (!_delayed_requests.empty() - && currentTime >= _delayed_requests.front().first) - { - BucketRequest& req(_delayed_requests.front().second); - send_request_bucket_info(req.targetNode, req.bucket, std::shared_ptr<MergeReplyGuard>()); - _delayed_requests.pop_front(); - } } bool @@ -488,7 +394,6 @@ BucketDBUpdater::activate_pending_cluster_state(StripeAccessGuard& guard) _pending_cluster_state.reset(); _outdated_nodes_map.clear(); guard.clear_pending_cluster_state_bundle(); - send_all_queued_bucket_rechecks(); complete_transition_timer(); guard.clear_read_only_bucket_repo_databases(); @@ -547,21 +452,6 @@ const vespalib::string BUCKETDB_UPDATER = "Bucket Database Updater"; } -void -BucketDBUpdater::BucketRequest::print_xml_tag(vespalib::xml::XmlOutputStream &xos, const vespalib::xml::XmlAttribute ×tampAttribute) const -{ - using namespace vespalib::xml; - xos << XmlTag("storagenode") - << XmlAttribute("index", targetNode); - xos << XmlAttribute("bucketspace", bucket.getBucketSpace().getId(), XmlAttribute::HEX); - if (bucket.getBucketId().getRawId() == 0) { - xos << XmlAttribute("bucket", ALL); - } else { - xos << XmlAttribute("bucket", bucket.getBucketId().getId(), XmlAttribute::HEX); - } - xos << timestampAttribute << XmlEndTag(); -} - bool BucketDBUpdater::reportStatus(std::ostream& out, const framework::HttpUrlPath& path) const @@ -599,18 +489,6 @@ BucketDBUpdater::report_xml_status(vespalib::xml::XmlOutputStream& xos, << XmlAttribute("processingtime", i->_processingTime) << XmlEndTag(); } - xos << XmlEndTag() - << XmlTag("single_bucket_requests"); - for (const auto & entry : _sent_messages) - { - entry.second.print_xml_tag(xos, XmlAttribute("sendtimestamp", entry.second.timestamp)); - } - xos << XmlEndTag() - << XmlTag("delayed_single_bucket_requests"); - for (const auto & entry : _delayed_requests) - { - entry.second.print_xml_tag(xos, XmlAttribute("resendtimestamp", entry.first.getTime())); - } xos << XmlEndTag() << XmlEndTag(); return ""; } diff --git a/storage/src/vespa/storage/distributor/bucketdbupdater.h b/storage/src/vespa/storage/distributor/bucketdbupdater.h index b990f094e9c..04962e3af9b 100644 --- a/storage/src/vespa/storage/distributor/bucketdbupdater.h +++ b/storage/src/vespa/storage/distributor/bucketdbupdater.h @@ -48,7 +48,6 @@ public: bool onSetSystemState(const std::shared_ptr<api::SetSystemStateCommand>& cmd) override; bool onActivateClusterStateVersion(const std::shared_ptr<api::ActivateClusterStateVersionCommand>& cmd) override; bool onRequestBucketInfoReply(const std::shared_ptr<api::RequestBucketInfoReply> & repl) override; - bool onMergeBucketReply(const std::shared_ptr<api::MergeBucketReply>& reply) override; vespalib::string getReportContentType(const framework::HttpUrlPath&) const override; bool reportStatus(std::ostream&, const framework::HttpUrlPath&) const override; @@ -61,7 +60,7 @@ public: void print(std::ostream& out, bool verbose, const std::string& indent) const; const DistributorNodeContext& node_context() const { return _node_ctx; } - DistributorOperationContext& operation_context() { return _op_ctx; } + DistributorStripeOperationContext& operation_context() { return _op_ctx; } void set_stale_reads_enabled(bool enabled) noexcept { _stale_reads_enabled.store(enabled, std::memory_order_relaxed); @@ -71,61 +70,6 @@ public: } private: - class MergeReplyGuard { - public: - MergeReplyGuard(DistributorStripeInterface& distributor_interface, const std::shared_ptr<api::MergeBucketReply>& reply) noexcept - : _distributor_interface(distributor_interface), _reply(reply) {} - - ~MergeReplyGuard(); - - // Used when we're flushing and simply want to drop the reply rather - // than send it down - void resetReply() { _reply.reset(); } - private: - DistributorStripeInterface& _distributor_interface; - std::shared_ptr<api::MergeBucketReply> _reply; - }; - - struct BucketRequest { - BucketRequest() - : targetNode(0), bucket(), timestamp(0) {}; - - BucketRequest(uint16_t t, uint64_t currentTime, const document::Bucket& b, - const std::shared_ptr<MergeReplyGuard>& guard) - : targetNode(t), - bucket(b), - timestamp(currentTime), - _mergeReplyGuard(guard) {}; - - void print_xml_tag(vespalib::xml::XmlOutputStream &xos, const vespalib::xml::XmlAttribute ×tampAttribute) const; - uint16_t targetNode; - document::Bucket bucket; - uint64_t timestamp; - - std::shared_ptr<MergeReplyGuard> _mergeReplyGuard; - }; - - struct EnqueuedBucketRecheck { - uint16_t node; - document::Bucket bucket; - - EnqueuedBucketRecheck() : node(0), bucket() {} - - EnqueuedBucketRecheck(uint16_t _node, const document::Bucket& _bucket) - : node(_node), - bucket(_bucket) - {} - - bool operator<(const EnqueuedBucketRecheck& o) const { - if (node != o.node) { - return node < o.node; - } - return bucket < o.bucket; - } - bool operator==(const EnqueuedBucketRecheck& o) const { - return node == o.node && bucket == o.bucket; - } - }; friend class DistributorTestUtil; // Only to be used by tests that want to ensure both the BucketDBUpdater _and_ the Distributor @@ -139,8 +83,6 @@ private: bool is_pending_cluster_state_completed() const; void process_completed_pending_cluster_state(StripeAccessGuard& guard); void activate_pending_cluster_state(StripeAccessGuard& guard); - void send_request_bucket_info(uint16_t node, const document::Bucket& bucket, - const std::shared_ptr<MergeReplyGuard>& mergeReplyGuard); void ensure_transition_timer_started(); void complete_transition_timer(); @@ -155,7 +97,6 @@ private: void enable_current_cluster_state_bundle_in_distributor_and_stripes(StripeAccessGuard& guard); void add_current_state_to_cluster_state_history(); - void send_all_queued_bucket_rechecks(); void propagate_active_state_bundle_internally(); @@ -170,14 +111,11 @@ private: DistributorStripeComponent _distributor_component; const DistributorNodeContext& _node_ctx; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DistributorStripeInterface& _distributor_interface; - std::deque<std::pair<framework::MilliSecTime, BucketRequest>> _delayed_requests; - std::map<uint64_t, BucketRequest> _sent_messages; std::unique_ptr<PendingClusterState> _pending_cluster_state; std::list<PendingClusterState::Summary> _history; DistributorMessageSender& _sender; - std::set<EnqueuedBucketRecheck> _enqueued_rechecks; OutdatedNodesMap _outdated_nodes_map; framework::MilliSecTimer _transition_timer; std::atomic<bool> _stale_reads_enabled; diff --git a/storage/src/vespa/storage/distributor/distributor_stripe_component.cpp b/storage/src/vespa/storage/distributor/distributor_stripe_component.cpp index ee131adf8ff..aef126b8318 100644 --- a/storage/src/vespa/storage/distributor/distributor_stripe_component.cpp +++ b/storage/src/vespa/storage/distributor/distributor_stripe_component.cpp @@ -177,7 +177,7 @@ DistributorStripeComponent::node_address(uint16_t node_index) const noexcept } -// Implements DistributorOperationContext +// Implements DistributorStripeOperationContext void DistributorStripeComponent::remove_nodes_from_bucket_database(const document::Bucket& bucket, const std::vector<uint16_t>& nodes) diff --git a/storage/src/vespa/storage/distributor/distributor_stripe_component.h b/storage/src/vespa/storage/distributor/distributor_stripe_component.h index cb69b963271..38fcb4ffef3 100644 --- a/storage/src/vespa/storage/distributor/distributor_stripe_component.h +++ b/storage/src/vespa/storage/distributor/distributor_stripe_component.h @@ -2,8 +2,8 @@ #pragma once #include "distributor_node_context.h" -#include "distributor_operation_context.h" #include "distributor_stripe_interface.h" +#include "distributor_stripe_operation_context.h" #include "document_selection_parser.h" #include "operationowner.h" #include "statechecker.h" @@ -30,7 +30,7 @@ struct DatabaseUpdate { */ class DistributorStripeComponent : public storage::DistributorComponent, public DistributorNodeContext, - public DistributorOperationContext, + public DistributorStripeOperationContext, public DocumentSelectionParser { public: @@ -62,7 +62,7 @@ public: */ api::StorageMessageAddress node_address(uint16_t node_index) const noexcept override; - // Implements DistributorOperationContext + // Implements DistributorStripeOperationContext api::Timestamp generate_unique_timestamp() override { return getUniqueTimestamp(); } /** diff --git a/storage/src/vespa/storage/distributor/distributor_operation_context.h b/storage/src/vespa/storage/distributor/distributor_stripe_operation_context.h index d9277a33088..8a62a102cc0 100644 --- a/storage/src/vespa/storage/distributor/distributor_operation_context.h +++ b/storage/src/vespa/storage/distributor/distributor_stripe_operation_context.h @@ -20,11 +20,11 @@ class DistributorBucketSpaceRepo; class PendingMessageTracker; /** - * Interface with functionality that is used when handling distributor operations. + * Interface with functionality that is used when handling distributor stripe operations. */ -class DistributorOperationContext { +class DistributorStripeOperationContext { public: - virtual ~DistributorOperationContext() {} + virtual ~DistributorStripeOperationContext() {} virtual api::Timestamp generate_unique_timestamp() = 0; virtual void update_bucket_database(const document::Bucket& bucket, const BucketCopy& changed_node, diff --git a/storage/src/vespa/storage/distributor/externaloperationhandler.cpp b/storage/src/vespa/storage/distributor/externaloperationhandler.cpp index 81201ff5469..2acd04f7eef 100644 --- a/storage/src/vespa/storage/distributor/externaloperationhandler.cpp +++ b/storage/src/vespa/storage/distributor/externaloperationhandler.cpp @@ -63,7 +63,7 @@ public: }; ExternalOperationHandler::ExternalOperationHandler(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorMetricSet& metrics, ChainedMessageSender& msg_sender, OperationSequencer& operation_sequencer, diff --git a/storage/src/vespa/storage/distributor/externaloperationhandler.h b/storage/src/vespa/storage/distributor/externaloperationhandler.h index 6205321ce84..fc1aa00ea65 100644 --- a/storage/src/vespa/storage/distributor/externaloperationhandler.h +++ b/storage/src/vespa/storage/distributor/externaloperationhandler.h @@ -40,7 +40,7 @@ public: bool onGetBucketList(const std::shared_ptr<api::GetBucketListCommand>&) override; ExternalOperationHandler(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorMetricSet& metrics, ChainedMessageSender& msg_sender, OperationSequencer& operation_sequencer, @@ -86,7 +86,7 @@ public: private: DistributorNodeContext& _node_ctx; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DistributorMetricSet& _metrics; ChainedMessageSender& _msg_sender; OperationSequencer& _operation_sequencer; diff --git a/storage/src/vespa/storage/distributor/idealstatemanager.h b/storage/src/vespa/storage/distributor/idealstatemanager.h index a5f80343512..ebcaad4cf96 100644 --- a/storage/src/vespa/storage/distributor/idealstatemanager.h +++ b/storage/src/vespa/storage/distributor/idealstatemanager.h @@ -77,8 +77,8 @@ public: } const DistributorNodeContext& node_context() const { return _distributorComponent; } - DistributorOperationContext& operation_context() { return _distributorComponent; } - const DistributorOperationContext& operation_context() const { return _distributorComponent; } + DistributorStripeOperationContext& operation_context() { return _distributorComponent; } + const DistributorStripeOperationContext& operation_context() const { return _distributorComponent; } DistributorBucketSpaceRepo &getBucketSpaceRepo() { return _bucketSpaceRepo; } const DistributorBucketSpaceRepo &getBucketSpaceRepo() const { return _bucketSpaceRepo; } diff --git a/storage/src/vespa/storage/distributor/operations/external/putoperation.cpp b/storage/src/vespa/storage/distributor/operations/external/putoperation.cpp index cb3c0be6cc5..de36bb60b2c 100644 --- a/storage/src/vespa/storage/distributor/operations/external/putoperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/putoperation.cpp @@ -22,7 +22,7 @@ using namespace storage; using document::BucketSpace; PutOperation::PutOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::PutCommand> msg, PersistenceOperationMetricSet& metric, SequencingHandle sequencingHandle) diff --git a/storage/src/vespa/storage/distributor/operations/external/putoperation.h b/storage/src/vespa/storage/distributor/operations/external/putoperation.h index 6503a5ce438..c9cfc08d63d 100644 --- a/storage/src/vespa/storage/distributor/operations/external/putoperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/putoperation.h @@ -24,7 +24,7 @@ class PutOperation : public SequencedOperation { public: PutOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::PutCommand> msg, PersistenceOperationMetricSet& metric, @@ -54,7 +54,7 @@ private: bool has_unavailable_targets_in_pending_state(const OperationTargetList& targets) const; std::shared_ptr<api::PutCommand> _msg; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DistributorBucketSpace &_bucketSpace; }; diff --git a/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.cpp b/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.cpp index ad308ee0c19..f8609dedde4 100644 --- a/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.cpp @@ -19,7 +19,7 @@ using document::BucketSpace; RemoveLocationOperation::RemoveLocationOperation( DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DocumentSelectionParser& parser, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::RemoveLocationCommand> msg, diff --git a/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.h b/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.h index 5cad43e02ca..bf09a95933f 100644 --- a/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/removelocationoperation.h @@ -16,7 +16,7 @@ class RemoveLocationOperation : public Operation { public: RemoveLocationOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DocumentSelectionParser& parser, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::RemoveLocationCommand> msg, diff --git a/storage/src/vespa/storage/distributor/operations/external/removeoperation.cpp b/storage/src/vespa/storage/distributor/operations/external/removeoperation.cpp index 722bcc7d27e..25c73d88e37 100644 --- a/storage/src/vespa/storage/distributor/operations/external/removeoperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/removeoperation.cpp @@ -13,7 +13,7 @@ using namespace storage; using document::BucketSpace; RemoveOperation::RemoveOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::RemoveCommand> msg, PersistenceOperationMetricSet& metric, diff --git a/storage/src/vespa/storage/distributor/operations/external/removeoperation.h b/storage/src/vespa/storage/distributor/operations/external/removeoperation.h index 8dc88cb1d65..32eb5bd3d70 100644 --- a/storage/src/vespa/storage/distributor/operations/external/removeoperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/removeoperation.h @@ -16,7 +16,7 @@ class RemoveOperation : public SequencedOperation { public: RemoveOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::RemoveCommand> msg, PersistenceOperationMetricSet& metric, diff --git a/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.cpp b/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.cpp index 362acdf18ec..1f8da7a0589 100644 --- a/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.cpp @@ -26,7 +26,7 @@ namespace storage::distributor { TwoPhaseUpdateOperation::TwoPhaseUpdateOperation( DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DocumentSelectionParser& parser, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::UpdateCommand> msg, diff --git a/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.h b/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.h index d353498c8e3..7817eb7bffd 100644 --- a/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/twophaseupdateoperation.h @@ -56,7 +56,7 @@ class TwoPhaseUpdateOperation : public SequencedOperation { public: TwoPhaseUpdateOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DocumentSelectionParser& parser, DistributorBucketSpace &bucketSpace, std::shared_ptr<api::UpdateCommand> msg, @@ -146,7 +146,7 @@ private: std::shared_ptr<api::UpdateCommand> _updateCmd; std::shared_ptr<api::StorageReply> _updateReply; DistributorNodeContext& _node_ctx; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DocumentSelectionParser& _parser; DistributorBucketSpace &_bucketSpace; SentMessageMap _sentMessageMap; diff --git a/storage/src/vespa/storage/distributor/operations/external/updateoperation.cpp b/storage/src/vespa/storage/distributor/operations/external/updateoperation.cpp index 593814cb2f9..4530d7b2864 100644 --- a/storage/src/vespa/storage/distributor/operations/external/updateoperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/updateoperation.cpp @@ -19,7 +19,7 @@ using document::BucketSpace; namespace storage::distributor { UpdateOperation::UpdateOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace& bucketSpace, const std::shared_ptr<api::UpdateCommand>& msg, std::vector<BucketDatabase::Entry> entries, diff --git a/storage/src/vespa/storage/distributor/operations/external/updateoperation.h b/storage/src/vespa/storage/distributor/operations/external/updateoperation.h index 9f0796e71d2..4e875b27133 100644 --- a/storage/src/vespa/storage/distributor/operations/external/updateoperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/updateoperation.h @@ -24,7 +24,7 @@ class UpdateOperation : public Operation { public: UpdateOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace& bucketSpace, const std::shared_ptr<api::UpdateCommand>& msg, std::vector<BucketDatabase::Entry> entries, diff --git a/storage/src/vespa/storage/distributor/operations/external/visitoroperation.cpp b/storage/src/vespa/storage/distributor/operations/external/visitoroperation.cpp index 292a3a5fc0b..b4ad16f3323 100644 --- a/storage/src/vespa/storage/distributor/operations/external/visitoroperation.cpp +++ b/storage/src/vespa/storage/distributor/operations/external/visitoroperation.cpp @@ -64,7 +64,7 @@ matches_visitor_library(vespalib::stringref input, vespalib::stringref expected) VisitorOperation::VisitorOperation( DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, const api::CreateVisitorCommand::SP& m, const Config& config, diff --git a/storage/src/vespa/storage/distributor/operations/external/visitoroperation.h b/storage/src/vespa/storage/distributor/operations/external/visitoroperation.h index 179727a330c..794436a28e6 100644 --- a/storage/src/vespa/storage/distributor/operations/external/visitoroperation.h +++ b/storage/src/vespa/storage/distributor/operations/external/visitoroperation.h @@ -20,7 +20,7 @@ namespace storage::distributor { class DistributorBucketSpace; class DistributorNodeContext; -class DistributorOperationContext; +class DistributorStripeOperationContext; class VisitorOperation : public Operation { @@ -36,7 +36,7 @@ public: }; VisitorOperation(DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, DistributorBucketSpace &bucketSpace, const std::shared_ptr<api::CreateVisitorCommand>& msg, const Config& config, @@ -153,7 +153,7 @@ private: vespalib::duration timeLeft() const noexcept; DistributorNodeContext& _node_ctx; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DistributorBucketSpace &_bucketSpace; SentMessagesMap _sentMessages; diff --git a/storage/src/vespa/storage/distributor/persistencemessagetracker.cpp b/storage/src/vespa/storage/distributor/persistencemessagetracker.cpp index 173e29566ac..9328a43cc6b 100644 --- a/storage/src/vespa/storage/distributor/persistencemessagetracker.cpp +++ b/storage/src/vespa/storage/distributor/persistencemessagetracker.cpp @@ -16,7 +16,7 @@ PersistenceMessageTrackerImpl::PersistenceMessageTrackerImpl( PersistenceOperationMetricSet& metric, std::shared_ptr<api::BucketInfoReply> reply, DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, api::Timestamp revertTimestamp) : MessageTracker(node_ctx), _metric(metric), diff --git a/storage/src/vespa/storage/distributor/persistencemessagetracker.h b/storage/src/vespa/storage/distributor/persistencemessagetracker.h index 87b2d1e8de0..57d0a77364b 100644 --- a/storage/src/vespa/storage/distributor/persistencemessagetracker.h +++ b/storage/src/vespa/storage/distributor/persistencemessagetracker.h @@ -37,7 +37,7 @@ public: PersistenceMessageTrackerImpl(PersistenceOperationMetricSet& metric, std::shared_ptr<api::BucketInfoReply> reply, DistributorNodeContext& node_ctx, - DistributorOperationContext& op_ctx, + DistributorStripeOperationContext& op_ctx, api::Timestamp revertTimestamp = 0); ~PersistenceMessageTrackerImpl() override; @@ -71,7 +71,7 @@ private: PersistenceOperationMetricSet& _metric; std::shared_ptr<api::BucketInfoReply> _reply; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; api::Timestamp _revertTimestamp; std::vector<BucketNodePair> _revertNodes; mbus::Trace _trace; diff --git a/storage/src/vespa/storage/distributor/stripe_bucket_db_updater.h b/storage/src/vespa/storage/distributor/stripe_bucket_db_updater.h index decaa964a59..67b31343f6f 100644 --- a/storage/src/vespa/storage/distributor/stripe_bucket_db_updater.h +++ b/storage/src/vespa/storage/distributor/stripe_bucket_db_updater.h @@ -61,7 +61,7 @@ public: bool reportStatus(std::ostream&, const framework::HttpUrlPath&) const override; void print(std::ostream& out, bool verbose, const std::string& indent) const; const DistributorNodeContext& node_context() const { return _node_ctx; } - DistributorOperationContext& operation_context() { return _op_ctx; } + DistributorStripeOperationContext& operation_context() { return _op_ctx; } /** * Returns whether the current PendingClusterState indicates that there has @@ -260,7 +260,7 @@ private: DistributorStripeComponent _distributorComponent; const DistributorNodeContext& _node_ctx; - DistributorOperationContext& _op_ctx; + DistributorStripeOperationContext& _op_ctx; DistributorStripeInterface& _distributor_interface; std::deque<std::pair<framework::MilliSecTime, BucketRequest> > _delayedRequests; std::map<uint64_t, BucketRequest> _sentMessages; diff --git a/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java b/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java index d2e0434f273..997b575612e 100755 --- a/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java +++ b/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java @@ -124,18 +124,16 @@ public class SharedSender implements ReplyHandler { synchronized (metrics) { metrics.addReply(r); } - if (log.isLoggable(Level.FINEST)) { - log.log(Level.FINEST, "Received reply for file " + owner.toString() + " count was " + owner.getPending().val()); - } + log.log(Level.FINEST, () -> "Received reply for file " + owner.toString() + " count was " + owner.getPending().val()); if (owner.isAborted()) { - log.log(Level.FINE, "Received reply for file " + owner.toString() + " which is aborted"); + log.log(Level.FINE, () -> "Received reply for file " + owner.toString() + " which is aborted"); owner.getPending().clear(); return; } if (owner.handleReply(r)) { owner.getPending().dec(); } else { - log.log(Level.FINE, "Received reply for file " + owner.toString() + " which wants to abort"); + log.log(Level.FINE, () -> "Received reply for file " + owner.toString() + " which wants to abort"); owner.getPending().clear(); } } else { diff --git a/vespajlib/src/main/java/com/yahoo/tensor/functions/Reduce.java b/vespajlib/src/main/java/com/yahoo/tensor/functions/Reduce.java index 86f23487efb..879daefaf72 100644 --- a/vespajlib/src/main/java/com/yahoo/tensor/functions/Reduce.java +++ b/vespajlib/src/main/java/com/yahoo/tensor/functions/Reduce.java @@ -114,7 +114,9 @@ public class Reduce<NAMETYPE extends Name> extends PrimitiveTensorFunction<NAMET // Special case: Reduce all if (dimensions.isEmpty() || dimensions.size() == argument.type().dimensions().size()) - if (argument.type().dimensions().size() == 1 && argument instanceof IndexedTensor) + if (argument.isEmpty()) + return Tensor.from(0.0); + else if (argument.type().dimensions().size() == 1 && argument instanceof IndexedTensor) return reduceIndexedVector((IndexedTensor)argument, aggregator); else return reduceAllGeneral(argument, aggregator); diff --git a/vespajlib/src/test/java/com/yahoo/tensor/functions/ReduceTestCase.java b/vespajlib/src/test/java/com/yahoo/tensor/functions/ReduceTestCase.java index 21fed1745b9..f96852df377 100644 --- a/vespajlib/src/test/java/com/yahoo/tensor/functions/ReduceTestCase.java +++ b/vespajlib/src/test/java/com/yahoo/tensor/functions/ReduceTestCase.java @@ -16,7 +16,6 @@ public class ReduceTestCase { @Test public void testReduce() { - assertNan(Tensor.from("tensor(x{})", "{}").median()); assertEquals(1.0, Tensor.from("tensor(x[1])", "[1]").median().asDouble(), delta); assertEquals(1.5, Tensor.from("tensor(x[2])", "[1, 2]").median().asDouble(), delta); assertEquals(3.0, Tensor.from("tensor(x[7])", "[3, 1, 1, 1, 4, 4, 4]").median().asDouble(), delta); @@ -28,6 +27,17 @@ public class ReduceTestCase { assertNan(Tensor.Builder.of("tensor(x[1])").cell(Double.NaN, 0).build().median()); } + @Test + public void testEmptyReduce() { + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").avg().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").max().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").median().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").min().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").prod().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").sum().asDouble(), delta); + assertEquals(0.0, Tensor.from("tensor(x[3],y{})", "{}").count().asDouble(), delta); + } + private void assertNan(Tensor tensor) { assertTrue(tensor + " is NaN", Double.isNaN(tensor.asDouble())); } diff --git a/vespalib/src/tests/btree/iteratespeed.cpp b/vespalib/src/tests/btree/iteratespeed.cpp index 218e4c9250e..c93968a7da8 100644 --- a/vespalib/src/tests/btree/iteratespeed.cpp +++ b/vespalib/src/tests/btree/iteratespeed.cpp @@ -136,7 +136,7 @@ int IterateSpeed::Main() { int argi; - char c; + int c; const char *optArg; argi = 1; int loops = 1; diff --git a/vespalib/src/vespa/vespalib/hwaccelrated/CMakeLists.txt b/vespalib/src/vespa/vespalib/hwaccelrated/CMakeLists.txt index ac9d8d76074..c5797cbd432 100644 --- a/vespalib/src/vespa/vespalib/hwaccelrated/CMakeLists.txt +++ b/vespalib/src/vespa/vespalib/hwaccelrated/CMakeLists.txt @@ -1,12 +1,17 @@ # Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. + +if(CMAKE_SYSTEM_PROCESSOR STREQUAL "x86_64") + set(ACCEL_FILES "avx2.cpp" "avx512.cpp") +else() + unset(ACCEL_FILES) +endif() + vespa_add_library(vespalib_vespalib_hwaccelrated OBJECT SOURCES iaccelrated.cpp generic.cpp - avx2.cpp - avx512.cpp + ${ACCEL_FILES} DEPENDS ) -set_source_files_properties(avx.cpp PROPERTIES COMPILE_FLAGS -march=sandybridge) set_source_files_properties(avx2.cpp PROPERTIES COMPILE_FLAGS -march=haswell) set_source_files_properties(avx512.cpp PROPERTIES COMPILE_FLAGS -march=skylake-avx512) diff --git a/vespalib/src/vespa/vespalib/hwaccelrated/iaccelrated.cpp b/vespalib/src/vespa/vespalib/hwaccelrated/iaccelrated.cpp index de917c5f065..674efe75c17 100644 --- a/vespalib/src/vespa/vespalib/hwaccelrated/iaccelrated.cpp +++ b/vespalib/src/vespa/vespalib/hwaccelrated/iaccelrated.cpp @@ -2,8 +2,10 @@ #include "iaccelrated.h" #include "generic.h" +#ifdef __x86_64__ #include "avx2.h" #include "avx512.h" +#endif #include <vespa/vespalib/util/memory.h> #include <cstdio> #include <vector> @@ -26,6 +28,7 @@ public: IAccelrated::UP create() const override { return std::make_unique<GenericAccelrator>(); } }; +#ifdef __x86_64__ class Avx2Factory :public Factory{ public: IAccelrated::UP create() const override { return std::make_unique<Avx2Accelrator>(); } @@ -35,6 +38,7 @@ class Avx512Factory :public Factory{ public: IAccelrated::UP create() const override { return std::make_unique<Avx512Accelrator>(); } }; +#endif template<typename T> std::vector<T> createAndFill(size_t sz) { @@ -255,6 +259,7 @@ private: Selector::Selector() : _factory() { +#ifdef __x86_64__ __builtin_cpu_init (); if (__builtin_cpu_supports("avx512f")) { _factory = std::make_unique<Avx512Factory>(); @@ -263,6 +268,9 @@ Selector::Selector() : } else { _factory = std::make_unique<GenericFactory>(); } +#else + _factory = std::make_unique<GenericFactory>(); +#endif } } diff --git a/vespalib/src/vespa/vespalib/util/time.cpp b/vespalib/src/vespa/vespalib/util/time.cpp index 341102bf9ff..b1e859bde00 100644 --- a/vespalib/src/vespa/vespalib/util/time.cpp +++ b/vespalib/src/vespa/vespalib/util/time.cpp @@ -2,7 +2,6 @@ #include "time.h" #include <thread> -#include <immintrin.h> namespace vespalib { @@ -43,7 +42,7 @@ Timer::waitAtLeast(duration dur, bool busyWait) { steady_clock::time_point deadline = steady_clock::now() + dur; while (steady_clock::now() < deadline) { for (int i = 0; i < 1000; i++) { - _mm_pause(); + std::this_thread::yield(); } } } else { diff --git a/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java b/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java index 3789e30509c..af269fc2ad5 100644 --- a/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java +++ b/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java @@ -1,6 +1,7 @@ // Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. package com.yahoo.vespa.curator; +import java.util.ArrayList; import java.util.logging.Level; import com.yahoo.path.Path; @@ -36,9 +37,9 @@ class CuratorCompletionWaiter implements Curator.CompletionWaiter { public void awaitCompletion(Duration timeout) { List<String> respondents; try { - log.log(Level.FINE, "Synchronizing on barrier " + barrierPath); + log.log(Level.FINE, () -> "Synchronizing on barrier " + barrierPath); respondents = awaitInternal(timeout); - log.log(Level.FINE, "Done synchronizing on barrier " + barrierPath); + log.log(Level.FINE, () -> "Done synchronizing on barrier " + barrierPath); } catch (Exception e) { throw new RuntimeException(e); } @@ -54,9 +55,10 @@ class CuratorCompletionWaiter implements Curator.CompletionWaiter { private List<String> awaitInternal(Duration timeout) throws Exception { Instant startTime = clock.instant(); Instant endTime = startTime.plus(timeout); - List<String> respondents; + List<String> respondents = new ArrayList<>(); do { - respondents = curator.framework().getChildren().forPath(barrierPath); + respondents.clear(); + respondents.addAll(curator.framework().getChildren().forPath(barrierPath)); if (log.isLoggable(Level.FINE)) { log.log(Level.FINE, respondents.size() + "/" + curator.zooKeeperEnsembleCount() + " responded: " + respondents + ", all participants: " + curator.zooKeeperEnsembleConnectionSpec()); @@ -64,12 +66,12 @@ class CuratorCompletionWaiter implements Curator.CompletionWaiter { // First, check if all config servers responded if (respondents.size() == curator.zooKeeperEnsembleCount()) { - log.log(Level.FINE, barrierCompletedMessage(respondents, startTime)); + log.log(Level.FINE, () -> barrierCompletedMessage(respondents, startTime)); break; } // If some are missing, quorum is enough if (respondents.size() >= barrierMemberCount()) { - log.log(Level.FINE, barrierCompletedMessage(respondents, startTime)); + log.log(Level.FINE, () -> barrierCompletedMessage(respondents, startTime)); break; } |