diff options
161 files changed, 504 insertions, 504 deletions
diff --git a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceConfirmationResource.java b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceConfirmationResource.java index 59616bec749..2828880ff67 100644 --- a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceConfirmationResource.java +++ b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceConfirmationResource.java @@ -32,7 +32,7 @@ public class InstanceConfirmationResource { @Consumes(MediaType.APPLICATION_JSON) @Produces(MediaType.APPLICATION_JSON) public InstanceConfirmation confirmInstance(InstanceConfirmation instanceConfirmation) { - log.log(LogLevel.DEBUG, instanceConfirmation.toString()); + log.log(Level.FINE, instanceConfirmation.toString()); if (!instanceValidator.isValidInstance(instanceConfirmation)) { log.log(LogLevel.ERROR, "Invalid instance: " + instanceConfirmation); throw new ForbiddenException("Instance is invalid"); diff --git a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceRefreshResource.java b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceRefreshResource.java index c62e5009c8f..a1eab136aa2 100644 --- a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceRefreshResource.java +++ b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceRefreshResource.java @@ -34,7 +34,7 @@ public class InstanceRefreshResource { @Consumes(MediaType.APPLICATION_JSON) @Produces(MediaType.APPLICATION_JSON) public InstanceConfirmation confirmInstanceRefresh(InstanceConfirmation instanceConfirmation) { - log.log(LogLevel.DEBUG, instanceConfirmation.toString()); + log.log(Level.FINE, instanceConfirmation.toString()); if (!instanceValidator.isValidRefresh(instanceConfirmation)) { log.log(LogLevel.ERROR, "Invalid instance refresh: " + instanceConfirmation); throw new ForbiddenException("Instance is invalid"); diff --git a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceValidator.java b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceValidator.java index b1958bf5eed..b101f0bce67 100644 --- a/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceValidator.java +++ b/athenz-identity-provider-service/src/main/java/com/yahoo/vespa/hosted/athenz/instanceproviderservice/instanceconfirmation/InstanceValidator.java @@ -85,11 +85,11 @@ public class InstanceValidator { return false; } - log.log(LogLevel.DEBUG, () -> String.format("Validating instance %s.", providerUniqueId)); + log.log(Level.FINE, () -> String.format("Validating instance %s.", providerUniqueId)); PublicKey publicKey = keyProvider.getPublicKey(signedIdentityDocument.signingKeyVersion()); if (signer.hasValidSignature(signedIdentityDocument, publicKey)) { - log.log(LogLevel.DEBUG, () -> String.format("Instance %s is valid.", providerUniqueId)); + log.log(Level.FINE, () -> String.format("Instance %s is valid.", providerUniqueId)); return true; } log.log(LogLevel.ERROR, () -> String.format("Instance %s has invalid signature.", providerUniqueId)); @@ -100,7 +100,7 @@ public class InstanceValidator { // We'll have to perform some validation on the instance id and other fields of the attribute map. // Separate between tenant and node certificate as well. public boolean isValidRefresh(InstanceConfirmation confirmation) { - log.log(LogLevel.DEBUG, () -> String.format("Accepting refresh for instance with identity '%s', provider '%s', instanceId '%s'.", + log.log(Level.FINE, () -> String.format("Accepting refresh for instance with identity '%s', provider '%s', instanceId '%s'.", new AthenzService(confirmation.domain, confirmation.service).getFullName(), confirmation.provider, confirmation.attributes.get(SAN_DNS_ATTRNAME))); 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 0fcb5b65237..eefa7dfb322 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 @@ -102,7 +102,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(LogLevel.DEBUG, "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/FleetController.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/FleetController.java index 82fb4c825b9..1e66c397b88 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 @@ -548,7 +548,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd responseCode = StatusPageResponse.ResponseCode.INTERNAL_SERVER_ERROR; message = "Internal Server Error"; hiddenMessage = ExceptionUtils.getStackTraceAsString(e);; - log.log(LogLevel.DEBUG, "Unknown exception thrown for request " + httpRequest.getRequest() + + log.log(Level.FINE, "Unknown exception thrown for request " + httpRequest.getRequest() + ": " + hiddenMessage); } @@ -671,7 +671,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd // If there's a pending DB store we have not yet been able to store the // current state bundle to ZK and must therefore _not_ allow it to be published. if (database.hasPendingClusterStateMetaDataStore()) { - log.log(LogLevel.DEBUG, "Can't publish current cluster state as it has one or more pending ZooKeeper stores"); + log.log(Level.FINE, "Can't publish current cluster state as it has one or more pending ZooKeeper stores"); return false; } boolean sentAny = false; @@ -682,7 +682,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd && currentTime >= nextStateSendTime) { if (currentTime < firstAllowedStateBroadcast) { - log.log(LogLevel.DEBUG, "Not set to broadcast states just yet, but as we have gotten info from all nodes we can do so safely."); + log.log(Level.FINE, "Not set to broadcast states just yet, but as we have gotten info from all nodes we can do so safely."); // Reset timer to only see warning once. firstAllowedStateBroadcast = currentTime; } @@ -1037,7 +1037,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd + stateVersionTracker.getCurrentVersion() + " to be in line.", timer.getCurrentTimeInMillis())); long currentTime = timer.getCurrentTimeInMillis(); firstAllowedStateBroadcast = currentTime + options.minTimeBeforeFirstSystemStateBroadcast; - log.log(LogLevel.DEBUG, "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; } @@ -1067,7 +1067,7 @@ public class FleetController implements NodeStateOrHostInfoChangeHandler, NodeAd tick(); } } catch (InterruptedException e) { - log.log(LogLevel.DEBUG, "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(LogLevel.ERROR, "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 205a6e13242..8299e77e01a 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 @@ -34,7 +34,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(LogLevel.DEBUG, "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(); @@ -179,7 +179,7 @@ public class MasterElectionHandler implements MasterInterface { if (nextInLineCount != ourPosition) { nextInLineCount = ourPosition; if (ourPosition > 0) { - log.log(LogLevel.DEBUG, "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 f98de8ca581..12cfe979511 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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); @@ -388,7 +388,7 @@ abstract public class NodeInfo implements Comparable<NodeInfo> { downgradeToRpcVersion(RPCCommunicator.LEGACY_SET_SYSTEM_STATE2_RPC_VERSION, methodName, timer); return true; } else if (timer.getCurrentTimeInMillis() - 2000 < adjustedVersionTime) { - log.log(LogLevel.DEBUG, () -> "Node " + toString() + " does not support " + methodName + " call. Version already downgraded, so ignoring it."); + log.log(Level.FINE, () -> "Node " + toString() + " does not support " + methodName + " call. Version already downgraded, so ignoring it."); return true; } } @@ -397,7 +397,7 @@ abstract public class NodeInfo implements Comparable<NodeInfo> { } private void downgradeToRpcVersion(int newVersion, String methodName, Timer timer) { - log.log(LogLevel.DEBUG, () -> String.format("Node %s does not support %s call. Downgrading to version %d.", + log.log(Level.FINE, () -> String.format("Node %s does not support %s call. Downgrading to version %d.", toString(), methodName, newVersion)); version = newVersion; nextAttemptTime = 0; @@ -453,7 +453,7 @@ abstract public class NodeInfo implements Comparable<NodeInfo> { && (wentDownAtClusterState == null || wentDownAtClusterState.getVersion() < stateBundle.getVersion()) && !stateBundle.getBaselineClusterState().getNodeState(node).getState().oneOf("dsm")) { - log.log(LogLevel.DEBUG, () -> String.format("Clearing going down timestamp of node %s after " + + log.log(Level.FINE, () -> String.format("Clearing going down timestamp of node %s after " + "receiving ack of cluster state bundle %s", node, stateBundle)); wentDownWithStartTime = 0; } 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 f1fe29cf0e3..7e7092eb67e 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Ignoring get node state error. Need to resend"); + log.log(Level.FINE, "Ignoring get node state error. Need to resend"); } } else { - log.log(LogLevel.DEBUG, "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), LogLevel.INFO); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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,7 +174,7 @@ public class NodeStateGatherer { if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.INFO); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + log.log(Level.FINE, "Failed to talk to node " + info + ": " + req.getReply().getReturnCode() + " " + req.getReply().getReturnMessage() + ": " + msg); } newState.setState(State.DOWN); @@ -186,7 +186,7 @@ public class NodeStateGatherer { if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.INFO); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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); } else if (msg.equals("Connection timed out")) { @@ -194,14 +194,14 @@ public class NodeStateGatherer { msg = "Connection error: Timeout"; eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.INFO); } else { - log.log(LogLevel.DEBUG, "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); } } else { msg = "Connection error: " + reason; if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.WARNING); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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); } @@ -212,7 +212,7 @@ public class NodeStateGatherer { if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.WARNING); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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 +223,19 @@ public class NodeStateGatherer { if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.WARNING); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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), LogLevel.INFO); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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 +244,7 @@ public class NodeStateGatherer { if (info.getReportedState().getState().oneOf("ui")) { eventLog.addNodeOnlyEvent(NodeEvent.forBaseline(info, prefix + msg, NodeEvent.Type.REPORTED, currentTime), LogLevel.WARNING); } else if (!info.getReportedState().hasDescription() || !info.getReportedState().getDescription().equals(msg)) { - log.log(LogLevel.DEBUG, "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 a8aa15d5959..e9005509c52 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 @@ -51,7 +51,7 @@ public class StateChangeHandler { final DatabaseHandler database, final DatabaseHandler.Context dbContext) throws InterruptedException { int startTimestampsReset = 0; - log.log(LogLevel.DEBUG, String.format("handleAllDistributorsInSync invoked for state version %d", currentState.getVersion())); + log.log(Level.FINE, String.format("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,19 +60,19 @@ public class StateChangeHandler { if (nodeInfo != null && nodeState != null) { if (nodeState.getStartTimestamp() > nodeInfo.getStartTimestamp()) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, String.format("Storing away new start timestamp for node %s (%d)", + 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(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, String.format("Resetting timestamp in cluster state for node %s", node)); + log.log(Level.FINE, String.format("Resetting timestamp in cluster state for node %s", node)); } ++startTimestampsReset; } } else if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, node + ": " + + log.log(Level.FINE, node + ": " + (nodeInfo == null ? "null" : nodeInfo.getStartTimestamp()) + ", " + (nodeState == null ? "null" : nodeState.getStartTimestamp())); } @@ -85,7 +85,7 @@ public class StateChangeHandler { stateMayHaveChanged = true; database.saveStartTimestamps(dbContext); } else { - log.log(LogLevel.DEBUG, "Found no start timestamps to reset in cluster state."); + log.log(Level.FINE, "Found no start timestamps to reset in cluster state."); } } @@ -147,13 +147,13 @@ public class StateChangeHandler { if (reportedState.getMinUsedBits() != currentState.getMinUsedBits()) { final int oldCount = currentState.getMinUsedBits(); final int newCount = reportedState.getMinUsedBits(); - log.log(LogLevel.DEBUG, + log.log(Level.FINE, 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(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, String.format("Not altering state of %s in cluster state because new state is too similar: %s", + 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))); } @@ -181,12 +181,12 @@ public class StateChangeHandler { } if (node.getReportedState().getState().equals(State.STOPPING)) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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; @@ -209,7 +209,7 @@ public class StateChangeHandler { stateMayHaveChanged = true; if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, 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())); @@ -321,11 +321,11 @@ public class StateChangeHandler { if (mayResetCrashCounterOnStableUpNode(currentTime, node, lastReportedState)) { node.setPrematureCrashCount(0); - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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; } @@ -416,7 +416,7 @@ public class StateChangeHandler { final NodeStateOrHostInfoChangeHandler nodeListener) { final long timeNow = timer.getCurrentTimeInMillis(); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, String.format("Finding new cluster state entry for %s switching state %s", + log.log(Level.FINE, String.format("Finding new cluster state entry for %s switching state %s", node, currentState.getTextualDifference(reportedState))); } @@ -482,7 +482,7 @@ public class StateChangeHandler { if (nodeUpToDownEdge(node, currentState, reportedState)) { node.setTransitionTime(timeNow); if (node.getUpStableStateTime() + stableStateTimePeriod > timeNow && !isControlledShutdown(reportedState)) { - log.log(LogLevel.DEBUG, "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/SystemStateBroadcaster.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/SystemStateBroadcaster.java index 55fc0294dd7..d6b8364954b 100644 --- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/SystemStateBroadcaster.java +++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/SystemStateBroadcaster.java @@ -92,11 +92,11 @@ public class SystemStateBroadcaster { // NO_SUCH_METHOD implies node is on a version that does not understand explicit activations // and it has already merrily started using the state version. Treat as if it had been ACKed. if (reply.getReturnCode() != ErrorCode.NO_SUCH_METHOD) { - log.log(LogLevel.DEBUG, () -> String.format("Activation NACK for node %s with version %d, message %s", + log.log(Level.FINE, () -> String.format("Activation NACK for node %s with version %d, message %s", info, version, reply.getReturnMessage())); success = false; } else { - log.log(LogLevel.DEBUG, () -> String.format("Node %s did not understand state activation RPC; " + + log.log(Level.FINE, () -> String.format("Node %s did not understand state activation RPC; " + "implicitly treating state %d as activated on node", info, version)); } } else if (reply.getActualVersion() != version) { @@ -109,7 +109,7 @@ public class SystemStateBroadcaster { version, info, reply.getActualVersion())); success = false; } else { - log.log(LogLevel.DEBUG, () -> String.format("Node %s reports successful activation of state " + + log.log(Level.FINE, () -> String.format("Node %s reports successful activation of state " + "version %d", info, version)); } info.setSystemStateVersionActivationAcked(version, success); @@ -140,7 +140,7 @@ public class SystemStateBroadcaster { } } else { info.setClusterStateBundleVersionAcknowledged(version, true); - log.log(LogLevel.DEBUG, () -> String.format("Node %s ACKed system state version %d.", info, version)); + log.log(Level.FINE, () -> String.format("Node %s ACKed system state version %d.", info, version)); lastErrorReported.remove(info.getNode()); } } @@ -216,7 +216,7 @@ public class SystemStateBroadcaster { if (!anyDistributorsNeedStateBundle && (currentStateVersion > lastStateVersionBundleAcked)) { markCurrentClusterStateBundleAsReceivedByAllDistributors(); if (clusterStateBundle.deferredActivation()) { - log.log(LogLevel.DEBUG, () -> String.format("All distributors have ACKed cluster state " + + log.log(Level.FINE, () -> String.format("All distributors have ACKed cluster state " + "version %d, sending activation", currentStateVersion)); } else { markCurrentClusterStateAsConverged(database, dbContext, fleetController); @@ -235,7 +235,7 @@ public class SystemStateBroadcaster { if (!anyDistributorsNeedActivation && (currentStateVersion > lastClusterStateVersionConverged)) { markCurrentClusterStateAsConverged(database, dbContext, fleetController); } else { - log.log(LogLevel.DEBUG, () -> String.format("distributors still need activation in state %d (last converged: %d)", + log.log(Level.FINE, () -> String.format("distributors still need activation in state %d (last converged: %d)", currentStateVersion, lastClusterStateVersionConverged)); } } @@ -245,7 +245,7 @@ public class SystemStateBroadcaster { } private void markCurrentClusterStateAsConverged(DatabaseHandler database, DatabaseHandler.Context dbContext, FleetController fleetController) throws InterruptedException { - log.log(LogLevel.DEBUG, "All distributors have newest clusterstate, updating start timestamps in zookeeper and clearing them from cluster state"); + log.log(Level.FINE, "All distributors have newest clusterstate, updating start timestamps in zookeeper and clearing them from cluster state"); lastClusterStateVersionConverged = clusterStateBundle.getVersion(); lastClusterStateBundleConverged = clusterStateBundle; fleetController.handleAllDistributorsInSync(database, dbContext); @@ -272,11 +272,11 @@ public class SystemStateBroadcaster { if (nodeNeedsToObserveStartupTimestamps(node)) { // TODO this is the same for all nodes, compute only once ClusterStateBundle modifiedBundle = clusterStateBundle.cloneWithMapper(state -> buildModifiedClusterState(state, dbContext)); - log.log(LogLevel.DEBUG, () -> String.format("Sending modified cluster state version %d" + + log.log(Level.FINE, () -> String.format("Sending modified cluster state version %d" + " to node %s: %s", baselineState.getVersion(), node, modifiedBundle)); communicator.setSystemState(modifiedBundle, node, setClusterStateWaiter); } else { - log.log(LogLevel.DEBUG, () -> String.format("Sending system state version %d to node %s. " + + log.log(Level.FINE, () -> String.format("Sending system state version %d to node %s. " + "(went down time %d, node start time %d)", baselineState.getVersion(), node, node.getWentDownWithStartTime(), node.getStartTimestamp())); communicator.setSystemState(clusterStateBundle, node, setClusterStateWaiter); @@ -297,7 +297,7 @@ public class SystemStateBroadcaster { var recipients = resolveStateActivationSendSet(dbContext); for (NodeInfo node : recipients) { - log.log(LogLevel.DEBUG, () -> String.format("Sending cluster state activation to node %s for version %d", + log.log(Level.FINE, () -> String.format("Sending cluster state activation to node %s for version %d", node, clusterStateBundle.getVersion())); communicator.activateClusterStateVersion(clusterStateBundle.getVersion(), node, activateClusterStateVersionWaiter); } 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 78e71d63e6a..a7570ce5028 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 @@ -52,7 +52,7 @@ public class DatabaseHandler { } private class DatabaseListener implements Database.DatabaseListener { public void handleZooKeeperSessionDown() { - log.log(LogLevel.DEBUG, "Fleetcontroller " + nodeIndex + ": Lost contact with zookeeper server"); + log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Lost contact with zookeeper server"); synchronized(monitor) { lostZooKeeperConnectionEvent = true; monitor.notifyAll(); @@ -62,7 +62,7 @@ public class DatabaseHandler { public void handleMasterData(Map<Integer, Integer> data) { synchronized (monitor) { if (masterDataEvent != null && masterDataEvent.equals(data)) { - log.log(LogLevel.DEBUG, "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; } @@ -133,7 +133,7 @@ public class DatabaseHandler { currentlyStored.clear(); pendingStore.clear(); pendingStore.masterVote = currentVote; - log.log(LogLevel.DEBUG, "Cleared session metadata. Pending master vote is now " + log.log(Level.FINE, "Cleared session metadata. Pending master vote is now " + pendingStore.masterVote); } @@ -149,7 +149,7 @@ public class DatabaseHandler { public void setZooKeeperSessionTimeout(int timeout) { if (timeout == zooKeeperSessionTimeout) return; - log.log(LogLevel.DEBUG, "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(); } @@ -176,7 +176,7 @@ public class DatabaseHandler { database = databaseFactory.create(params); } } catch (KeeperException.NodeExistsException e) { - log.log(LogLevel.DEBUG, "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); @@ -202,17 +202,17 @@ public class DatabaseHandler { synchronized (monitor) { if (zooKeeperAddress == null) return false; // If not using zookeeper no work to be done if (lostZooKeeperConnectionEvent) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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); @@ -257,10 +257,10 @@ public class DatabaseHandler { boolean didWork = false; if (pendingStore.masterVote != null) { didWork = true; - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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; @@ -271,7 +271,7 @@ public class DatabaseHandler { } if (pendingStore.lastSystemStateVersion != null) { didWork = true; - log.log(LogLevel.DEBUG, "Fleetcontroller " + nodeIndex + log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Attempting to store last system state version " + pendingStore.lastSystemStateVersion + " into zookeeper."); if (database.storeLatestSystemStateVersion(pendingStore.lastSystemStateVersion)) { @@ -283,7 +283,7 @@ public class DatabaseHandler { } if (pendingStore.startTimestamps != null) { didWork = true; - log.log(LogLevel.DEBUG, "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; @@ -294,7 +294,7 @@ public class DatabaseHandler { } if (pendingStore.wantedStates != null) { didWork = true; - log.log(LogLevel.DEBUG, "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; @@ -316,7 +316,7 @@ public class DatabaseHandler { } public void setMasterVote(Context context, int wantedMasterCandidate) throws InterruptedException { - log.log(LogLevel.DEBUG, "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 @@ -324,14 +324,14 @@ public class DatabaseHandler { if (pendingStore.masterVote != null || currentlyStored.masterVote == null || currentlyStored.masterVote != wantedMasterCandidate) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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 @@ -339,14 +339,14 @@ public class DatabaseHandler { if (pendingStore.lastSystemStateVersion != null || currentlyStored.lastSystemStateVersion == null || currentlyStored.lastSystemStateVersion != version) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(); @@ -363,7 +363,7 @@ public class DatabaseHandler { } public void saveLatestClusterStateBundle(Context context, ClusterStateBundle clusterStateBundle) throws InterruptedException { - log.log(LogLevel.DEBUG, () -> String.format("Fleetcontroller %d: Scheduling bundle %s to be saved to ZooKeeper", nodeIndex, clusterStateBundle)); + log.log(Level.FINE, () -> String.format("Fleetcontroller %d: Scheduling bundle %s to be saved to ZooKeeper", nodeIndex, clusterStateBundle)); pendingStore.clusterStateBundle = clusterStateBundle; doNextZooKeeperTask(context); } @@ -378,7 +378,7 @@ public class DatabaseHandler { } public ClusterStateBundle getLatestClusterStateBundle() throws InterruptedException { - log.log(LogLevel.DEBUG, () -> String.format("Fleetcontroller %d: Retrieving latest cluster state bundle from ZooKeeper", nodeIndex)); + log.log(Level.FINE, () -> String.format("Fleetcontroller %d: Retrieving latest cluster state bundle from ZooKeeper", nodeIndex)); synchronized (databaseMonitor) { if (database != null && !database.isClosed()) { return database.retrieveLastPublishedStateBundle(); @@ -389,7 +389,7 @@ public class DatabaseHandler { } public void saveWantedStates(Context context) throws InterruptedException { - log.log(LogLevel.DEBUG, "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))) { @@ -403,14 +403,14 @@ public class DatabaseHandler { if (pendingStore.wantedStates != null || currentlyStored.wantedStates == null || !currentlyStored.wantedStates.equals(wantedStates)) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(); @@ -421,7 +421,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(LogLevel.DEBUG, "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<>(); } @@ -435,7 +435,7 @@ public class DatabaseHandler { context.getNodeStateUpdateListener().handleNewWantedNodeState(nodeInfo, wantedState); altered = true; } - log.log(LogLevel.DEBUG, "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 @@ -451,13 +451,13 @@ public class DatabaseHandler { } public void saveStartTimestamps(Context context) throws InterruptedException { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Fleetcontroller " + nodeIndex + ": Retrieving start timestamps"); + log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Retrieving start timestamps"); synchronized (databaseMonitor) { if (database == null || database.isClosed()) { return false; @@ -473,7 +473,7 @@ public class DatabaseHandler { } for (Map.Entry<Node, Long> e : startTimestamps.entrySet()) { cluster.setStartTimestamp(e.getKey(), e.getValue()); - log.log(LogLevel.DEBUG, "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 0fdfd46dec5..28527162b71 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 @@ -68,10 +68,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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Fleetcontroller " + nodeIndex + ": Got ZooKeeper event None."); + log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Got ZooKeeper event None."); } } } @@ -90,7 +90,7 @@ public class MasterDataGatherer { for (String node : nodes) { int index = Integer.parseInt(node); nextMasterData.put(index, null); - log.log(LogLevel.DEBUG, "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 @@ -127,7 +127,7 @@ public class MasterDataGatherer { Integer value = Integer.valueOf(data); if (nextMasterData.containsKey(index)) { if (value.equals(nextMasterData.get(index))) { - log.log(LogLevel.DEBUG, "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(LogLevel.INFO, "Fleetcontroller " + nodeIndex + ": Got vote from fleetcontroller " + index + ". Altering vote from " + nextMasterData.get(index) + " to " + value + "."); nextMasterData.put(index, value); @@ -143,7 +143,7 @@ public class MasterDataGatherer { } } } - log.log(LogLevel.DEBUG, "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(); } } @@ -173,14 +173,14 @@ public class MasterDataGatherer { Map<Integer, Integer> copy; synchronized (nextMasterData) { if (nextMasterData.equals(masterData)) { - log.log(LogLevel.DEBUG, "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<Integer, Integer>(nextMasterData); copy = masterData; } - log.log(LogLevel.DEBUG, "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 453216039d9..a2d370a6fe8 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 @@ -114,13 +114,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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Fleetcontroller " + nodeIndex + ": Created zookeeper node '" + prefix + nodename + "'"); + log.log(Level.FINE, "Fleetcontroller " + nodeIndex + ": Created zookeeper node '" + prefix + nodename + "'"); } catch (KeeperException.NodeExistsException e) { - log.log(LogLevel.DEBUG, "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."); } } @@ -162,7 +162,7 @@ public class ZooKeeperDatabase extends Database { public void close() { sessionOpen = false; try{ - log.log(LogLevel.DEBUG, "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) { @@ -217,7 +217,7 @@ public class ZooKeeperDatabase extends Database { public Integer retrieveLatestSystemStateVersion() throws InterruptedException { Stat stat = new Stat(); try{ - log.log(LogLevel.DEBUG, () -> String.format("Fleetcontroller %d: Fetching latest cluster state at '%slatestversion'", + log.log(Level.FINE, () -> String.format("Fleetcontroller %d: Fetching latest cluster state at '%slatestversion'", nodeIndex, zooKeeperRoot)); byte[] data = session.getData(zooKeeperRoot + "latestversion", false, stat); lastKnownStateVersionZNodeVersion = stat.getVersion(); @@ -249,7 +249,7 @@ public class ZooKeeperDatabase extends Database { } byte val[] = sb.toString().getBytes(utf8); try{ - log.log(LogLevel.DEBUG, "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) { @@ -262,7 +262,7 @@ public class ZooKeeperDatabase extends Database { public Map<Node, NodeState> retrieveWantedStates() throws InterruptedException { try{ - log.log(LogLevel.DEBUG, "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<>(); @@ -300,7 +300,7 @@ public class ZooKeeperDatabase extends Database { } byte val[] = sb.toString().getBytes(utf8); try{ - log.log(LogLevel.DEBUG, "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) { @@ -314,7 +314,7 @@ public class ZooKeeperDatabase extends Database { @Override public Map<Node, Long> retrieveStartTimestamps() throws InterruptedException { try{ - log.log(LogLevel.DEBUG, "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>(); @@ -347,7 +347,7 @@ public class ZooKeeperDatabase extends Database { EnvelopedClusterStateBundleCodec envelopedBundleCodec = new SlimeClusterStateBundleCodec(); byte[] encodedBundle = envelopedBundleCodec.encodeWithEnvelope(stateBundle); try{ - log.log(LogLevel.DEBUG, () -> String.format("Fleetcontroller %d: Storing published state bundle %s at " + + log.log(Level.FINE, () -> String.format("Fleetcontroller %d: Storing published state bundle %s at " + "'%spublished_state_bundle' with expected znode version %d", nodeIndex, stateBundle, zooKeeperRoot, lastKnownStateBundleZNodeVersion)); var stat = session.setData(zooKeeperRoot + "published_state_bundle", encodedBundle, lastKnownStateBundleZNodeVersion); 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 64ca08dc997..94b1a9e1fbc 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 @@ -117,7 +117,7 @@ public class SetNodeStateRequest extends Request<SetResponse> { NodeStateChangeChecker.Result result = cluster.calculateEffectOfNewState( node, currentClusterState, condition, wantedState, newWantedState); - log.log(LogLevel.DEBUG, "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/RPCCommunicator.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RPCCommunicator.java index a2619692961..d8a72a9272c 100644 --- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RPCCommunicator.java +++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/rpc/RPCCommunicator.java @@ -110,7 +110,7 @@ public class RPCCommunicator implements Communicator { public void getNodeState(NodeInfo node, Waiter<GetNodeStateRequest> externalWaiter) { Target connection = getConnection(node); if ( ! connection.isValid()) { - log.log(LogLevel.DEBUG, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); + log.log(Level.FINE, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); } NodeState currentState = node.getReportedState(); Request req = new Request("getnodestate3"); @@ -138,7 +138,7 @@ public class RPCCommunicator implements Communicator { Target connection = getConnection(node); if ( ! connection.isValid()) { - log.log(LogLevel.DEBUG, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); + log.log(Level.FINE, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); return; } int nodeVersion = node.getVersion(); @@ -156,7 +156,7 @@ public class RPCCommunicator implements Communicator { v.add(new DataValue(encodedBundle.getCompression().data())); } - log.log(LogLevel.DEBUG, () -> String.format("Sending '%s' RPC to %s for state version %d", + log.log(Level.FINE, () -> String.format("Sending '%s' RPC to %s for state version %d", req.methodName(), node.getRpcAddress(), stateBundle.getVersion())); RPCSetClusterStateRequest stateRequest = new RPCSetClusterStateRequest(node, req, baselineState.getVersion()); waiter.setRequest(stateRequest); @@ -171,14 +171,14 @@ public class RPCCommunicator implements Communicator { Target connection = getConnection(node); if ( ! connection.isValid()) { - log.log(LogLevel.DEBUG, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); + log.log(Level.FINE, () -> String.format("Connection to '%s' could not be created.", node.getRpcAddress())); return; } var req = new Request(ACTIVATE_CLUSTER_STATE_VERSION_RPC_METHOD_NAME); req.parameters().add(new Int32Value(clusterStateVersion)); - log.log(LogLevel.DEBUG, () -> String.format("Sending '%s' RPC to %s for state version %d", + log.log(Level.FINE, () -> String.format("Sending '%s' RPC to %s for state version %d", req.methodName(), node.getRpcAddress(), clusterStateVersion)); var activationRequest = new RPCActivateClusterStateVersionRequest(node, req, clusterStateVersion); waiter.setRequest(activationRequest); 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 d368d377aee..e3ae95b0abe 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(LogLevel.DEBUG, "Fleetcontroller " + fleetControllerIndex + ": Connecting RPC server."); + log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": Connecting RPC server."); if (supervisor != null) disconnect(); supervisor = new Supervisor(new Transport()); addMethods(); - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Fleetcontroller " + fleetControllerIndex + ": Disconnecting RPC server."); + log.log(Level.FINE, "Fleetcontroller " + fleetControllerIndex + ": Disconnecting RPC server."); register.shutdown(); register = null; } @@ -218,7 +218,7 @@ public class RpcServer { } try{ if (req.methodName().equals("getMaster")) { - log.log(LogLevel.DEBUG, "Resolving RPC getMaster request"); + log.log(Level.FINE, "Resolving RPC getMaster request"); Integer master = masterHandler.getMaster(); String masterReason = masterHandler.getMasterReason(); req.returnValues().add(new Int32Value(master == null ? -1 : master)); @@ -230,7 +230,7 @@ public class RpcServer { throw new IllegalStateException("Refusing to answer RPC calls as we are not the master fleetcontroller."); } if (req.methodName().equals("getNodeList")) { - log.log(LogLevel.DEBUG, "Resolving RPC getNodeList request"); + log.log(Level.FINE, "Resolving RPC getNodeList request"); List<String> slobrok = new ArrayList<String>(); List<String> rpc = new ArrayList<String>(); for(NodeInfo node : cluster.getNodeInfo()) { @@ -244,12 +244,12 @@ public class RpcServer { req.returnValues().add(new StringArray(rpc.toArray(new String[rpc.size()]))); req.returnRequest(); } else if (req.methodName().equals("getSystemState")) { - log.log(LogLevel.DEBUG, "Resolving RPC getSystemState request"); + log.log(Level.FINE, "Resolving RPC getSystemState request"); req.returnValues().add(new StringValue("")); req.returnValues().add(new StringValue(systemState.toString(true))); req.returnRequest(); } else if (req.methodName().equals("getNodeState")) { - log.log(LogLevel.DEBUG, "Resolving RPC getNodeState request"); + log.log(Level.FINE, "Resolving RPC getNodeState request"); NodeType nodeType = NodeType.get(req.parameters().get(0).asString()); int nodeIndex = req.parameters().get(1).asInt32(); @@ -296,7 +296,7 @@ public class RpcServer { changeListener.handleNewWantedNodeState(node, nodeState); } else { message = "Node " + node + " already had wanted state " + nodeState.toString(); - log.log(LogLevel.DEBUG, message); + log.log(Level.FINE, message); } req.returnValues().add(new StringValue(message)); req.returnRequest(); @@ -309,7 +309,7 @@ public class RpcServer { if (log.isLoggable(LogLevel.DEBUG)) { StringWriter sw = new StringWriter(); e.printStackTrace(new PrintWriter(sw)); - log.log(LogLevel.DEBUG, "Failed RPC Request: " + sw); + log.log(Level.FINE, "Failed RPC Request: " + sw); } String errorMsg = e.getMessage(); if (errorMsg == null) { errorMsg = e.toString(); } diff --git a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/status/statuspage/StatusPageServer.java b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/status/statuspage/StatusPageServer.java index c7f7682a62a..8e6cbc28a85 100644 --- a/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/status/statuspage/StatusPageServer.java +++ b/clustercontroller-core/src/main/java/com/yahoo/vespa/clustercontroller/core/status/statuspage/StatusPageServer.java @@ -85,7 +85,7 @@ public class StatusPageServer implements Runnable, StatusPageServerInterface { if (!isConnected()) { log.log(LogLevel.INFO, "Fleetcontroller: Server Socket not ready after connect()"); } - log.log(LogLevel.DEBUG, "Fleet controller status page viewer listening to " + ssocket.getLocalSocketAddress()); + log.log(Level.FINE, "Fleet controller status page viewer listening to " + ssocket.getLocalSocketAddress()); monitor.notifyAll(); } } @@ -149,7 +149,7 @@ public class StatusPageServer implements Runnable, StatusPageServerInterface { log.log(shouldBeConnected ? LogLevel.WARNING : LogLevel.DEBUG, "Caught IO exception in ServerSocket.accept(): " + e.getMessage()); } if (connection == null) continue; - log.log(LogLevel.DEBUG, "Got a status page request."); + log.log(Level.FINE, "Got a status page request."); String requestString = ""; OutputStream output = null; try (BufferedReader br = new BufferedReader(new InputStreamReader(connection.getInputStream()))) { @@ -168,7 +168,7 @@ public class StatusPageServer implements Runnable, StatusPageServerInterface { if (s == null || s.equals("")) break; sb.append(s).append("\n"); } - log.log(LogLevel.DEBUG, "Got HTTP request: " + sb.toString()); + log.log(Level.FINE, "Got HTTP request: " + sb.toString()); HttpRequest httpRequest = null; StatusPageResponse response = null; @@ -255,7 +255,7 @@ public class StatusPageServer implements Runnable, StatusPageServerInterface { } } } catch (InterruptedException e) { - log.log(LogLevel.DEBUG, "Status processing thread shut down by interrupt exception: " + e); + log.log(Level.FINE, "Status processing thread shut down by interrupt exception: " + e); } } 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 8d8835d5932..d6959ed1952 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 @@ -84,7 +84,7 @@ public class DummyVdsNode { private Thread messageResponder = new Thread() { public void run() { - log.log(LogLevel.DEBUG, "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; @@ -92,7 +92,7 @@ public class DummyVdsNode { for (Iterator<Req> it = waitingRequests.iterator(); it.hasNext(); ) { Req r = it.next(); if (r.timeout <= currentTime) { - log.log(LogLevel.DEBUG, "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")); @@ -109,7 +109,7 @@ public class DummyVdsNode { } } } - log.log(LogLevel.DEBUG, "Dummy node " + DummyVdsNode.this.toString() + ": shut down message reponder thread"); + log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": shut down message reponder thread"); } }; @@ -171,7 +171,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(LogLevel.DEBUG, "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); } @@ -190,7 +190,7 @@ public class DummyVdsNode { acceptor.shutdown().join(); supervisor.transport().shutdown().join(); supervisor = null; - log.log(LogLevel.DEBUG, "Dummy node " + DummyVdsNode.this.toString() + ": Done breaking connection."); + log.log(Level.FINE, "Dummy node " + DummyVdsNode.this.toString() + ": Done breaking connection."); } public String toString() { @@ -244,25 +244,25 @@ public class DummyVdsNode { private void waitForPendingGetNodeStateRequest(long timeout) { long startTime = System.currentTimeMillis(); long endTime = startTime + timeout; - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Dummy node " + this + " has pending request, returning."); + log.log(Level.FINE, "Dummy node " + this + " has pending request, returning."); return; } try{ - log.log(LogLevel.DEBUG, "Dummy node " + this + " waiting " + (endTime - startTime) + " ms for pending request."); + log.log(Level.FINE, "Dummy node " + this + " waiting " + (endTime - startTime) + " ms for pending request."); timer.wait(endTime - startTime); } catch (InterruptedException e) { } - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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."); } @@ -271,7 +271,7 @@ public class DummyVdsNode { void replyToPendingNodeStateRequests() { for(Req req : waitingRequests) { - log.log(LogLevel.DEBUG, "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)); @@ -283,7 +283,7 @@ public class DummyVdsNode { } public void setNodeState(NodeState state, String hostInfo) { - log.log(LogLevel.DEBUG, "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; @@ -415,7 +415,7 @@ public class DummyVdsNode { return; } String stateString = nodeState.serialize(-1, true); - log.log(LogLevel.DEBUG, "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)); @@ -427,7 +427,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(LogLevel.DEBUG, "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(); @@ -440,7 +440,7 @@ public class DummyVdsNode { } private void rpc_getNodeState2(Request req) { - log.log(LogLevel.DEBUG, "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(); @@ -452,14 +452,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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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")); @@ -526,7 +526,7 @@ public class DummyVdsNode { } req.returnValues().add(new Int32Value(1)); req.returnValues().add(new StringValue("OK")); - log.log(LogLevel.DEBUG, "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(LogLevel.ERROR, "Dummy node " + this + ": An error occurred when answering setsystemstate request: " + e.getMessage()); e.printStackTrace(System.err); @@ -550,7 +550,7 @@ public class DummyVdsNode { } timer.notifyAll(); } - log.log(LogLevel.DEBUG, "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(LogLevel.ERROR, "Dummy node " + this + ": An error occurred when answering setsystemstate request: " + e.getMessage()); e.printStackTrace(System.err); @@ -573,7 +573,7 @@ public class DummyVdsNode { } timer.notifyAll(); } - log.log(LogLevel.DEBUG, "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(LogLevel.ERROR, "Dummy node " + this + ": An error occurred when answering setdistributionstates request: " + e.getMessage()); e.printStackTrace(System.err); @@ -596,11 +596,11 @@ public class DummyVdsNode { activatedClusterStateVersion = activateVersion; timer.notifyAll(); } else { - log.log(LogLevel.DEBUG, () -> String.format("Dummy node %s: got a mismatching activation (request version %d, " + + log.log(Level.FINE, () -> String.format("Dummy node %s: got a mismatching activation (request version %d, " + "actual %d), not marking version as active", this, activateVersion, actualVersion)); } } - log.log(LogLevel.DEBUG, "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(LogLevel.ERROR, "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 bcf98d003a6..bda24b826fd 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 @@ -23,7 +23,7 @@ public class FakeTimer implements Timer { public synchronized void advanceTime(long time) { long currentTime = getCurrentTimeInMillis(); this.currentTime += time; - log.log(LogLevel.DEBUG, "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/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FleetControllerTest.java b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FleetControllerTest.java index d69725ebe20..6d8afa14f3e 100644 --- a/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FleetControllerTest.java +++ b/clustercontroller-core/src/test/java/com/yahoo/vespa/clustercontroller/core/FleetControllerTest.java @@ -135,13 +135,13 @@ public abstract class FleetControllerTest implements Waiter { } void setUpSystem(boolean useFakeTimer, FleetControllerOptions options) throws Exception { - log.log(LogLevel.DEBUG, "Setting up system"); + log.log(Level.FINE, "Setting up system"); slobrok = new Slobrok(); this.options = options; if (options.zooKeeperServerAddress != null) { zooKeeperServer = new ZooKeeperTestServer(); this.options.zooKeeperServerAddress = zooKeeperServer.getAddress(); - log.log(LogLevel.DEBUG, "Set up new zookeeper server at " + this.options.zooKeeperServerAddress); + log.log(Level.FINE, "Set up new zookeeper server at " + this.options.zooKeeperServerAddress); } this.options.slobrokConnectionSpecs = new String[1]; this.options.slobrokConnectionSpecs[0] = "tcp/localhost:" + slobrok.port(); 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 02862207e53..6a946e1ce75 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(LogLevel.DEBUG, "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 521bc141b2b..31349967462 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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 c2ad0817de5..79bf3f12649 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 @@ -282,7 +282,7 @@ public class FilesApplicationPackage implements ApplicationPackage { String dir = include.getAttribute(IncludeDirs.DIR); validateIncludeDir(dir); IncludeDirs.validateFilesInIncludedDir(dir, include.getParentNode(), this); - log.log(LogLevel.DEBUG, "Adding user include dir '" + dir + "'"); + log.log(Level.FINE, "Adding user include dir '" + dir + "'"); userIncludeDirs.add(dir); } @@ -458,7 +458,7 @@ public class FilesApplicationPackage implements ApplicationPackage { private void addAllDefsFromConfigDir(Map<ConfigDefinitionKey, UnparsedConfigDefinition> defs, File configDefsDir) { if (! configDefsDir.isDirectory()) return; - log.log(LogLevel.DEBUG, "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 23fe0109871..28f74b4adc0 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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,10 +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(LogLevel.DEBUG, "Using schemas found in " + schemaPath); + log.log(Level.FINE, "Using schemas found in " + schemaPath); copySchemas(schemaPath, tmpDir); } else { - log.log(LogLevel.DEBUG, String.format("Saving schemas for model bundle %s:%s", bundle.getSymbolicName(), bundle + 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 2925b394c83..454da0d657a 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(LogLevel.DEBUG, "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/builder/xml/XmlHelper.java b/config-model/src/main/java/com/yahoo/config/model/builder/xml/XmlHelper.java index 107908c91db..93f308a2c2e 100644 --- a/config-model/src/main/java/com/yahoo/config/model/builder/xml/XmlHelper.java +++ b/config-model/src/main/java/com/yahoo/config/model/builder/xml/XmlHelper.java @@ -121,7 +121,7 @@ public final class XmlHelper { public static synchronized DocumentBuilder getDocumentBuilder() { try { DocumentBuilder docBuilder = factory.newDocumentBuilder(); - log.log(LogLevel.DEBUG, "XML parser now operational!"); + log.log(Level.FINE, "XML parser now operational!"); return docBuilder; } catch (ParserConfigurationException e) { log.log(LogLevel.WARNING, "No XML parser available - " + e); diff --git a/config-model/src/main/java/com/yahoo/config/model/producer/AbstractConfigProducer.java b/config-model/src/main/java/com/yahoo/config/model/producer/AbstractConfigProducer.java index 43eeb613e6b..fc602ca8dcd 100644 --- a/config-model/src/main/java/com/yahoo/config/model/producer/AbstractConfigProducer.java +++ b/config-model/src/main/java/com/yahoo/config/model/producer/AbstractConfigProducer.java @@ -203,7 +203,7 @@ public abstract class AbstractConfigProducer<CHILD extends AbstractConfigProduce boolean foundHere = builder.dispatchGetConfig(this); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "cascadeconfig in " + this + ", getting config " + + log.log(Level.FINE, "cascadeconfig in " + this + ", getting config " + builder.getClass().getDeclaringClass().getName() + " for config id '" + configId + "' found here=" + foundHere); } found = found || foundHere; 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 058b456fdb8..2a0b8a236bc 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 @@ -357,7 +357,7 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri */ protected void checkId(String configId) { if ( ! id2producer.containsKey(configId)) { - log.log(LogLevel.DEBUG, "Invalid config id: " + configId); + log.log(Level.FINE, "Invalid config id: " + configId); } } @@ -382,7 +382,7 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri private static void populateConfigBuilder(Builder builder, ConfigProducer configProducer) { boolean found = configProducer.cascadeConfig(builder); boolean foundOverride = configProducer.addUserConfig(builder); - log.log(LogLevel.DEBUG, () -> "Trying to get config for " + builder.getClass().getDeclaringClass().getName() + + log.log(Level.FINE, () -> "Trying to get config for " + builder.getClass().getDeclaringClass().getName() + " for config id " + quote(configProducer.getConfigId()) + ", found=" + found + ", foundOverride=" + foundOverride); @@ -400,7 +400,7 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri ConfigInstance.Builder builder = resolveToBuilder(configKey); // TODO: remove if-statement, the builder can never be null. if (builder != null) { - log.log(LogLevel.DEBUG, () -> "Found builder for " + configKey); + log.log(Level.FINE, () -> "Found builder for " + configKey); ConfigPayload payload; InnerCNode innerCNode = targetDef != null ? targetDef.getCNode() : null; if (builder instanceof GenericConfig.GenericConfigBuilder) { @@ -429,7 +429,7 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri private ConfigPayload getConfigFromBuilder(ConfigInstance.Builder builder, InnerCNode targetDef) { try { ConfigInstance instance = InstanceResolver.resolveToInstance(builder, targetDef); - log.log(LogLevel.DEBUG, () -> "getConfigFromBuilder for builder " + builder.getClass().getName() + ", instance=" + instance); + log.log(Level.FINE, () -> "getConfigFromBuilder for builder " + builder.getClass().getName() + ", instance=" + instance); return ConfigPayload.fromInstance(instance); } catch (ConfigurationRuntimeException e) { // This can happen in cases where services ask for config that no longer exist before they have been able @@ -465,12 +465,12 @@ public final class VespaModel extends AbstractConfigProducerRoot implements Seri final String builderName = fullClassName + "$Builder"; if (classLoader == null) { classLoader = getClass().getClassLoader(); - log.log(LogLevel.DEBUG, () -> "No producer found to get classloader from for " + fullClassName + ". Using default"); + log.log(Level.FINE, () -> "No producer found to get classloader from for " + fullClassName + ". Using default"); } try { clazz = classLoader.loadClass(builderName); } catch (ClassNotFoundException e) { - log.log(LogLevel.DEBUG, () -> "Tried to load " + builderName + ", not found, trying with generic builder"); + log.log(Level.FINE, () -> "Tried to load " + builderName + ", not found, trying with generic builder"); // TODO: Enable config compiler when configserver is using new API. // ConfigCompiler compiler = new LazyConfigCompiler(Files.createTempDir()); // return compiler.compile(targetDef.generateClass()).newInstance(); 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 71e90686e22..8437df43df9 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 @@ -89,7 +89,7 @@ public class RankSetupValidator extends Validator { // Give up, don't say same error msg repeatedly deleteTempDir(tempDir); } - log.log(LogLevel.DEBUG, String.format("Validating %s for %s, %s took %s ms", + log.log(Level.FINE, String.format("Validating %s for %s, %s took %s ms", sdName, searchCluster, configId, 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 92785e00436..03b09a2bf2d 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(LogLevel.SPAM, "In getUserConfigs. producerSpec is null"); } - log.log(LogLevel.DEBUG, "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/VespaDomBuilder.java b/config-model/src/main/java/com/yahoo/vespa/model/builder/xml/dom/VespaDomBuilder.java index 9067df53a91..9ca5904a7c5 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(LogLevel.DEBUG, "Adding user configs " + userConfigs + " for " + producerSpec); + log.log(Level.FINE, "Adding user configs " + userConfigs + " for " + producerSpec); child.mergeUserConfigs(userConfigs); } 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 e27c26bd248..c8b16f5376a 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(LogLevel.DEBUG, "Ready for requests on " + spec); + log.log(Level.FINE, "Ready for requests on " + spec); supervisor.transport().join(); acceptor.shutdown().join(); } catch (ListenFailedException e) { @@ -270,7 +270,7 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer */ private void getConfigImpl(JRTServerConfigRequest request) { request.getRequestTrace().trace(TRACELEVEL, "Config proxy getConfig()"); - log.log(LogLevel.DEBUG, () ->"getConfig: " + request.getShortDescription() + ",configmd5=" + request.getRequestConfigMd5()); + log.log(Level.FINE, () ->"getConfig: " + request.getShortDescription() + ",configmd5=" + request.getRequestConfigMd5()); if (!request.validateParameters()) { // Error code is set in verifyParameters if parameters are not OK. log.log(LogLevel.WARNING, "Parameters for request " + request + " did not validate: " + request.errorCode() + " : " + request.errorMessage()); @@ -335,12 +335,12 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer */ @Override public void notifyTargetInvalid(Target target) { - log.log(LogLevel.DEBUG, () -> "Target invalid " + target); + log.log(Level.FINE, () -> "Target invalid " + target); for (Iterator<DelayedResponse> it = proxyServer.delayedResponses().responses().iterator(); it.hasNext(); ) { DelayedResponse delayed = it.next(); JRTServerConfigRequest request = delayed.getRequest(); if (request.getRequest().target().equals(target)) { - log.log(LogLevel.DEBUG, () -> "Removing " + request.getShortDescription()); + log.log(Level.FINE, () -> "Removing " + request.getShortDescription()); it.remove(); } } @@ -351,7 +351,7 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer public void returnOkResponse(JRTServerConfigRequest request, RawConfig config) { request.getRequestTrace().trace(TRACELEVEL, "Config proxy returnOkResponse()"); request.addOkResponse(config.getPayload(), config.getGeneration(), config.isInternalRedeploy(), config.getConfigMd5()); - log.log(LogLevel.DEBUG, () -> "Return response: " + request.getShortDescription() + ",configMd5=" + config.getConfigMd5() + + log.log(Level.FINE, () -> "Return response: " + request.getShortDescription() + ",configMd5=" + config.getConfigMd5() + ",generation=" + config.getGeneration()); log.log(LogLevel.SPAM, () -> "Config payload in response for " + request.getShortDescription() + ":" + config.getPayload()); @@ -361,7 +361,7 @@ public class ConfigProxyRpcServer implements Runnable, TargetWatcher, RpcServer try { request.getRequest().returnRequest(); } catch (IllegalStateException e) { - log.log(LogLevel.DEBUG, () -> "Something bad happened when sending response for '" + request.getShortDescription() + "':" + e.getMessage()); + log.log(Level.FINE, () -> "Something bad happened when sending response for '" + request.getShortDescription() + "':" + e.getMessage()); } } 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 e10289733df..50f8ad26bf0 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 @@ -50,7 +50,7 @@ public class MemoryCache { return; } - log.log(LogLevel.DEBUG, () -> "Putting '" + config + "' into memory cache"); + log.log(Level.FINE, () -> "Putting '" + config + "' into memory cache"); cache.put(new ConfigCacheKey(config.getKey(), config.getDefMd5()), config); } @@ -114,11 +114,11 @@ public class MemoryCache { try { filename = path + File.separator + createCacheFileName(config); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Writing '" + config.getKey() + "' to '" + filename + "'"); + log.log(Level.FINE, "Writing '" + config.getKey() + "' to '" + filename + "'"); } final Payload payload = config.getPayload(); long protocolVersion = 3; - log.log(LogLevel.DEBUG, "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/MemoryCacheConfigClient.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCacheConfigClient.java index 16b80f8d31e..df0b274f32b 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCacheConfigClient.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/MemoryCacheConfigClient.java @@ -32,11 +32,11 @@ class MemoryCacheConfigClient implements ConfigSourceClient { */ @Override public RawConfig getConfig(RawConfig input, JRTServerConfigRequest request) { - log.log(LogLevel.DEBUG, () -> "Getting config from cache"); + log.log(Level.FINE, () -> "Getting config from cache"); ConfigKey<?> key = input.getKey(); RawConfig cached = cache.get(new ConfigCacheKey(key, input.getDefMd5())); if (cached != null) { - log.log(LogLevel.DEBUG, () -> "Found config " + key + " in cache"); + log.log(Level.FINE, () -> "Found config " + key + " in cache"); return cached; } else { return null; 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 ddc0c0d8320..1ebf3106a94 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 @@ -48,7 +48,7 @@ public class ProxyServer implements Runnable { ProxyServer(Spec spec, ConfigSourceSet source, MemoryCache memoryCache, ConfigSourceClient configClient) { this.configSource = source; - log.log(LogLevel.DEBUG, "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/RpcConfigSourceClient.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/RpcConfigSourceClient.java index ddf3bc4d9ce..d37408f97b3 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/RpcConfigSourceClient.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/RpcConfigSourceClient.java @@ -92,7 +92,7 @@ class RpcConfigSourceClient implements ConfigSourceClient { Target target = supervisor.connect(spec); target.invokeSync(req, 30.0); if (target.isValid()) { - log.log(LogLevel.DEBUG, () -> "Created connection to config source at " + spec.toString()); + log.log(Level.FINE, () -> "Created connection to config source at " + spec.toString()); return; } else { log.log(LogLevel.INFO, "Could not connect to config source at " + spec.toString()); @@ -132,7 +132,7 @@ class RpcConfigSourceClient implements ConfigSourceClient { RawConfig ret = null; if (cachedConfig != null) { - log.log(LogLevel.DEBUG, () -> "Found config " + configCacheKey + " in cache, generation=" + cachedConfig.getGeneration() + + log.log(Level.FINE, () -> "Found config " + configCacheKey + " in cache, generation=" + cachedConfig.getGeneration() + ",configmd5=" + cachedConfig.getConfigMd5()); log.log(LogLevel.SPAM, () -> "input config=" + input + ",cached config=" + cachedConfig); if (ProxyServer.configOrGenerationHasChanged(cachedConfig, request)) { @@ -155,9 +155,9 @@ class RpcConfigSourceClient implements ConfigSourceClient { private void subscribeToConfig(RawConfig input, ConfigCacheKey configCacheKey) { synchronized (activeSubscribersLock) { if (activeSubscribers.containsKey(configCacheKey)) { - log.log(LogLevel.DEBUG, () -> "Already a subscriber running for: " + configCacheKey); + log.log(Level.FINE, () -> "Already a subscriber running for: " + configCacheKey); } else { - log.log(LogLevel.DEBUG, () -> "Could not find good config in cache, creating subscriber for: " + configCacheKey); + log.log(Level.FINE, () -> "Could not find good config in cache, creating subscriber for: " + configCacheKey); UpstreamConfigSubscriber subscriber = new UpstreamConfigSubscriber(input, this, configSourceSet, timingValues, requester, memoryCache); try { @@ -215,14 +215,14 @@ class RpcConfigSourceClient implements ConfigSourceClient { * @param config new config */ public void updateSubscribers(RawConfig config) { - log.log(LogLevel.DEBUG, () -> "Config updated for " + config.getKey() + "," + config.getGeneration()); + log.log(Level.FINE, () -> "Config updated for " + config.getKey() + "," + config.getGeneration()); DelayQueue<DelayedResponse> responseDelayQueue = delayedResponses.responses(); log.log(LogLevel.SPAM, () -> "Delayed response queue: " + responseDelayQueue); if (responseDelayQueue.size() == 0) { - log.log(LogLevel.DEBUG, () -> "There exists no matching element on delayed response queue for " + config.getKey()); + log.log(Level.FINE, () -> "There exists no matching element on delayed response queue for " + config.getKey()); return; } else { - log.log(LogLevel.DEBUG, () -> "Delayed response queue has " + responseDelayQueue.size() + " elements"); + log.log(Level.FINE, () -> "Delayed response queue has " + responseDelayQueue.size() + " elements"); } boolean found = false; for (DelayedResponse response : responseDelayQueue.toArray(new DelayedResponse[0])) { @@ -232,7 +232,7 @@ class RpcConfigSourceClient implements ConfigSourceClient { && (config.getGeneration() >= request.getRequestGeneration() || config.getGeneration() == 0)) { if (delayedResponses.remove(response)) { found = true; - log.log(LogLevel.DEBUG, () -> "Call returnOkResponse for " + config.getKey() + "," + config.getGeneration()); + log.log(Level.FINE, () -> "Call returnOkResponse for " + config.getKey() + "," + config.getGeneration()); rpcServer.returnOkResponse(request, config); } else { log.log(LogLevel.INFO, "Could not remove " + config.getKey() + " from delayedResponses queue, already removed"); @@ -240,9 +240,9 @@ class RpcConfigSourceClient implements ConfigSourceClient { } } if (!found) { - log.log(LogLevel.DEBUG, () -> "Found no recipient for " + config.getKey() + " in delayed response queue"); + log.log(Level.FINE, () -> "Found no recipient for " + config.getKey() + " in delayed response queue"); } - log.log(LogLevel.DEBUG, () -> "Finished updating config for " + config.getKey() + "," + config.getGeneration()); + log.log(Level.FINE, () -> "Finished updating config for " + config.getKey() + "," + config.getGeneration()); } @Override diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/UpstreamConfigSubscriber.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/UpstreamConfigSubscriber.java index c7567c45c27..14d93ee046e 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/UpstreamConfigSubscriber.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/UpstreamConfigSubscriber.java @@ -65,7 +65,7 @@ public class UpstreamConfigSubscriber implements Subscriber { private void updateWithNewConfig(GenericConfigHandle handle) { RawConfig newConfig = handle.getRawConfig(); - log.log(LogLevel.DEBUG, () -> "config to be returned for '" + newConfig.getKey() + + log.log(Level.FINE, () -> "config to be returned for '" + newConfig.getKey() + "', generation=" + newConfig.getGeneration() + ", payload=" + newConfig.getPayload()); memoryCache.update(newConfig); 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 c2daa6e739b..146a5e644ef 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(LogLevel.DEBUG, "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-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/FileDistributionRpcServer.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/FileDistributionRpcServer.java index 6f5b125cc1e..3b8a882963c 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/FileDistributionRpcServer.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/FileDistributionRpcServer.java @@ -106,7 +106,7 @@ class FileDistributionRpcServer { } private void setFileReferencesToDownload(Request req) { - log.log(LogLevel.DEBUG, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); + log.log(Level.FINE, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); Arrays.stream(req.parameters().get(0).asStringArray()) .map(FileReference::new) .forEach(fileReference -> downloader.downloadIfNeeded(new FileReferenceDownload(fileReference))); @@ -115,12 +115,12 @@ class FileDistributionRpcServer { private void downloadFile(Request req) { FileReference fileReference = new FileReference(req.parameters().get(0).asString()); - log.log(LogLevel.DEBUG, () -> "getFile() called for file reference '" + fileReference.value() + "'"); + log.log(Level.FINE, () -> "getFile() called for file reference '" + fileReference.value() + "'"); Optional<File> file = downloader.getFile(fileReference); if (file.isPresent()) { new RequestTracker().trackRequest(file.get().getParentFile()); req.returnValues().add(new StringValue(file.get().getAbsolutePath())); - log.log(LogLevel.DEBUG, () -> "File reference '" + fileReference.value() + "' available at " + file.get()); + log.log(Level.FINE, () -> "File reference '" + fileReference.value() + "' available at " + file.get()); } else { log.log(LogLevel.INFO, "File reference '" + fileReference.value() + "' not found, returning error"); req.setError(fileReferenceDoesNotExists, "File reference '" + fileReference.value() + "' not found"); diff --git a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/UrlDownloadRpcServer.java b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/UrlDownloadRpcServer.java index 970e4da5511..74393ca07f9 100644 --- a/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/UrlDownloadRpcServer.java +++ b/config-proxy/src/main/java/com/yahoo/vespa/config/proxy/filedistribution/UrlDownloadRpcServer.java @@ -111,7 +111,7 @@ class UrlDownloadRpcServer { writeLastModifiedTimestamp(downloadDir, connection.getLastModified()); new RequestTracker().trackRequest(downloadDir); req.returnValues().add(new StringValue(contentsPath.getAbsolutePath())); - log.log(LogLevel.DEBUG, () -> "URL '" + url + "' available at " + contentsPath); + log.log(Level.FINE, () -> "URL '" + url + "' available at " + contentsPath); log.log(LogLevel.INFO, String.format("Download of URL '%s' done in %.3f seconds", url, (System.currentTimeMillis() -start) / 1000.0)); } else { 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 8db1ac5c0a0..be607907854 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 @@ -450,14 +450,14 @@ public class ApplicationRepository implements com.yahoo.config.provision.Deploye log.log(LogLevel.WARNING, "Getting file references in use for '" + application + "' failed", e); } } - log.log(LogLevel.DEBUG, "File references in use : " + fileReferencesInUse); + log.log(Level.FINE, "File references in use : " + fileReferencesInUse); // Find those on disk that are not in use Set<String> fileReferencesOnDisk = new HashSet<>(); File[] filesOnDisk = fileReferencesPath.listFiles(); if (filesOnDisk != null) fileReferencesOnDisk.addAll(Arrays.stream(filesOnDisk).map(File::getName).collect(Collectors.toSet())); - log.log(LogLevel.DEBUG, "File references on disk (in " + fileReferencesPath + "): " + fileReferencesOnDisk); + log.log(Level.FINE, "File references on disk (in " + fileReferencesPath + "): " + fileReferencesOnDisk); Instant instant = Instant.now().minus(keepFileReferences); Set<String> fileReferencesToDelete = fileReferencesOnDisk @@ -783,7 +783,7 @@ public class ApplicationRepository implements com.yahoo.config.provision.Deploye } private void cleanupTempDirectory(File tempDir) { - logger.log(LogLevel.DEBUG, "Deleting tmp dir '" + tempDir + "'"); + logger.log(Level.FINE, "Deleting tmp dir '" + tempDir + "'"); if (!IOUtils.recursiveDeleteDir(tempDir)) { logger.log(LogLevel.WARNING, "Not able to delete tmp dir '" + tempDir + "'"); } 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 a3fbe9ec5fb..98c751dcee5 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 @@ -97,7 +97,7 @@ public class ConfigServerBootstrap extends AbstractComponent implements Runnable this.sleepTimeWhenRedeployingFails = Duration.ofSeconds(configserverConfig.sleepTimeWhenRedeployingFails()); this.exitIfRedeployingApplicationsFails = exitIfRedeployingApplicationsFails; rpcServerExecutor = Executors.newSingleThreadExecutor(new DaemonThreadFactory("config server RPC server")); - log.log(LogLevel.DEBUG, "Bootstrap mode: " + mode + ", VIP status mode: " + vipStatusMode); + log.log(Level.FINE, "Bootstrap mode: " + mode + ", VIP status mode: " + vipStatusMode); initializing(vipStatusMode); switch (mode) { case BOOTSTRAP_IN_SEPARATE_THREAD: @@ -121,7 +121,7 @@ public class ConfigServerBootstrap extends AbstractComponent implements Runnable log.log(LogLevel.INFO, "Stopping config server"); down(); server.stop(); - log.log(LogLevel.DEBUG, "RPC server stopped"); + log.log(Level.FINE, "RPC server stopped"); rpcServerExecutor.shutdown(); serverThread.ifPresent(thread -> { try { 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 72d91e99278..6cf0ad5fab7 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(LogLevel.DEBUG, "Found " + bundles.size() + " bundles"); + log.log(Level.FINE, "Found " + bundles.size() + " bundles"); List<Bundle> addedBundles = new ArrayList<>(); for (Bundle bundle : bundles) { - log.log(LogLevel.DEBUG, "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/SuperModelRequestHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/SuperModelRequestHandler.java index aa6c2c1a2b2..6fcfde80510 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/SuperModelRequestHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/SuperModelRequestHandler.java @@ -74,10 +74,10 @@ public class SuperModelRequestHandler implements RequestHandler { @Override public ConfigResponse resolveConfig(ApplicationId appId, GetConfigRequest req, Optional<Version> vespaVersion) { - log.log(LogLevel.DEBUG, () -> "SuperModelRequestHandler resolving " + req + " for app id '" + appId + "'"); + log.log(Level.FINE, () -> "SuperModelRequestHandler resolving " + req + " for app id '" + appId + "'"); if (handler != null) { ConfigResponse configResponse = handler.resolveConfig(req); - log.log(LogLevel.DEBUG, () -> "SuperModelRequestHandler returning response for config " + req + + log.log(Level.FINE, () -> "SuperModelRequestHandler returning response for config " + req + " with generation " + configResponse.getGeneration()); return configResponse; } 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 ef9c5161e98..10cfcc96a09 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 @@ -153,7 +153,7 @@ public class Application implements ModelResult { } private void debug(String message) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(getId())+message); + log.log(Level.FINE, TenantRepository.logPre(getId())+message); } private ConfigDefinition getTargetDef(GetConfigRequest req) { 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 931d85dbe45..2cab0ea5e20 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 @@ -84,23 +84,23 @@ public class CompressedApplicationInputStream implements AutoCloseable { } private void decompressInto(File application) throws IOException { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Unpacking " + entry.getName()); + log.log(Level.FINE, "Unpacking " + 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(LogLevel.DEBUG, "Creating dir: " + outFile.getAbsolutePath()); + log.log(Level.FINE, "Creating dir: " + outFile.getAbsolutePath()); boolean res = outFile.mkdirs(); if (!res) { log.log(LogLevel.WARNING, "Could not create dir " + entry.getName()); } } } else { - log.log(LogLevel.DEBUG, "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/ConfigConvergenceChecker.java b/configserver/src/main/java/com/yahoo/vespa/config/server/application/ConfigConvergenceChecker.java index 9ffca3d5ea5..824cc932ecc 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/application/ConfigConvergenceChecker.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/application/ConfigConvergenceChecker.java @@ -72,7 +72,7 @@ public class ConfigConvergenceChecker extends AbstractComponent { /** Check all services in given application. Returns the minimum current generation of all services */ public ServiceListResponse servicesToCheck(Application application, URI requestUrl, Duration timeoutPerService) { - log.log(LogLevel.DEBUG, () -> "Finding services to check config convergence for in '" + application); + log.log(Level.FINE, () -> "Finding services to check config convergence for in '" + application); List<ServiceInfo> servicesToCheck = new ArrayList<>(); application.getModel().getHosts() .forEach(host -> host.getServices().stream() 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 52aae860480..ac994e8405d 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(LogLevel.DEBUG, "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 a1b7df5f19d..318cd367e30 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 @@ -175,7 +175,7 @@ public class TenantApplications { } private void applicationAdded(ApplicationId applicationId) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(applicationId) + "Application added: " + applicationId); + log.log(Level.FINE, TenantRepository.logPre(applicationId) + "Application added: " + applicationId); } private Path applicationPath(ApplicationId id) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/deploy/Deployment.java b/configserver/src/main/java/com/yahoo/vespa/config/server/deploy/Deployment.java index 5f2bece849b..37dd0502ee8 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/deploy/Deployment.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/deploy/Deployment.java @@ -196,12 +196,12 @@ public class Deployment implements com.yahoo.config.provision.Deployment { private void checkIfActiveHasChanged(LocalSession session, LocalSession currentActiveSession, boolean ignoreStaleSessionFailure) { long activeSessionAtCreate = session.getActiveSessionAtCreate(); - log.log(LogLevel.DEBUG, currentActiveSession.logPre() + "active session id at create time=" + activeSessionAtCreate); + log.log(Level.FINE, currentActiveSession.logPre() + "active session id at create time=" + activeSessionAtCreate); if (activeSessionAtCreate == 0) return; // No active session at create long sessionId = session.getSessionId(); long currentActiveSessionSessionId = currentActiveSession.getSessionId(); - log.log(LogLevel.DEBUG, currentActiveSession.logPre() + "sessionId=" + sessionId + + log.log(Level.FINE, currentActiveSession.logPre() + "sessionId=" + sessionId + ", current active session=" + currentActiveSessionSessionId); if (currentActiveSession.isNewerThan(activeSessionAtCreate) && currentActiveSessionSessionId != sessionId) { 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 25747113d9e..c4279414a9b 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 @@ -82,7 +82,7 @@ public class FileDirectory { if (file.isDirectory()) { return Files.walk(file.toPath(), 100).map(path -> { try { - log.log(LogLevel.DEBUG, "Calculating hash for '" + path + "'"); + log.log(Level.FINE, "Calculating hash for '" + path + "'"); return hash(path.toFile(), hasher); } catch (IOException e) { log.log(LogLevel.WARNING, "Failed getting hash from '" + path + "'"); @@ -143,15 +143,15 @@ public class FileDirectory { File destination = new File(tempDestinationDir.toFile(), source.getName()); if (!destinationDir.exists()) { destinationDir.mkdir(); - log.log(LogLevel.DEBUG, "file reference ' " + reference.value() + "', source: " + source.getAbsolutePath() ); + log.log(Level.FINE, "file reference ' " + reference.value() + "', source: " + source.getAbsolutePath() ); if (source.isDirectory()) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "Moving from " + tempDestinationDir + " to " + destinationDir.getAbsolutePath()); + log.log(Level.FINE, "Moving from " + tempDestinationDir + " to " + destinationDir.getAbsolutePath()); if ( ! tempDestinationDir.toFile().renameTo(destinationDir)) { log.log(LogLevel.WARNING, "Failed moving '" + tempDestinationDir.toFile().getAbsolutePath() + "' to '" + destination.getAbsolutePath() + "'."); } @@ -168,7 +168,7 @@ public class FileDirectory { private void logfileInfo(File file ) throws IOException { BasicFileAttributes basicFileAttributes = Files.readAttributes(file.toPath(), BasicFileAttributes.class); - log.log(LogLevel.DEBUG, "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 3040a43bde4..56bdeab76b2 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, 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 465c8a02200..6cde8cca18f 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 @@ -101,7 +101,7 @@ public class FileServer { try { return root.getFile(reference).exists(); } catch (IllegalArgumentException e) { - log.log(LogLevel.DEBUG, "Failed locating file reference '" + reference + "' with error " + e.toString()); + log.log(Level.FINE, "Failed locating file reference '" + reference + "' with error " + e.toString()); } return false; } @@ -117,7 +117,7 @@ public class FileServer { private void serveFile(FileReference reference, Receiver target) { File file = root.getFile(reference); - log.log(LogLevel.DEBUG, () -> "Start serving reference '" + reference.value() + "' with file '" + file.getAbsolutePath() + "'"); + log.log(Level.FINE, () -> "Start serving reference '" + reference.value() + "' with file '" + file.getAbsolutePath() + "'"); boolean success = false; String errorDescription = "OK"; FileReferenceData fileData = FileReferenceDataBlob.empty(reference, file.getName()); @@ -131,7 +131,7 @@ public class FileServer { try { target.receive(fileData, new ReplayStatus(success ? 0 : 1, success ? "OK" : errorDescription)); - log.log(LogLevel.DEBUG, "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(LogLevel.WARNING, "Failed serving file reference '" + reference.value() + "': " + Exceptions.toMessageString(e)); } finally { @@ -156,7 +156,7 @@ public class FileServer { } private void serveFileInternal(String fileReference, boolean downloadFromOtherSourceIfNotFound, Request request, Receiver receiver) { - log.log(LogLevel.DEBUG, () -> "Received request for reference '" + fileReference + "' from " + request.target()); + log.log(Level.FINE, () -> "Received request for reference '" + fileReference + "' from " + request.target()); boolean fileExists; try { @@ -178,10 +178,10 @@ public class FileServer { // This is to avoid config servers asking each other for a file that does not exist private boolean download(String fileReference, boolean downloadFromOtherSourceIfNotFound) { if (downloadFromOtherSourceIfNotFound) { - log.log(LogLevel.DEBUG, "File not found, downloading from another source"); + log.log(Level.FINE, "File not found, downloading from another source"); return download(fileReference).isPresent(); } else { - log.log(LogLevel.DEBUG, "File not found, will not download from another source since request came from another config server"); + log.log(Level.FINE, "File not found, will not download from another source since request came from another config server"); return false; } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/host/HostRegistry.java b/configserver/src/main/java/com/yahoo/vespa/config/server/host/HostRegistry.java index cb33371aee9..ec37f2598e0 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/host/HostRegistry.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/host/HostRegistry.java @@ -28,7 +28,7 @@ public class HostRegistry<T> implements HostValidator<T> { public synchronized void update(T key, Collection<String> newHosts) { verifyHosts(key, newHosts); Collection<String> currentHosts = getHostsForKey(key); - log.log(LogLevel.DEBUG, () -> "Setting hosts for key '" + key + "', " + + log.log(Level.FINE, () -> "Setting hosts for key '" + key + "', " + "newHosts: " + newHosts + ", " + "currentHosts: " + currentHosts); Collection<String> removedHosts = getRemovedHosts(newHosts, currentHosts); @@ -71,14 +71,14 @@ public class HostRegistry<T> implements HostValidator<T> { private void removeHosts(Collection<String> removedHosts) { for (String host : removedHosts) { - log.log(LogLevel.DEBUG, () -> "Removing " + host); + log.log(Level.FINE, () -> "Removing " + host); host2KeyMap.remove(host); } } private void addHosts(T key, Collection<String> newHosts) { for (String host : newHosts) { - log.log(LogLevel.DEBUG, () -> "Adding " + host); + log.log(Level.FINE, () -> "Adding " + host); host2KeyMap.put(host, key); } } 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 592aed83024..7458c82942f 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(LogLevel.DEBUG, "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 78bc0f48232..e1a5845c4a1 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(LogLevel.DEBUG, 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 7fc9c4ead47..075b4bc329b 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 @@ -30,7 +30,7 @@ class SessionContentStatusListResponse extends SessionResponse { element.setString("status", f.getMetaData().getStatus()); element.setString("md5", f.getMetaData().getMd5()); element.setString("name", urlBase + f.getPath()); - log.log(LogLevel.DEBUG, "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 577a0fdd17a..514e0c1c8ae 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 @@ -59,7 +59,7 @@ public class TesterClient { } private HttpResponse execute(HttpUriRequest request, String messageIfRequestFails) { - logger.log(LogLevel.DEBUG, "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/HostHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HostHandler.java index ddeb49fda6f..ffe3d39b524 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HostHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/http/v2/HostHandler.java @@ -39,22 +39,22 @@ public class HostHandler extends HttpHandler { @Override public HttpResponse handleGET(HttpRequest request) { String hostname = getBindingMatch(request).group(2); - log.log(LogLevel.DEBUG, "hostname=" + hostname); + log.log(Level.FINE, "hostname=" + hostname); HostRegistry<TenantName> tenantHostRegistry = hostRegistries.getTenantHostRegistry(); - log.log(LogLevel.DEBUG, "hosts in tenant host registry '" + tenantHostRegistry + "' " + tenantHostRegistry.getAllHosts()); + log.log(Level.FINE, "hosts in tenant host registry '" + tenantHostRegistry + "' " + tenantHostRegistry.getAllHosts()); TenantName tenant = tenantHostRegistry.getKeyForHost(hostname); if (tenant == null) return createError(hostname); - log.log(LogLevel.DEBUG, "tenant=" + tenant); + log.log(Level.FINE, "tenant=" + tenant); HostRegistry<ApplicationId> applicationIdHostRegistry = hostRegistries.getApplicationHostRegistry(tenant); ApplicationId applicationId; if (applicationIdHostRegistry == null) return createError(hostname); applicationId = applicationIdHostRegistry.getKeyForHost(hostname); - log.log(LogLevel.DEBUG, "applicationId=" + applicationId); + log.log(Level.FINE, "applicationId=" + applicationId); if (applicationId == null) { return createError(hostname); } else { - log.log(LogLevel.DEBUG, "hosts in application host registry '" + applicationIdHostRegistry + "' " + applicationIdHostRegistry.getAllHosts()); + log.log(Level.FINE, "hosts in application host registry '" + applicationIdHostRegistry + "' " + applicationIdHostRegistry.getAllHosts()); return new HostResponse(Response.Status.OK, applicationId, zone); } } 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 5b4c32da7e1..b4ce833cb75 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(LogLevel.DEBUG, "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/metrics/ClusterMetricsRetriever.java b/configserver/src/main/java/com/yahoo/vespa/config/server/metrics/ClusterMetricsRetriever.java index 15ed5fd2408..42d3ace6bd9 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/metrics/ClusterMetricsRetriever.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/metrics/ClusterMetricsRetriever.java @@ -76,7 +76,7 @@ public class ClusterMetricsRetriever { throw new RuntimeException(e); } - log.log(LogLevel.DEBUG, () -> + log.log(Level.FINE, () -> String.format("Metric retrieval for %d nodes took %d milliseconds", hosts.size(), System.currentTimeMillis() - startTime) ); 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 e4276687c38..77d84206fec 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 @@ -88,7 +88,7 @@ public class ActivatedModelsBuilder extends ModelsBuilder<Application> { Version wantedNodeVespaVersion, Optional<AllocatedHosts> ignored, // Ignored since we have this in the app package for activated models Instant now) { - log.log(LogLevel.DEBUG, String.format("Loading model version %s for session %s application %s", + log.log(Level.FINE, String.format("Loading model version %s for session %s application %s", modelFactory.version(), appGeneration, applicationId)); ModelContext.Properties modelContextProperties = createModelContextProperties(applicationId); Provisioned provisioned = new Provisioned(); 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 2662e14e8e9..361153d2817 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 @@ -78,7 +78,7 @@ public abstract class ModelsBuilder<MODELRESULT extends ModelResult> { ApplicationPackage applicationPackage, SettableOptional<AllocatedHosts> allocatedHosts, Instant now) { - log.log(LogLevel.DEBUG, "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 @@ -130,7 +130,7 @@ public abstract class ModelsBuilder<MODELRESULT extends ModelResult> { } } } - log.log(LogLevel.DEBUG, "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 032e7232744..34d7d8641ea 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 @@ -89,7 +89,7 @@ public class PreparedModelsBuilder extends ModelsBuilder<PreparedModelsBuilder.P Optional<AllocatedHosts> allocatedHosts, Instant now) { Version modelVersion = modelFactory.version(); - log.log(LogLevel.DEBUG, "Building model " + modelVersion + " for " + applicationId); + log.log(Level.FINE, "Building model " + modelVersion + " for " + applicationId); FileDistributionProvider fileDistributionProvider = fileDistributionFactory.createProvider(context.getServerDBSessionDir()); // Use empty on non-hosted systems, use already allocated hosts if available, create connection to a host provisioner otherwise @@ -109,12 +109,12 @@ public class PreparedModelsBuilder extends ModelsBuilder<PreparedModelsBuilder.P modelVersion, wantedNodeVespaVersion); - log.log(LogLevel.DEBUG, "Create and validate model " + modelVersion + " for " + applicationId); + log.log(Level.FINE, "Create and validate model " + modelVersion + " for " + applicationId); ValidationParameters validationParameters = new ValidationParameters(params.ignoreValidationErrors() ? IgnoreValidationErrors.TRUE : IgnoreValidationErrors.FALSE); ModelCreateResult result = modelFactory.createAndValidateModel(modelContext, validationParameters); validateModelHosts(context.getHostValidator(), applicationId, result.getModel()); - log.log(LogLevel.DEBUG, "Done building model " + modelVersion + " for " + applicationId); + log.log(Level.FINE, "Done building model " + modelVersion + " for " + applicationId); return new PreparedModelsBuilder.PreparedModelResult(modelVersion, result.getModel(), fileDistributionProvider, result.getConfigChangeActions()); } 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 fd840a6385a..8b9580c9688 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(LogLevel.DEBUG, "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); @@ -134,9 +134,9 @@ public class Metrics extends AbstractComponent implements MetricUpdaterFactory, @Override public void run() { for (MetricUpdater metricUpdater : metricUpdaters.values()) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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 03b11a89d08..3c18d5f11d2 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 @@ -89,7 +89,7 @@ public class DelayedConfigResponses { removeWatcher(); rpcServer.addToRequestQueue(request, true, null); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, logPre()+"DelayedConfigResponse. putting on queue: " + request.getShortDescription()); + log.log(Level.FINE, logPre()+"DelayedConfigResponse. putting on queue: " + request.getShortDescription()); } } @@ -169,7 +169,7 @@ public class DelayedConfigResponses { */ final void delayResponse(JRTServerConfigRequest request, GetConfigContext context) { if (request.isDelayedResponse()) { - log.log(LogLevel.DEBUG, context.logPre()+"Request already delayed"); + log.log(Level.FINE, context.logPre()+"Request already delayed"); } else { createQueueIfNotExists(context); BlockingQueue<DelayedConfigResponse> delayedResponsesQueue = delayedResponses.get(context.applicationId()); @@ -177,7 +177,7 @@ public class DelayedConfigResponses { request.setDelayedResponse(true); try { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, context.logPre()+"Putting on delayedRequests queue (" + delayedResponsesQueue.size() + " elements): " + + log.log(Level.FINE, context.logPre()+"Putting on delayedRequests queue (" + delayedResponsesQueue.size() + " elements): " + response.getRequest().getShortDescription()); } // Config will be resolved in the run() method of DelayedConfigResponse, 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 ff39faa9d29..f2099388c7c 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 @@ -164,7 +164,7 @@ class GetConfigProcessor implements Runnable { } private void returnEmpty(JRTServerConfigRequest request) { - log.log(LogLevel.DEBUG, () -> "Returning empty sentinel config for request from " + request.getClientHostName()); + log.log(Level.FINE, () -> "Returning empty sentinel config for request from " + request.getClientHostName()); ConfigPayload emptyPayload = ConfigPayload.empty(); String configMd5 = ConfigUtils.getMd5(emptyPayload); ConfigResponse config = SlimeConfigResponse.fromConfigPayload(emptyPayload, 0, false, configMd5); @@ -178,7 +178,7 @@ class GetConfigProcessor implements Runnable { private void debugLog(Trace trace, String message) { if (logDebug(trace)) { - log.log(LogLevel.DEBUG, 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 f2cabe77f36..6082e4d34e5 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 @@ -263,7 +263,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { List<DelayedConfigResponses.DelayedConfigResponse> responses = delayedConfigResponses.drainQueue(applicationId); String logPre = TenantRepository.logPre(applicationId); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, logPre + "Start of configReload: " + responses.size() + " requests on delayed requests queue"); + log.log(Level.FINE, logPre + "Start of configReload: " + responses.size() + " requests on delayed requests queue"); } int responsesSent = 0; CompletionService<Boolean> completionService = new ExecutorCompletionService<>(executorService); @@ -281,7 +281,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { responsesSent++; } } else { - log.log(LogLevel.DEBUG, logPre + "Timer already cancelled or finished or never scheduled"); + log.log(Level.FINE, logPre + "Timer already cancelled or finished or never scheduled"); } } @@ -293,7 +293,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { } } - log.log(LogLevel.DEBUG, logPre + "Finished reloading " + responsesSent + " requests"); + log.log(Level.FINE, logPre + "Finished reloading " + responsesSent + " requests"); } private void logRequestDebug(LogLevel level, String message, JRTServerConfigRequest request) { @@ -304,7 +304,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { @Override public void hostsUpdated(TenantName tenant, Collection<String> newHosts) { - log.log(LogLevel.DEBUG, "Updating hosts in tenant host registry '" + hostRegistry + "' with " + newHosts); + log.log(Level.FINE, "Updating hosts in tenant host registry '" + hostRegistry + "' with " + newHosts); hostRegistry.update(tenant, newHosts); } @@ -322,7 +322,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { public void respond(JRTServerConfigRequest request) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Trace at request return:\n" + request.getRequestTrace().toString()); + log.log(Level.FINE, "Trace at request return:\n" + request.getRequestTrace().toString()); } request.getRequest().returnRequest(); } @@ -338,8 +338,8 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { if (tenant == null) { if (GetConfigProcessor.logDebug(trace)) { String message = "Did not find tenant for host '" + hostname + "', using " + TenantName.defaultName(); - log.log(LogLevel.DEBUG, message); - log.log(LogLevel.DEBUG, "hosts in host registry: " + hostRegistry.getAllHosts()); + log.log(Level.FINE, message); + log.log(Level.FINE, "hosts in host registry: " + hostRegistry.getAllHosts()); trace.trace(6, message); } return Optional.empty(); @@ -420,7 +420,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { @Override public void onTenantDelete(TenantName tenant) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant)+"Tenant deleted, removing request handler and cleaning host registry"); + log.log(Level.FINE, TenantRepository.logPre(tenant)+"Tenant deleted, removing request handler and cleaning host registry"); tenantProviders.remove(tenant); hostRegistry.removeHostsForKey(tenant); } @@ -433,7 +433,7 @@ public class RpcServer implements Runnable, ReloadListener, TenantListener { @Override public void onTenantCreate(TenantName tenant, TenantHandlerProvider tenantHandlerProvider) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant)+"Tenant created, adding request handler"); + log.log(Level.FINE, TenantRepository.logPre(tenant)+"Tenant created, adding request handler"); tenantProviders.put(tenant, tenantHandlerProvider); } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/security/MultiTenantRpcAuthorizer.java b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/security/MultiTenantRpcAuthorizer.java index 4a030de8c26..4484fa55057 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/security/MultiTenantRpcAuthorizer.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/rpc/security/MultiTenantRpcAuthorizer.java @@ -84,7 +84,7 @@ public class MultiTenantRpcAuthorizer implements RpcAuthorizer { try { getPeerIdentity(request) .ifPresent(peerIdentity -> authorizer.accept(request, peerIdentity)); - log.log(LogLevel.DEBUG, () -> String.format("Authorization succeeded for request '%s' from '%s'", + log.log(Level.FINE, () -> String.format("Authorization succeeded for request '%s' from '%s'", request.methodName(), request.target().toString())); } catch (Throwable t) { handleAuthorizationFailure(request, t); @@ -158,7 +158,7 @@ public class MultiTenantRpcAuthorizer implements RpcAuthorizer { if (!isAuthorizationException || ((AuthorizationException) throwable).type() != Type.SILENT) { log.log(LogLevel.INFO, errorMessage); } - log.log(LogLevel.DEBUG, throwable, throwable::getMessage); + log.log(Level.FINE, throwable, throwable::getMessage); JrtErrorCode error = isAuthorizationException ? JrtErrorCode.UNAUTHORIZED : JrtErrorCode.AUTHORIZATION_FAILED; request.setError(error.code, errorMessage); request.returnRequest(); @@ -180,7 +180,7 @@ public class MultiTenantRpcAuthorizer implements RpcAuthorizer { } try { NodeIdentity identity = nodeIdentifier.identifyNode(certChain); - log.log(LogLevel.DEBUG, () -> String.format("Client '%s' identified as %s", request.target().toString(), identity.toString())); + log.log(Level.FINE, () -> String.format("Client '%s' identified as %s", request.target().toString(), identity.toString())); return Optional.of(identity); } catch (NodeIdentifierException e) { throw new AuthorizationException("Failed to identity peer: " + e.getMessage(), e); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionRepo.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionRepo.java index e697e7193ca..bf76cf67cf1 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionRepo.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionRepo.java @@ -78,7 +78,7 @@ public class LocalSessionRepo extends SessionRepo<LocalSession> { } public void purgeOldSessions() { - log.log(LogLevel.DEBUG, "Purging old sessions"); + log.log(Level.FINE, "Purging old sessions"); try { List<LocalSession> sessions = new ArrayList<>(listSessions()); for (LocalSession candidate : sessions) { @@ -90,7 +90,7 @@ public class LocalSessionRepo extends SessionRepo<LocalSession> { } catch (Throwable e) { log.log(LogLevel.WARNING, "Error when purging old sessions ", e); } - log.log(LogLevel.DEBUG, "Done purging old sessions"); + log.log(Level.FINE, "Done purging old sessions"); } private boolean hasExpired(LocalSession candidate) { @@ -103,7 +103,7 @@ public class LocalSessionRepo extends SessionRepo<LocalSession> { void deleteSession(LocalSession session) { long sessionId = session.getSessionId(); - log.log(LogLevel.DEBUG, "Deleting local session " + sessionId); + log.log(Level.FINE, "Deleting local session " + sessionId); LocalSessionStateWatcher watcher = sessionStateWatchers.remove(sessionId); if (watcher != null) watcher.close(); removeSession(sessionId); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionStateWatcher.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionStateWatcher.java index 6a27a300a15..5a972086d82 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionStateWatcher.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/LocalSessionStateWatcher.java @@ -41,7 +41,7 @@ public class LocalSessionStateWatcher { session.logPre() + "Session change: Local session " + sessionId + " changed status to " + status); if (status.equals(Session.Status.DELETE) && localSessionRepo.getSession(sessionId) != null) { - log.log(LogLevel.DEBUG, session.logPre() + "Deleting session " + sessionId); + log.log(Level.FINE, session.logPre() + "Deleting session " + sessionId); localSessionRepo.deleteSession(session); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSession.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSession.java index de084e598c9..0f96d70a3b1 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSession.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSession.java @@ -88,11 +88,11 @@ public class RemoteSession extends Session { void makeActive(ReloadHandler reloadHandler) { Curator.CompletionWaiter waiter = zooKeeperClient.getActiveWaiter(); - log.log(LogLevel.DEBUG, () -> logPre() + "Getting session from repo: " + getSessionId()); + log.log(Level.FINE, () -> logPre() + "Getting session from repo: " + getSessionId()); ApplicationSet app = ensureApplicationLoaded(); - log.log(LogLevel.DEBUG, () -> logPre() + "Reloading config for " + getSessionId()); + log.log(Level.FINE, () -> logPre() + "Reloading config for " + getSessionId()); reloadHandler.reloadConfig(app); - log.log(LogLevel.DEBUG, () -> logPre() + "Notifying " + waiter); + log.log(Level.FINE, () -> logPre() + "Notifying " + waiter); notifyCompletion(waiter); log.log(LogLevel.INFO, logPre() + "Session activated: " + getSessionId()); } @@ -108,9 +108,9 @@ public class RemoteSession extends Session { void confirmUpload() { Curator.CompletionWaiter waiter = zooKeeperClient.getUploadWaiter(); - log.log(LogLevel.DEBUG, "Notifying upload waiter for session " + getSessionId()); + log.log(Level.FINE, "Notifying upload waiter for session " + getSessionId()); notifyCompletion(waiter); - log.log(LogLevel.DEBUG, "Done notifying upload for session " + getSessionId()); + log.log(Level.FINE, "Done notifying upload for session " + getSessionId()); } private void notifyCompletion(Curator.CompletionWaiter completionWaiter) { diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionRepo.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionRepo.java index 6b5ad0c10a8..e4e097cf448 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionRepo.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionRepo.java @@ -138,7 +138,7 @@ public class RemoteSessionRepo extends SessionRepo<RemoteSession> { * @param sessionId session id for the new session */ private void sessionAdded(long sessionId) { - log.log(LogLevel.DEBUG, () -> "Adding session to RemoteSessionRepo: " + sessionId); + log.log(Level.FINE, () -> "Adding session to RemoteSessionRepo: " + sessionId); try { RemoteSession session = remoteSessionFactory.createSession(sessionId); Path sessionPath = sessionsPath.append(String.valueOf(sessionId)); @@ -164,7 +164,7 @@ public class RemoteSessionRepo extends SessionRepo<RemoteSession> { private void loadSessionIfActive(RemoteSession session) { for (ApplicationId applicationId : applicationRepo.activeApplications()) { if (applicationRepo.requireActiveSessionOf(applicationId) == session.getSessionId()) { - log.log(LogLevel.DEBUG, () -> "Found active application for session " + session.getSessionId() + " , loading it"); + log.log(Level.FINE, () -> "Found active application for session " + session.getSessionId() + " , loading it"); reloadHandler.reloadConfig(session.ensureApplicationLoaded()); log.log(LogLevel.INFO, session.logPre() + "Application activated successfully: " + applicationId + " (generation " + session.getSessionId() + ")"); return; @@ -200,7 +200,7 @@ public class RemoteSessionRepo extends SessionRepo<RemoteSession> { @SuppressWarnings("unused") private void childEvent(CuratorFramework ignored, PathChildrenCacheEvent event) { zkWatcherExecutor.execute(() -> { - log.log(LogLevel.DEBUG, () -> "Got child event: " + event); + log.log(Level.FINE, () -> "Got child event: " + event); switch (event.getType()) { case CHILD_ADDED: sessionsChanged(); @@ -220,7 +220,7 @@ public class RemoteSessionRepo extends SessionRepo<RemoteSession> { for (long sessionId : sessionList) { RemoteSession session = getSession(sessionId); if (session == null) continue; // session might have been deleted after getting session list - log.log(LogLevel.DEBUG, () -> session.logPre() + "Confirming upload for session " + sessionId); + log.log(Level.FINE, () -> session.logPre() + "Confirming upload for session " + sessionId); session.confirmUpload(); } } diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionStateWatcher.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionStateWatcher.java index 1f11c0f9737..549ad2a2d24 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionStateWatcher.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/RemoteSessionStateWatcher.java @@ -43,11 +43,11 @@ public class RemoteSessionStateWatcher { } private void sessionChanged(Session.Status status) { - log.log(LogLevel.DEBUG, session.logPre() + "Session change: Remote session " + session.getSessionId() + " changed status to " + status); + log.log(Level.FINE, session.logPre() + "Session change: Remote session " + session.getSessionId() + " changed status to " + status); // valid for NEW -> PREPARE transitions, not ACTIVATE -> PREPARE. if (status.equals(Session.Status.PREPARE)) { - log.log(LogLevel.DEBUG, session.logPre() + "Loading prepared session: " + session.getSessionId()); + log.log(Level.FINE, session.logPre() + "Loading prepared session: " + session.getSessionId()); session.loadPrepared(); } else if (status.equals(Session.Status.ACTIVATE)) { session.makeActive(reloadHandler); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionFactoryImpl.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionFactoryImpl.java index 9473855e2aa..58b643ec82c 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionFactoryImpl.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionFactoryImpl.java @@ -105,16 +105,16 @@ public class SessionFactoryImpl implements SessionFactory, LocalSessionLoader { SessionZooKeeperClient sessionZKClient, TimeoutBudget timeoutBudget, Clock clock) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant) + "Creating session " + sessionId + " in ZooKeeper"); + log.log(Level.FINE, TenantRepository.logPre(tenant) + "Creating session " + sessionId + " in ZooKeeper"); sessionZKClient.createNewSession(clock.instant().toEpochMilli(), TimeUnit.MILLISECONDS); - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant) + "Creating upload waiter for session " + sessionId); + log.log(Level.FINE, TenantRepository.logPre(tenant) + "Creating upload waiter for session " + sessionId); Curator.CompletionWaiter waiter = sessionZKClient.getUploadWaiter(); - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant) + "Done creating upload waiter for session " + sessionId); + log.log(Level.FINE, TenantRepository.logPre(tenant) + "Done creating upload waiter for session " + sessionId); SessionContext context = new SessionContext(applicationPackage, sessionZKClient, getSessionAppDir(sessionId), applicationRepo, hostRegistry, flagSource); LocalSession session = new LocalSession(tenant, sessionId, sessionPreparer, context); - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant) + "Waiting on upload waiter for session " + sessionId); + log.log(Level.FINE, TenantRepository.logPre(tenant) + "Waiting on upload waiter for session " + sessionId); waiter.awaitCompletion(timeoutBudget.timeLeft()); - log.log(LogLevel.DEBUG, TenantRepository.logPre(tenant) + "Done waiting on upload waiter for session " + sessionId); + log.log(Level.FINE, TenantRepository.logPre(tenant) + "Done waiting on upload waiter for session " + sessionId); return session; } @@ -127,7 +127,7 @@ public class SessionFactoryImpl implements SessionFactory, LocalSessionLoader { ApplicationId existingApplicationId = existingSession.getApplicationId(); long activeSessionId = getActiveSessionId(existingApplicationId); - logger.log(LogLevel.DEBUG, "Create new session for application id '" + existingApplicationId + "' from existing active session " + activeSessionId); + logger.log(Level.FINE, "Create new session for application id '" + existingApplicationId + "' from existing active session " + activeSessionId); LocalSession session = create(existingApp, existingApplicationId, activeSessionId, internalRedeploy, timeoutBudget); // Note: Needs to be kept in sync with calls in SessionPreparer.writeStateToZooKeeper() session.setApplicationId(existingApplicationId); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionPreparer.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionPreparer.java index d39ddd68f25..c28d432ea08 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionPreparer.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionPreparer.java @@ -121,7 +121,7 @@ public class SessionPreparer { preparation.writeContainerEndpointsZK(); preparation.distribute(); } - log.log(LogLevel.DEBUG, () -> "time used " + params.getTimeoutBudget().timesUsed() + + log.log(Level.FINE, () -> "time used " + params.getTimeoutBudget().timesUsed() + " : " + params.getApplicationId()); return preparation.result(); } @@ -243,7 +243,7 @@ public class SessionPreparer { } void writeStateZK() { - log.log(LogLevel.DEBUG, "Writing application package state to zookeeper"); + log.log(Level.FINE, "Writing application package state to zookeeper"); writeStateToZooKeeper(context.getSessionZooKeeperClient(), applicationPackage, applicationId, diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionZooKeeperClient.java b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionZooKeeperClient.java index bd130ebb153..fd32cb020d6 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionZooKeeperClient.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/session/SessionZooKeeperClient.java @@ -128,7 +128,7 @@ public class SessionZooKeeperClient { public void delete(NestedTransaction transaction ) { try { - log.log(LogLevel.DEBUG, "Deleting " + sessionPath.getAbsolute()); + log.log(Level.FINE, "Deleting " + sessionPath.getAbsolute()); CuratorTransaction curatorTransaction = new CuratorTransaction(curator); CuratorOperations.deleteAll(sessionPath.getAbsolute(), curator).forEach(curatorTransaction::add); transaction.add(curatorTransaction); 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 b82574efa9f..45b22ae156c 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 @@ -121,10 +121,10 @@ public class TenantRepository { } else { this.directoryCache = Optional.empty(); } - log.log(LogLevel.DEBUG, "Creating all tenants"); + log.log(Level.FINE, "Creating all tenants"); bootstrapTenants(); notifyTenantsLoaded(); - log.log(LogLevel.DEBUG, "All tenants created"); + log.log(Level.FINE, "All tenants created"); checkForRemovedApplicationsService.scheduleWithFixedDelay(this::removeUnusedApplications, checkForRemovedApplicationsInterval.getSeconds(), checkForRemovedApplicationsInterval.getSeconds(), @@ -153,7 +153,7 @@ public class TenantRepository { /** Public for testing. */ public synchronized void updateTenants() { Set<TenantName> allTenants = readTenantsFromZooKeeper(curator); - log.log(LogLevel.DEBUG, "Create tenants, tenants found in zookeeper: " + allTenants); + log.log(Level.FINE, "Create tenants, tenants found in zookeeper: " + allTenants); for (TenantName tenantName : Set.copyOf(tenants.keySet())) if ( ! allTenants.contains(tenantName)) zkWatcherExecutor.execute(tenantName, () -> closeTenant(tenantName)); diff --git a/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRequestHandler.java b/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRequestHandler.java index 6f0638a4760..b3d783633a5 100644 --- a/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRequestHandler.java +++ b/configserver/src/main/java/com/yahoo/vespa/config/server/tenant/TenantRequestHandler.java @@ -81,7 +81,7 @@ public class TenantRequestHandler implements RequestHandler, ReloadHandler, Host public ConfigResponse resolveConfig(ApplicationId appId, GetConfigRequest req, Optional<Version> vespaVersion) { Application application = getApplication(appId, vespaVersion); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, TenantRepository.logPre(appId) + "Resolving for tenant '" + tenant + "' with handler for application '" + application + "'"); + log.log(Level.FINE, TenantRepository.logPre(appId) + "Resolving for tenant '" + tenant + "' with handler for application '" + application + "'"); } return application.resolveConfig(req, responseFactory); } 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 fdc96ea390e..6bf645cc02c 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(LogLevel.DEBUG, "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 76a934236d0..34cf6e345a0 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 @@ -150,7 +150,7 @@ class ZKApplicationFile extends ApplicationFile { StringWriter writer = new StringWriter(); try { mapper.writeValue(writer, new MetaData(status, input == null ? "" : ConfigUtils.getMd5(input))); - log.log(LogLevel.DEBUG, "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); @@ -159,7 +159,7 @@ class ZKApplicationFile extends ApplicationFile { public MetaData getMetaData() { String metaPath = getZKPath(getMetaPath()); - log.log(LogLevel.DEBUG, "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/configserver/src/test/java/com/yahoo/vespa/config/server/deploy/DeployHandlerLoggerTest.java b/configserver/src/test/java/com/yahoo/vespa/config/server/deploy/DeployHandlerLoggerTest.java index 3ec515a1528..9e7576ae8f5 100644 --- a/configserver/src/test/java/com/yahoo/vespa/config/server/deploy/DeployHandlerLoggerTest.java +++ b/configserver/src/test/java/com/yahoo/vespa/config/server/deploy/DeployHandlerLoggerTest.java @@ -42,7 +42,7 @@ public class DeployHandlerLoggerTest { } private void logMessages(DeployLogger logger) { - logger.log(LogLevel.DEBUG, "foobar"); + logger.log(Level.FINE, "foobar"); logger.log(LogLevel.SPAM, "foobar"); logger.log(LogLevel.FINE, "baz"); logger.log(LogLevel.WARNING, "baz"); diff --git a/configserver/src/test/java/com/yahoo/vespa/config/server/http/SessionHandlerTest.java b/configserver/src/test/java/com/yahoo/vespa/config/server/http/SessionHandlerTest.java index c5015536e03..a2e0b1e9443 100644 --- a/configserver/src/test/java/com/yahoo/vespa/config/server/http/SessionHandlerTest.java +++ b/configserver/src/test/java/com/yahoo/vespa/config/server/http/SessionHandlerTest.java @@ -131,7 +131,7 @@ public class SessionHandlerTest { status = Session.Status.PREPARE; this.dockerImageRepository = params.dockerImageRepository(); if (doVerboseLogging) { - logger.log(LogLevel.DEBUG, "debuglog"); + logger.log(Level.FINE, "debuglog"); } return actions; } 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 1d4a174dc55..270decfeaeb 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 @@ -57,7 +57,7 @@ public class HandlersConfigurerDi { ComponentRegistry<RequestHandler> requestHandlerRegistry, ComponentRegistry<ClientProvider> clientProviderRegistry, ComponentRegistry<ServerProvider> serverProviderRegistry) { - log.log(LogLevel.DEBUG, "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/jdisc/LoggingRequestHandler.java b/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java index 8371acb59d4..6878b6df09d 100644 --- a/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java +++ b/container-core/src/main/java/com/yahoo/container/jdisc/LoggingRequestHandler.java @@ -228,7 +228,7 @@ public abstract class LoggingRequestHandler extends ThreadedHttpRequestHandler { long endTime = System.currentTimeMillis(); writeToLogs(endTime); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Got exception when writing to client: " + Exceptions.toMessageString(throwable)); + log.log(Level.FINE, "Got exception when writing to client: " + Exceptions.toMessageString(throwable)); } } diff --git a/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java b/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java index 9e69b9890b5..2b4c1489313 100644 --- a/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java +++ b/container-core/src/main/java/com/yahoo/container/jdisc/ThreadedHttpRequestHandler.java @@ -70,7 +70,7 @@ public abstract class ThreadedHttpRequestHandler extends ThreadedRequestHandler @Override public final void handleRequest(Request request, BufferedContentChannel requestContent, ResponseHandler responseHandler) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "In " + this.getClass() + ".handleRequest()"); + log.log(Level.FINE, "In " + this.getClass() + ".handleRequest()"); } com.yahoo.jdisc.http.HttpRequest jdiscRequest = asHttpRequest(request); HttpRequest httpRequest = new HttpRequest(jdiscRequest, new UnsafeContentInputStream(requestContent.toReadable())); @@ -192,7 +192,7 @@ public abstract class ThreadedHttpRequestHandler extends ThreadedRequestHandler } catch (Exception e) { metric.add(RENDERING_ERRORS, 1, null); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Error writing response to client - connection probably terminated " + + log.log(Level.FINE, "Error writing response to client - connection probably terminated " + "from client side.", e); } return new DevNullChannel(); // Ignore further operations on this diff --git a/container-core/src/main/java/com/yahoo/restapi/JacksonJsonResponse.java b/container-core/src/main/java/com/yahoo/restapi/JacksonJsonResponse.java index d76804a1d5f..699ebb7a705 100644 --- a/container-core/src/main/java/com/yahoo/restapi/JacksonJsonResponse.java +++ b/container-core/src/main/java/com/yahoo/restapi/JacksonJsonResponse.java @@ -39,7 +39,7 @@ public class JacksonJsonResponse<T> extends HttpResponse { public void render(OutputStream outputStream) throws IOException { if (log.isLoggable(LogLevel.DEBUG)) { String json = jsonMapper.writeValueAsString(entity); - log.log(LogLevel.DEBUG, "Writing the following JSON to response output stream:\n" + json); + log.log(Level.FINE, "Writing the following JSON to response output stream:\n" + json); outputStream.write(json.getBytes()); } else { jsonMapper.writeValue(outputStream, entity); diff --git a/container-di/src/main/java/com/yahoo/container/di/componentgraph/core/ComponentGraph.java b/container-di/src/main/java/com/yahoo/container/di/componentgraph/core/ComponentGraph.java index e0cb69d8499..fdaaf4b698d 100644 --- a/container-di/src/main/java/com/yahoo/container/di/componentgraph/core/ComponentGraph.java +++ b/container-di/src/main/java/com/yahoo/container/di/componentgraph/core/ComponentGraph.java @@ -255,7 +255,7 @@ public class ComponentGraph { if (component.isEmpty()) { Object instance; try { - log.log(LogLevel.DEBUG, "Trying the fallback injector to create" + messageForNoGlobalComponent(clazz, node)); + log.log(Level.FINE, "Trying the fallback injector to create" + messageForNoGlobalComponent(clazz, node)); instance = fallbackInjector.getInstance(key); } catch (ConfigurationException e) { throw removeStackTrace(new IllegalStateException( diff --git a/container-messagebus/src/main/java/com/yahoo/container/jdisc/messagebus/SessionCache.java b/container-messagebus/src/main/java/com/yahoo/container/jdisc/messagebus/SessionCache.java index ef9b4e8d1ca..c8cef145a91 100644 --- a/container-messagebus/src/main/java/com/yahoo/container/jdisc/messagebus/SessionCache.java +++ b/container-messagebus/src/main/java/com/yahoo/container/jdisc/messagebus/SessionCache.java @@ -128,7 +128,7 @@ public final class SessionCache extends AbstractComponent { } private static void logSystemInfo(ContainerMbusConfig containerMbusConfig, long maxPendingSize) { - log.log(LogLevel.DEBUG, + log.log(Level.FINE, "Running with maximum heap size of " + (Runtime.getRuntime().maxMemory() / 1024L / 1024L) + " MB"); log.log(LogLevel.CONFIG, "Amount of memory reserved for container core: " + containerMbusConfig.containerCoreMemory() + " MB."); @@ -204,7 +204,7 @@ public final class SessionCache extends AbstractComponent { @Override SharedSourceSession create(SourceSessionParams p) { - log.log(LogLevel.DEBUG, "Creating new source session."); + log.log(Level.FINE, "Creating new source session."); return messageBus.newSourceSession(p); } @@ -215,7 +215,7 @@ public final class SessionCache extends AbstractComponent { @Override void logReuse(final SharedSourceSession session) { - log.log(LogLevel.DEBUG, "Reusing source session."); + log.log(Level.FINE, "Reusing source session."); } } @@ -224,7 +224,7 @@ public final class SessionCache extends AbstractComponent { @Override SharedIntermediateSession create(IntermediateSessionParams p) { - log.log(LogLevel.DEBUG, "Creating new intermediate session " + p.getName() + ""); + log.log(Level.FINE, "Creating new intermediate session " + p.getName() + ""); return messageBus.newIntermediateSession(p); } @@ -235,7 +235,7 @@ public final class SessionCache extends AbstractComponent { @Override void logReuse(SharedIntermediateSession session) { - log.log(LogLevel.DEBUG, "Reusing intermediate session " + session.name() + ""); + log.log(Level.FINE, "Reusing intermediate session " + session.name() + ""); } } diff --git a/container-search/src/main/java/com/yahoo/search/Query.java b/container-search/src/main/java/com/yahoo/search/Query.java index 0966ae3e4c0..9e3f6d20e36 100644 --- a/container-search/src/main/java/com/yahoo/search/Query.java +++ b/container-search/src/main/java/com/yahoo/search/Query.java @@ -726,7 +726,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable { if (includeQuery) message += ": [" + queryTreeText() + "]"; - log.log(LogLevel.DEBUG,message); + log.log(Level.FINE,message); // Pass 0 as traceLevel as the trace level check is already done above, // and it is not propagated to trace until execution has started diff --git a/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java b/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java index 30860f9570b..dbde0ad409f 100644 --- a/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java +++ b/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java @@ -227,7 +227,7 @@ public class GroupingExecutor extends Searcher { } if (log.isLoggable(LogLevel.DEBUG)) { for (Grouping grouping : passList) { - log.log(LogLevel.DEBUG, "Pass(" + pass + "), Grouping(" + grouping.getId() + "): " + grouping); + log.log(Level.FINE, "Pass(" + pass + "), Grouping(" + grouping.getId() + "): " + grouping); } } Item passRoot; @@ -265,7 +265,7 @@ public class GroupingExecutor extends Searcher { } if (log.isLoggable(LogLevel.DEBUG)) { for (Grouping grouping : groupingMap.values()) { - log.log(LogLevel.DEBUG, "Result Grouping(" + grouping.getId() + "): " + grouping); + log.log(Level.FINE, "Result Grouping(" + grouping.getId() + "): " + grouping); } } return ret; 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 ee81f2c819e..2a8eeaf8e7f 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 @@ -154,7 +154,7 @@ public class SearchHandler extends LoggingRequestHandler { long numQueriesToTraceOnDebugAfterStartup, Optional<String> hostResponseHeaderKey) { super(executor, accessLog, metric, true); - log.log(LogLevel.DEBUG, "SearchHandler.init " + System.identityHashCode(this)); + log.log(Level.FINE, "SearchHandler.init " + System.identityHashCode(this)); this.queryProfileRegistry = queryProfileRegistry; this.executionFactory = executionFactory; @@ -426,7 +426,7 @@ public class SearchHandler extends LoggingRequestHandler { } catch (ParseException e) { ErrorMessage error = ErrorMessage.createIllegalQuery("Could not parse query [" + request + "]: " + Exceptions.toMessageString(e)); - log.log(LogLevel.DEBUG, error::getDetailedMessage); + log.log(Level.FINE, error::getDetailedMessage); return new Result(query, error); } catch (IllegalArgumentException e) { if ("Comparison method violates its general contract!".equals(e.getMessage())) { @@ -438,7 +438,7 @@ public class SearchHandler extends LoggingRequestHandler { else { ErrorMessage error = ErrorMessage.createBadRequest("Invalid search request [" + request + "]: " + Exceptions.toMessageString(e)); - log.log(LogLevel.DEBUG, error::getDetailedMessage); + log.log(Level.FINE, error::getDetailedMessage); return new Result(query, error); } } catch (LinkageError | StackOverflowError e) { 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 d4db21c3810..d66aff7bcd7 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(LogLevel.DEBUG, 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(LogLevel.DEBUG, logger.getName() + ": " + msg); + logger.log(Level.FINE, logger.getName() + ": " + msg); } /** diff --git a/container-search/src/main/java/com/yahoo/search/searchers/InputCheckingSearcher.java b/container-search/src/main/java/com/yahoo/search/searchers/InputCheckingSearcher.java index 7d9d3f147f5..65b3fc5a805 100644 --- a/container-search/src/main/java/com/yahoo/search/searchers/InputCheckingSearcher.java +++ b/container-search/src/main/java/com/yahoo/search/searchers/InputCheckingSearcher.java @@ -52,7 +52,7 @@ public class InputCheckingSearcher extends Searcher { checkQuery(query); } catch (IllegalArgumentException e) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Rejected query \"" + query.toString() + "\" on cause of: " + e.getMessage()); + log.log(Level.FINE, "Rejected query \"" + query.toString() + "\" on cause of: " + e.getMessage()); } return new Result(query, ErrorMessage.createIllegalQuery(e.getMessage())); } 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 ad92512d1a1..f7c8c646bb4 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 @@ -330,20 +330,20 @@ class VdsVisitor extends VisitorDataHandler implements Visitor { VisitorSession session = visitorSessionFactory.createVisitorSession(params); try { if ( !session.waitUntilDone(query.getTimeout())) { - log.log(LogLevel.DEBUG, "Visitor returned from waitUntilDone without being completed for " + query + " with selection " + params.getDocumentSelection()); + 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()); } } finally { session.destroy(); sessionTrace = session.getTrace(); - log.log(LogLevel.DEBUG, () -> sessionTrace.toString()); + log.log(Level.FINE, () -> sessionTrace.toString()); query.trace(sessionTrace.toString(), false, 9); } if (params.getControlHandler().getResult().code == VisitorControlHandler.CompletionCode.SUCCESS) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "VdsVisitor completed successfully for " + query + " with selection " + params.getDocumentSelection()); + log.log(Level.FINE, "VdsVisitor completed successfully for " + query + " with selection " + params.getDocumentSelection()); } } else { throw new IllegalArgumentException("Query failed: " // TODO: Is it necessary to use a runtime exception? @@ -394,7 +394,7 @@ class VdsVisitor extends VisitorDataHandler implements Visitor { final int hitCountTotal = sr.getTotalHitCount(); final int hitCount = sr.getHitCount(); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Got SearchResult with " + hitCountTotal + " in total and " + hitCount + " hits in real for query with selection " + params.getDocumentSelection()); + log.log(Level.FINE, "Got SearchResult with " + hitCountTotal + " in total and " + hitCount + " hits in real for query with selection " + params.getDocumentSelection()); } List<SearchResult.Hit> newHits = new ArrayList<>(hitCount); @@ -449,7 +449,7 @@ class VdsVisitor extends VisitorDataHandler implements Visitor { private void handleSummary(DocumentSummary ds) { int summaryCount = ds.getSummaryCount(); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Got DocumentSummary with " + summaryCount + " summaries for query with selection " + params.getDocumentSelection()); + log.log(Level.FINE, "Got DocumentSummary with " + summaryCount + " summaries for query with selection " + params.getDocumentSelection()); } synchronized (summaryMap) { for (int i = 0; i < summaryCount; i++) { 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 c478c396ca3..ae9d35e6790 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 @@ -259,7 +259,7 @@ public class AthenzFacade implements AccessControl { } public List<AthenzDomain> getDomainList(String prefix) { - log.log(LogLevel.DEBUG, String.format("getDomainList(prefix=%s)", prefix)); + log.log(Level.FINE, String.format("getDomainList(prefix=%s)", prefix)); return zmsClient.getDomainList(prefix); } @@ -279,7 +279,7 @@ public class AthenzFacade implements AccessControl { } private static void log(String format, Object... args) { - log.log(LogLevel.DEBUG, String.format(format, args)); + log.log(Level.FINE, String.format(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 b63b4e4fcc6..56d3b928b8f 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 @@ -155,7 +155,7 @@ public class DeploymentTrigger { /** Attempts to trigger the given job. */ public void trigger(Job job) { - log.log(LogLevel.DEBUG, "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/proxy/ConfigServerRestExecutorImpl.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/proxy/ConfigServerRestExecutorImpl.java index 5cfd07dcb2e..d10c4dd226b 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/proxy/ConfigServerRestExecutorImpl.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/proxy/ConfigServerRestExecutorImpl.java @@ -102,7 +102,7 @@ public class ConfigServerRestExecutorImpl extends AbstractComponent implements C errorBuilder.append("Talking to server ").append(uri.getHost()); errorBuilder.append(", got ").append(status).append(" ") .append(content).append("\n"); - log.log(LogLevel.DEBUG, () -> String.format("Got response from %s with status code %d and content:\n %s", + log.log(Level.FINE, () -> String.format("Got response from %s with status code %d and content:\n %s", uri.getHost(), status, content)); return Optional.empty(); } @@ -118,7 +118,7 @@ public class ConfigServerRestExecutorImpl extends AbstractComponent implements C } catch (Exception e) { errorBuilder.append("Talking to server ").append(uri.getHost()); errorBuilder.append(" got exception ").append(e.getMessage()); - log.log(LogLevel.DEBUG, e, () -> "Got exception while sending request to " + uri.getHost()); + log.log(Level.FINE, e, () -> "Got exception while sending request to " + uri.getHost()); return Optional.empty(); } } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/filter/SignatureFilter.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/filter/SignatureFilter.java index 2e7f75cbb9c..1f515035fe7 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/filter/SignatureFilter.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/filter/SignatureFilter.java @@ -59,7 +59,7 @@ public class SignatureFilter extends JsonSecurityRequestFilterBase { }); } catch (Exception e) { - logger.log(LogLevel.DEBUG, () -> "Exception verifying signed request: " + Exceptions.toMessageString(e)); + logger.log(Level.FINE, () -> "Exception verifying signed request: " + Exceptions.toMessageString(e)); } return Optional.empty(); } diff --git a/docproc/src/main/java/com/yahoo/docproc/SimpleDocumentProcessor.java b/docproc/src/main/java/com/yahoo/docproc/SimpleDocumentProcessor.java index f074d4a287c..5036ce59727 100644 --- a/docproc/src/main/java/com/yahoo/docproc/SimpleDocumentProcessor.java +++ b/docproc/src/main/java/com/yahoo/docproc/SimpleDocumentProcessor.java @@ -35,7 +35,7 @@ public class SimpleDocumentProcessor extends DocumentProcessor { */ public void process(DocumentPut put) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Ignored " + put); + log.log(Level.FINE, "Ignored " + put); } } @@ -48,7 +48,7 @@ public class SimpleDocumentProcessor extends DocumentProcessor { */ public void process(DocumentUpdate update) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Ignored " + update); + log.log(Level.FINE, "Ignored " + update); } } @@ -61,7 +61,7 @@ public class SimpleDocumentProcessor extends DocumentProcessor { */ public void process(DocumentRemove remove) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Ignored " + remove); + log.log(Level.FINE, "Ignored " + remove); } } @@ -97,7 +97,7 @@ public class SimpleDocumentProcessor extends DocumentProcessor { } } catch (RuntimeException e) { if (log.isLoggable(LogLevel.DEBUG) && initialSize != 1) { - log.log(LogLevel.DEBUG, + log.log(Level.FINE, "Processing of document failed, from processing.getDocumentOperations() containing " + initialSize + " DocumentOperation(s).", e); } 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 caa8b0b282d..2ebc29a6b09 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingHandler.java @@ -194,13 +194,13 @@ public class DocumentProcessingHandler extends AbstractRequestHandler { private LaterTimerTask(DocumentProcessingTask processingTask, long delay) { this.delay = delay; - log.log(LogLevel.DEBUG, "Enqueueing in " + delay + " ms due to Progress.LATER: " + processingTask); + log.log(Level.FINE, "Enqueueing in " + delay + " ms due to Progress.LATER: " + processingTask); this.processingTask = processingTask; } @Override public void run() { - log.log(LogLevel.DEBUG, "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 383918ce188..810e8c6ada4 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/DocumentProcessingTask.java @@ -203,7 +203,7 @@ public class DocumentProcessingTask implements Runnable { if (exception != null) { StringWriter backtrace = new StringWriter(); exception.printStackTrace(new PrintWriter(backtrace)); - log.log(LogLevel.DEBUG, "Failed to process " + processing + ": " + backtrace.toString()); + log.log(Level.FINE, "Failed to process " + processing + ": " + backtrace.toString()); } } diff --git a/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MbusRequestContext.java b/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MbusRequestContext.java index 47d639e5dc6..e8897f55a9e 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MbusRequestContext.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MbusRequestContext.java @@ -92,7 +92,7 @@ public class MbusRequestContext implements RequestContext, ResponseHandler { } } if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Forwarding " + messages.size() + " messages from " + processings.size() + + log.log(Level.FINE, "Forwarding " + messages.size() + " messages from " + processings.size() + " processings."); } if (messages.isEmpty()) { diff --git a/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MessageFactory.java b/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MessageFactory.java index 7c4a6c8c2c3..ca7455e1305 100644 --- a/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MessageFactory.java +++ b/docproc/src/main/java/com/yahoo/docproc/jdisc/messagebus/MessageFactory.java @@ -43,7 +43,7 @@ class MessageFactory { message.setTimeRemaining(requestMsg.getTimeRemainingNow()); message.getTrace().setLevel(requestMsg.getTrace().getLevel()); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Created '" + message.getClass().getName() + + log.log(Level.FINE, "Created '" + message.getClass().getName() + "', route = '" + message.getRoute() + "', priority = '" + message.getPriority().name() + "', load type = '" + message.getLoadType() + 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 93d87a49c64..406fc9a6db9 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(LogLevel.DEBUG, "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 f6be7a4d990..7ec4ece3a3c 100644 --- a/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java +++ b/docproc/src/main/java/com/yahoo/docproc/util/SplitterDocumentProcessor.java @@ -42,7 +42,7 @@ 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(LogLevel.DEBUG, "More than one document given, returning. (Was given " + log.log(Level.FINE, "More than one document given, returning. (Was given " + processing.getDocumentOperations().size() + " documents)."); return Progress.DONE; } @@ -57,14 +57,14 @@ 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(LogLevel.DEBUG, "The given Document does not have a field value for field " + 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(LogLevel.DEBUG, "The given Document does not have any elements in array field " + log.log(Level.FINE, "The given Document does not have any elements in array field " + arrayFieldName + ", returning. (Was given " + outerDoc + ")."); return Progress.DONE; } @@ -118,7 +118,7 @@ public class SplitterDocumentProcessor extends DocumentProcessor { static boolean doProcessOuterDocument(Object o, String documentTypeName) { if ( ! (o instanceof DocumentOperation)) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, o + " is not a DocumentOperation."); + log.log(Level.FINE, o + " is not a DocumentOperation."); } return false; } @@ -127,7 +127,7 @@ public class SplitterDocumentProcessor extends DocumentProcessor { if ( ! (outerDocOp instanceof DocumentPut)) { //this is not a put, return if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Given DocumentOperation is not a DocumentPut, returning. (Was given " + log.log(Level.FINE, "Given DocumentOperation is not a DocumentPut, returning. (Was given " + outerDocOp + ")."); } return false; @@ -138,7 +138,7 @@ public class SplitterDocumentProcessor extends DocumentProcessor { if (!type.getName().equalsIgnoreCase(documentTypeName)) { //this is not the right document type if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Given Document is of wrong type, returning. (Was given " + outerDoc + ")."); + log.log(Level.FINE, "Given Document is of wrong type, returning. (Was given " + outerDoc + ")."); } return false; } 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 30b7f9bf718..ec17e5e37e4 100644 --- a/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java +++ b/docprocs/src/main/java/com/yahoo/docprocs/indexing/IndexingProcessor.java @@ -89,14 +89,14 @@ public class IndexingProcessor extends DocumentProcessor { private void processDocument(DocumentPut prev, List<DocumentOperation> out) { DocumentScript script = scriptMgr.getScript(prev.getDocument().getDataType()); if (script == null) { - log.log(LogLevel.DEBUG, "No indexing script for document '%s'.", prev.getId()); + log.log(Level.FINE, "No indexing script for document '%s'.", prev.getId()); out.add(prev); return; } - log.log(LogLevel.DEBUG, "Processing document '%s'.", prev.getId()); + log.log(Level.FINE, "Processing document '%s'.", prev.getId()); Document next = script.execute(adapterFactory, prev.getDocument()); if (next == null) { - log.log(LogLevel.DEBUG, "Document '" + prev.getId() + "' produced no output."); + log.log(Level.FINE, "Document '" + prev.getId() + "' produced no output."); return; } @@ -106,14 +106,14 @@ public class IndexingProcessor extends DocumentProcessor { private void processUpdate(DocumentUpdate prev, List<DocumentOperation> out) { DocumentScript script = scriptMgr.getScript(prev.getType()); if (script == null) { - log.log(LogLevel.DEBUG, "No indexing script for update '%s'.", prev.getId()); + log.log(Level.FINE, "No indexing script for update '%s'.", prev.getId()); out.add(prev); return; } - log.log(LogLevel.DEBUG, "Processing update '%s'.", prev.getId()); + log.log(Level.FINE, "Processing update '%s'.", prev.getId()); DocumentUpdate next = script.execute(adapterFactory, prev); if (next == null) { - log.log(LogLevel.DEBUG, "Update '" + prev.getId() + "' produced no output."); + log.log(Level.FINE, "Update '" + prev.getId() + "' produced no output."); return; } next.setCondition(prev.getCondition()); @@ -121,7 +121,7 @@ public class IndexingProcessor extends DocumentProcessor { } private void processRemove(DocumentRemove prev, List<DocumentOperation> out) { - log.log(LogLevel.DEBUG, "Not processing remove '%s'.", prev.getId()); + log.log(Level.FINE, "Not processing remove '%s'.", prev.getId()); out.add(prev); } diff --git a/docprocs/src/main/java/com/yahoo/docprocs/indexing/ScriptManager.java b/docprocs/src/main/java/com/yahoo/docprocs/indexing/ScriptManager.java index 783a003043e..a148966c250 100644 --- a/docprocs/src/main/java/com/yahoo/docprocs/indexing/ScriptManager.java +++ b/docprocs/src/main/java/com/yahoo/docprocs/indexing/ScriptManager.java @@ -35,22 +35,22 @@ public class ScriptManager { private Map<String, DocumentScript> getScripts(DocumentType inputType) { Map<String, DocumentScript> scripts = documentFieldScripts.get(inputType.getName()); if (scripts != null) { - log.log(LogLevel.DEBUG, "Using script for type '%s'.", inputType.getName()); + log.log(Level.FINE, "Using script for type '%s'.", inputType.getName()); return scripts; } for (Map.Entry<String, Map<String, DocumentScript>> entry : documentFieldScripts.entrySet()) { if (inputType.inherits(docTypeMgr.getDocumentType(entry.getKey()))) { - log.log(LogLevel.DEBUG, "Using script of super-type '%s'.", entry.getKey()); + log.log(Level.FINE, "Using script of super-type '%s'.", entry.getKey()); return entry.getValue(); } } for (Map.Entry<String, Map<String, DocumentScript>> entry : documentFieldScripts.entrySet()) { if (docTypeMgr.getDocumentType(entry.getKey()).inherits(inputType)) { - log.log(LogLevel.DEBUG, "Using script of sub-type '%s'.", entry.getKey()); + log.log(Level.FINE, "Using script of sub-type '%s'.", entry.getKey()); return entry.getValue(); } } - log.log(LogLevel.DEBUG, "No script for type '%s'.", inputType.getName()); + log.log(Level.FINE, "No script for type '%s'.", inputType.getName()); return null; } @@ -63,7 +63,7 @@ public class ScriptManager { if (fieldScripts != null) { DocumentScript script = fieldScripts.get(inputFieldName); if (script != null) { - log.log(LogLevel.DEBUG, "Using script for type '%s' and field '%s'.", inputType.getName(), inputFieldName); + log.log(Level.FINE, "Using script for type '%s' and field '%s'.", inputType.getName(), inputFieldName); return script; } } diff --git a/document/src/main/java/com/yahoo/document/DocumentTypeManagerConfigurer.java b/document/src/main/java/com/yahoo/document/DocumentTypeManagerConfigurer.java index d5da805dcdc..1d81d9e6e78 100644 --- a/document/src/main/java/com/yahoo/document/DocumentTypeManagerConfigurer.java +++ b/document/src/main/java/com/yahoo/document/DocumentTypeManagerConfigurer.java @@ -72,7 +72,7 @@ public class DocumentTypeManagerConfigurer implements ConfigSubscriber.SingleSub setupAnnotationTypesWithoutPayloads(config, manager); setupAnnotationRefTypes(config, manager); - log.log(LogLevel.DEBUG, "Configuring document manager with " + config.datatype().size() + " data types."); + log.log(Level.FINE, "Configuring document manager with " + config.datatype().size() + " data types."); ArrayList<DocumentmanagerConfig.Datatype> failed = new ArrayList<>(); failed.addAll(config.datatype()); while (!failed.isEmpty()) { @@ -226,7 +226,7 @@ public class DocumentTypeManagerConfigurer implements ConfigSubscriber.SingleSub DocumentTypeManager manager = configureNewManager(config); int defaultTypeCount = new DocumentTypeManager().getDataTypes().size(); if (this.managerToConfigure.getDataTypes().size() != defaultTypeCount) { - log.log(LogLevel.DEBUG, "Live document config overwritten with new config."); + log.log(Level.FINE, "Live document config overwritten with new config."); } managerToConfigure.assign(manager); } diff --git a/documentapi/src/main/java/com/yahoo/documentapi/ProgressToken.java b/documentapi/src/main/java/com/yahoo/documentapi/ProgressToken.java index 1842c1972df..eea3d6e66e8 100644 --- a/documentapi/src/main/java/com/yahoo/documentapi/ProgressToken.java +++ b/documentapi/src/main/java/com/yahoo/documentapi/ProgressToken.java @@ -306,7 +306,7 @@ public class ProgressToken { && !superbucket.contains(progress) && !progress.contains(superbucket)) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "updateProgress called with non-contained bucket " + log.log(Level.FINE, "updateProgress called with non-contained bucket " + "pair " + superbucket + ":" + progress + ", but allowing anyway"); } } @@ -323,7 +323,7 @@ public class ProgressToken { if (!progress.equals(FINISHED_BUCKET)) { if (entry.getState() != BucketState.BUCKET_ACTIVE) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "updateProgress called with sub-bucket that was " + log.log(Level.FINE, "updateProgress called with sub-bucket that was " + "not marked as active " + superbucket + ":" + progress); } } else { @@ -362,7 +362,7 @@ public class ProgressToken { protected void addBucket(BucketId superbucket, BucketId progress, BucketState state) { if (progress.equals(FINISHED_BUCKET)) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Trying to add already finished superbucket " + log.log(Level.FINE, "Trying to add already finished superbucket " + superbucket + "; ignoring it"); } return; @@ -796,7 +796,7 @@ public class ProgressToken { // be discarded if (rightSibling.getProgress().getUsedBits() != 0 && log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Bucket progress for " + rightCheck + + log.log(Level.FINE, "Bucket progress for " + rightCheck + " will be lost due to merging; potential for duplicates in result-set"); } buckets.remove(bucketToKeyWrapper(rightCheck)); diff --git a/documentapi/src/main/java/com/yahoo/documentapi/VisitorIterator.java b/documentapi/src/main/java/com/yahoo/documentapi/VisitorIterator.java index 83a7bc20353..ecf6d640ef7 100755 --- a/documentapi/src/main/java/com/yahoo/documentapi/VisitorIterator.java +++ b/documentapi/src/main/java/com/yahoo/documentapi/VisitorIterator.java @@ -111,7 +111,7 @@ public class VisitorIterator { if (!progress.isFinished()) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Importing unfinished progress token with " + + log.log(Level.FINE, "Importing unfinished progress token with " + "bits: " + progressToken.getDistributionBitCount() + ", active: " + progressToken.getActiveBucketCount() + ", pending: " + progressToken.getPendingBucketCount() + @@ -123,7 +123,7 @@ public class VisitorIterator { // Lower all active to pending if (progressToken.getActiveBucketCount() > 0) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Progress token had active buckets upon range " + + log.log(Level.FINE, "Progress token had active buckets upon range " + "construction. Setting these as pending"); } progressToken.setAllBucketsToState(ProgressToken.BucketState.BUCKET_PENDING); @@ -137,7 +137,7 @@ public class VisitorIterator { correctTruncatedBucketCursor(); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Partial bucket space progress; continuing "+ + log.log(Level.FINE, "Partial bucket space progress; continuing "+ "from position " + progressToken.getBucketCursor()); } } @@ -196,7 +196,7 @@ public class VisitorIterator { // single-bit bucket once did if (isLosslessResetPossible()) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "At start of bucket space and all " + + log.log(Level.FINE, "At start of bucket space and all " + "buckets have no progress; doing a lossless reset " + "instead of splitting/merging"); } @@ -263,7 +263,7 @@ public class VisitorIterator { } } if ((bucketsSplit > 0 || bucketsMerged > 0) && log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Existing progress' pending buckets had inconsistent " + + log.log(Level.FINE, "Existing progress' pending buckets had inconsistent " + "distribution bits; performed " + bucketsSplit + " split ops and " + bucketsMerged + " merge ops. Pending: " + pendingBefore + " -> " + p.getPendingBucketCount()); @@ -335,7 +335,7 @@ public class VisitorIterator { if (progressToken.getActiveBucketCount() > 0) { flushActive = true; if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Holding off new/pending buckets and consistency " + + log.log(Level.FINE, "Holding off new/pending buckets and consistency " + "correction until all " + progress.getActiveBucketCount() + " active buckets have been updated"); } @@ -350,7 +350,7 @@ public class VisitorIterator { correctInconsistentPending(distributionBitCount); if (delta > 0) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Increasing distribution bits for full bucket " + + log.log(Level.FINE, "Increasing distribution bits for full bucket " + "space range source from " + progressToken.getDistributionBitCount() + " to " + distributionBitCount); } @@ -360,7 +360,7 @@ public class VisitorIterator { progressToken.setBucketCursor(progressToken.getBucketCursor() << delta); } else if (delta < 0) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Decreasing distribution bits for full bucket " + + log.log(Level.FINE, "Decreasing distribution bits for full bucket " + "space range source from " + progressToken.getDistributionBitCount() + " to " + distributionBitCount + " bits"); } @@ -387,14 +387,14 @@ public class VisitorIterator { // consistency fix. This simplifies things greatly assert(flushActive); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Received non-finished bucket " + + log.log(Level.FINE, "Received non-finished bucket " + superbucket + " with wrong distribution bit count (" + superbucket.getUsedBits() + "). Waiting to correct " + "until all active are done"); } } else { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Received finished bucket " + + log.log(Level.FINE, "Received finished bucket " + superbucket + " with wrong distribution bit count (" + superbucket.getUsedBits() + "). Waiting to correct " + "until all active are done"); @@ -405,7 +405,7 @@ public class VisitorIterator { if (progressToken.getActiveBucketCount() == 0) { if (flushActive) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "All active buckets flushed, " + + log.log(Level.FINE, "All active buckets flushed, " + "correcting progress token and continuing normal operation"); } // Trigger the actual bucket state change this time @@ -509,7 +509,7 @@ public class VisitorIterator { progress.setDistributionBitCount(distributionBitCount); this.distributionBitCount = distributionBitCount; if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Set distribution bit count to " + log.log(Level.FINE, "Set distribution bit count to " + distributionBitCount + " for explicit bucket source (no-op)"); } } @@ -722,7 +722,7 @@ public class VisitorIterator { bucketSource.setDistributionBitCount(distBits, progressToken); distributionBitCount = distBits; if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Set visitor iterator distribution bit count to " + log.log(Level.FINE, "Set visitor iterator distribution bit count to " + distBits); } } 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 247364c8a7a..92abd8c98ca 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(LogLevel.DEBUG, "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 b6e822b597e..c2c36d01805 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(LogLevel.DEBUG, 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(LogLevel.DEBUG, 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "No route specified; resolved implicit " + + log.log(Level.FINE, "No route specified; resolved implicit " + "storage cluster: " + params.getRoute().toString()); } } @@ -575,7 +575,7 @@ public class MessageBusVisitorSession implements VisitorSession { progressToken); } else { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "parameters specify explicit bucket set " + + log.log(Level.FINE, "parameters specify explicit bucket set " + "to visit; using it rather than document selection (" + params.getBucketsToVisit().size() + " buckets given)"); } @@ -647,7 +647,7 @@ public class MessageBusVisitorSession implements VisitorSession { VisitorIterator.BucketProgress bucket = progress.getIterator().getNext(); Result result = sender.send(createMessage(bucket)); if (result.isAccepted()) { - log.log(LogLevel.DEBUG, sessionName + ": sent CreateVisitor for bucket " + + log.log(Level.FINE, sessionName + ": sent CreateVisitor for bucket " + bucket.getSuperbucket() + " with progress " + bucket.getProgress()); ++pendingMessageCount; } else { @@ -688,7 +688,7 @@ public class MessageBusVisitorSession implements VisitorSession { // 'done' is only ever written when token mutex is held, so safe to check // outside of completionMonitor lock. assert(!done) : "Session was marked as completed more than once"; - log.log(LogLevel.DEBUG, "Visitor session '" + sessionName + "' has completed"); + log.log(Level.FINE, "Visitor session '" + sessionName + "' has completed"); if (params.getLocalDataHandler() != null) { params.getLocalDataHandler().onDone(); } @@ -755,7 +755,7 @@ public class MessageBusVisitorSession implements VisitorSession { @Override public void run() { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Visitor session " + sessionName + ": Received message " + message); + log.log(Level.FINE, "Visitor session " + sessionName + ": Received message " + message); } try { if (message instanceof VisitorInfoMessage) { @@ -810,7 +810,7 @@ public class MessageBusVisitorSession implements VisitorSession { msg.swapState(reply); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Visitor session " + sessionName + + log.log(Level.FINE, "Visitor session " + sessionName + ": Received VisitorInfo with " + msg.getFinishedBuckets().size() + " finished buckets"); } @@ -902,7 +902,7 @@ public class MessageBusVisitorSession implements VisitorSession { progress.getIterator().update(bucket, subProgress); String message = getErrorMessage(reply.getError(0)); - log.log(LogLevel.DEBUG, sessionName + ": received error reply for bucket " + + log.log(Level.FINE, sessionName + ": received error reply for bucket " + bucket + " with message '" + message + "'"); if (isFatalError(reply)) { @@ -1027,7 +1027,7 @@ public class MessageBusVisitorSession implements VisitorSession { BucketId superbucket = msg.getBuckets().get(0); BucketId subBucketProgress = reply.getLastBucket(); - log.log(LogLevel.DEBUG, sessionName + ": received CreateVisitorReply for bucket " + + log.log(Level.FINE, sessionName + ": received CreateVisitorReply for bucket " + superbucket + " with progress " + subBucketProgress); progress.getIterator().update(superbucket, subBucketProgress); @@ -1045,7 +1045,7 @@ public class MessageBusVisitorSession implements VisitorSession { int newMaxBuckets = Math.max(Math.min((int)(params.getMaxBucketsPerVisitor() * params.getDynamicMaxBucketsIncreaseFactor()), 128), 1); params.setMaxBucketsPerVisitor(newMaxBuckets); - log.log(LogLevel.DEBUG, sessionName + ": increasing max buckets per visitor to " + log.log(Level.FINE, sessionName + ": increasing max buckets per visitor to " + params.getMaxBucketsPerVisitor()); } } @@ -1055,7 +1055,7 @@ public class MessageBusVisitorSession implements VisitorSession { ClusterState newState = new ClusterState(reply.getSystemState()); int stateBits = newState.getDistributionBitCount(); if (stateBits != progress.getIterator().getDistributionBitCount()) { - log.log(LogLevel.DEBUG, "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 @@ -1102,7 +1102,7 @@ public class MessageBusVisitorSession implements VisitorSession { @Override public void ack(AckToken token) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Visitor session " + sessionName + + log.log(Level.FINE, "Visitor session " + sessionName + ": Sending ack " + token.ackObject); } // No locking here; replying should be thread safe in itself @@ -1144,7 +1144,7 @@ public class MessageBusVisitorSession implements VisitorSession { @Override public void destroy() { - log.log(LogLevel.DEBUG, sessionName + ": synchronous destroy() called"); + log.log(Level.FINE, sessionName + ": synchronous destroy() called"); try { synchronized (progress.getToken()) { synchronized (completionMonitor) { @@ -1172,7 +1172,7 @@ public class MessageBusVisitorSession implements VisitorSession { } catch (Exception e) { log.log(LogLevel.ERROR, "Caught exception destroying communication interfaces", e); } - log.log(LogLevel.DEBUG, sessionName + ": synchronous destroy() done"); + log.log(Level.FINE, sessionName + ": synchronous destroy() done"); } } } diff --git a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/protocol/StoragePolicy.java b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/protocol/StoragePolicy.java index 236a2a6c0f6..f89ab28ee16 100644 --- a/documentapi/src/main/java/com/yahoo/documentapi/messagebus/protocol/StoragePolicy.java +++ b/documentapi/src/main/java/com/yahoo/documentapi/messagebus/protocol/StoragePolicy.java @@ -395,7 +395,7 @@ public class StoragePolicy extends SlobrokPolicy { return targetSpec; } else { sendRandomReason = "Want to use distributor " + target + " but it is not in slobrok. Sending to random."; - log.log(LogLevel.DEBUG, "Target distributor is not in slobrok"); + log.log(Level.FINE, "Target distributor is not in slobrok"); } } else { context.setContext(new MessageContext(cachedClusterState)); @@ -407,7 +407,7 @@ public class StoragePolicy extends SlobrokPolicy { context.setReply(reply); return null; } catch (Distribution.NoDistributorsAvailableException e) { - log.log(LogLevel.DEBUG, "No distributors available; clearing cluster state"); + log.log(Level.FINE, "No distributors available; clearing cluster state"); safeCachedClusterState.set(null); sendRandomReason = "No distributors available. Sending to random distributor."; context.setContext(createRandomDistributorTargetContext()); @@ -482,7 +482,7 @@ public class StoragePolicy extends SlobrokPolicy { // reject an operation bound to a particular bucket if it does not own the bucket in _both_ // the current and the next (transition target) state. Since it can happen during normal operation // and will happen per client operation, we keep this as debug level to prevent spamming the logs. - log.log(LogLevel.DEBUG, msg); + log.log(Level.FINE, msg); } else if (newState.getVersion() > context.usedState.getVersion()) { if (reply.getTrace().shouldTrace(1)) { reply.getTrace().trace(1, "Message sent to distributor " + context.calculatedDistributor + 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 e83a78df719..e95eaa754b6 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(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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/CompressedFileReference.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java index 5ea4092e0c6..66b713ac6ba 100644 --- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java +++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java @@ -63,7 +63,7 @@ public class CompressedFileReference { } static void decompress(File inputFile, File outputDir) throws IOException { - log.log(LogLevel.DEBUG, () -> "Decompressing '" + inputFile + "' into '" + outputDir + "'"); + log.log(Level.FINE, () -> "Decompressing '" + inputFile + "' into '" + outputDir + "'"); try (ArchiveInputStream ais = new TarArchiveInputStream(new GZIPInputStream(new FileInputStream(inputFile)))) { decompress(ais, outputDir); } catch (IllegalArgumentException e) { @@ -78,7 +78,7 @@ public class CompressedFileReference { File outFile = new File(outputFile, entry.getName()); if (entry.isDirectory()) { if (!(outFile.exists() && outFile.isDirectory())) { - log.log(LogLevel.DEBUG, () -> "Creating dir: " + outFile.getAbsolutePath()); + log.log(Level.FINE, () -> "Creating dir: " + outFile.getAbsolutePath()); if (!outFile.mkdirs()) { log.log(LogLevel.WARNING, "Could not create dir " + entry.getName()); } @@ -113,7 +113,7 @@ public class CompressedFileReference { } private static void writeFileToTar(ArchiveOutputStream taos, File baseDir, File file) throws IOException { - log.log(LogLevel.DEBUG, () -> "Adding file to tar: " + baseDir.toPath().relativize(file.toPath()).toString()); + log.log(Level.FINE, () -> "Adding file to tar: " + baseDir.toPath().relativize(file.toPath()).toString()); taos.putArchiveEntry(taos.createArchiveEntry(file, baseDir.toPath().relativize(file.toPath()).toString())); ByteStreams.copy(new FileInputStream(file), taos); taos.closeArchiveEntry(); diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileDownloader.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileDownloader.java index 57281d4a84b..cb3a3caf2d4 100644 --- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileDownloader.java +++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileDownloader.java @@ -89,7 +89,7 @@ public class FileDownloader { } else if (!file.canRead()) { throw new RuntimeException("File reference '" + fileReference.value() + "'exists, but unable to read it"); } else { - log.log(LogLevel.DEBUG, () -> "File reference '" + fileReference.value() + "' found: " + file.getAbsolutePath()); + log.log(Level.FINE, () -> "File reference '" + fileReference.value() + "' found: " + file.getAbsolutePath()); fileReferenceDownloader.setDownloadStatus(fileReference, 1.0); return Optional.of(file); } 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 0228ad0a5a2..a79f3831c17 100644 --- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java +++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java @@ -123,7 +123,7 @@ public class FileReceiver { log.log(LogLevel.ERROR, "Failed creating directory (" + fileReferenceDir.toPath() + "): " + e.getMessage(), e); throw new RuntimeException("Failed creating directory (" + fileReferenceDir.toPath() + "): ", e); } - log.log(LogLevel.DEBUG, () -> "Uncompressed file, moving to " + file.getAbsolutePath()); + log.log(Level.FINE, () -> "Uncompressed file, moving to " + file.getAbsolutePath()); moveFileToDestination(inprogressFile, file); } } catch (IOException e) { @@ -188,7 +188,7 @@ public class FileReceiver { private static void moveFileToDestination(File tempFile, File destination) { try { Files.move(tempFile.toPath(), destination.toPath()); - log.log(LogLevel.DEBUG, () -> "File moved from " + tempFile.getAbsolutePath()+ " to " + destination.getAbsolutePath()); + log.log(Level.FINE, () -> "File moved from " + tempFile.getAbsolutePath()+ " to " + destination.getAbsolutePath()); } 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. @@ -215,7 +215,7 @@ public class FileReceiver { } private void receiveFileMeta(Request req) { - log.log(LogLevel.DEBUG, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); + log.log(Level.FINE, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); FileReference reference = new FileReference(req.parameters().get(0).asString()); String fileName = req.parameters().get(1).asString(); String type = req.parameters().get(2).asString(); @@ -240,7 +240,7 @@ public class FileReceiver { } private void receiveFilePart(Request req) { - log.log(LogLevel.DEBUG, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); + log.log(Level.FINE, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); FileReference reference = new FileReference(req.parameters().get(0).asString()); int sessionId = req.parameters().get(1).asInt32(); @@ -261,7 +261,7 @@ public class FileReceiver { } private void receiveFileEof(Request req) { - log.log(LogLevel.DEBUG, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); + log.log(Level.FINE, () -> "Received method call '" + req.methodName() + "' with parameters : " + req.parameters()); FileReference reference = new FileReference(req.parameters().get(0).asString()); int sessionId = req.parameters().get(1).asInt32(); long xxhash = req.parameters().get(2).asInt64(); diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java index 4a3c474a436..35f8636c0f9 100644 --- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java +++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java @@ -81,7 +81,7 @@ public class FileReferenceDownloader { void addToDownloadQueue(FileReferenceDownload fileReferenceDownload) { FileReference fileReference = fileReferenceDownload.fileReference(); - log.log(LogLevel.DEBUG, () -> "Will download file reference '" + fileReference.value() + "' with timeout " + downloadTimeout); + log.log(Level.FINE, () -> "Will download file reference '" + fileReference.value() + "' with timeout " + downloadTimeout); synchronized (downloads) { downloads.put(fileReference, fileReferenceDownload); downloadStatus.put(fileReference, 0.0); @@ -97,7 +97,7 @@ public class FileReferenceDownloader { downloads.remove(fileReference); download.future().complete(Optional.of(file)); } else { - log.log(LogLevel.DEBUG, () -> "Received '" + fileReference + "', which was not requested. Can be ignored if happening during upgrades/restarts"); + log.log(Level.FINE, () -> "Received '" + fileReference + "', which was not requested. Can be ignored if happening during upgrades/restarts"); } } } diff --git a/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/athenz/AthenzAuthorizationFilter.java b/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/athenz/AthenzAuthorizationFilter.java index 0f69003d7ee..18cd6cf02c1 100644 --- a/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/athenz/AthenzAuthorizationFilter.java +++ b/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/athenz/AthenzAuthorizationFilter.java @@ -79,7 +79,7 @@ public class AthenzAuthorizationFilter extends JsonSecurityRequestFilterBase { try { Optional<ResourceNameAndAction> resourceMapping = requestResourceMapper.getResourceNameAndAction(request.getMethod(), request.getRequestURI(), request.getQueryString()); - log.log(LogLevel.DEBUG, () -> String.format("Resource mapping for '%s': %s", request, resourceMapping)); + log.log(Level.FINE, () -> String.format("Resource mapping for '%s': %s", request, resourceMapping)); if (resourceMapping.isEmpty()) { incrementAcceptedMetrics(request, false); return Optional.empty(); @@ -92,11 +92,11 @@ public class AthenzAuthorizationFilter extends JsonSecurityRequestFilterBase { incrementAcceptedMetrics(request, true); return Optional.empty(); } - log.log(LogLevel.DEBUG, () -> String.format("Forbidden (403) for '%s': %s", request, resultType.name())); + log.log(Level.FINE, () -> String.format("Forbidden (403) for '%s': %s", request, resultType.name())); incrementRejectedMetrics(request, FORBIDDEN, resultType.name()); return Optional.of(new ErrorResponse(FORBIDDEN, "Access forbidden: " + resultType.getDescription())); } catch (IllegalArgumentException e) { - log.log(LogLevel.DEBUG, () -> String.format("Unauthorized (401) for '%s': %s", request, e.getMessage())); + log.log(Level.FINE, () -> String.format("Unauthorized (401) for '%s': %s", request, e.getMessage())); incrementRejectedMetrics(request, UNAUTHORIZED, "Unauthorized"); return Optional.of(new ErrorResponse(UNAUTHORIZED, e.getMessage())); } @@ -196,7 +196,7 @@ public class AthenzAuthorizationFilter extends JsonSecurityRequestFilterBase { } private static void setAttribute(DiscFilterRequest request, String name, String value) { - log.log(LogLevel.DEBUG, () -> String.format("Setting attribute on '%s': '%s' = '%s'", request, name, value)); + log.log(Level.FINE, () -> String.format("Setting attribute on '%s': '%s' = '%s'", request, name, value)); request.setAttribute(name, value); } diff --git a/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/base/JsonSecurityRequestFilterBase.java b/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/base/JsonSecurityRequestFilterBase.java index 514fdbcc745..ec6b1361ebc 100644 --- a/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/base/JsonSecurityRequestFilterBase.java +++ b/jdisc-security-filters/src/main/java/com/yahoo/jdisc/http/filter/security/base/JsonSecurityRequestFilterBase.java @@ -41,7 +41,7 @@ public abstract class JsonSecurityRequestFilterBase extends AbstractComponent im errorMessage.put("message", error.message); error.response.headers().put("Content-Type", "application/json"); // Note: Overwrites header if already exists error.response.headers().put("Cache-Control", "must-revalidate,no-cache,no-store"); - log.log(LogLevel.DEBUG, () -> String.format("Error response for '%s': statusCode=%d, errorCode=%d, message='%s'", + log.log(Level.FINE, () -> String.format("Error response for '%s': statusCode=%d, errorCode=%d, message='%s'", request, error.response.getStatus(), error.errorCode, error.message)); try (FastContentWriter writer = ResponseDispatch.newInstance(error.response).connectFastWriter(responseHandler)) { writer.write(mapper.writerWithDefaultPrettyPrinter().writeValueAsString(errorMessage)); diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusClient.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusClient.java index 6ecb36f7af9..8045e35604a 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusClient.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusClient.java @@ -72,7 +72,7 @@ public final class MbusClient extends AbstractResource implements ClientProvider @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying message bus client."); + log.log(Level.FINE, "Destroying message bus client."); sessionReference.close(); done = true; } diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusServer.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusServer.java index 5893e4f6252..e26e1e7e134 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusServer.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/jdisc/MbusServer.java @@ -42,19 +42,19 @@ public final class MbusServer extends AbstractResource implements ServerProvider @Override public void start() { - log.log(LogLevel.DEBUG, "Starting message bus server."); + log.log(Level.FINE, "Starting message bus server."); running.set(true); } @Override public void close() { - log.log(LogLevel.DEBUG, "Closing message bus server."); + log.log(Level.FINE, "Closing message bus server."); running.set(false); } @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying message bus server."); + log.log(Level.FINE, "Destroying message bus server."); running.set(false); sessionReference.close(); } diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedDestinationSession.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedDestinationSession.java index d9db66b6041..7da164757cd 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedDestinationSession.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedDestinationSession.java @@ -78,7 +78,7 @@ public class SharedDestinationSession extends AbstractResource implements Messag @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying shared destination session."); + log.log(Level.FINE, "Destroying shared destination session."); session.destroy(); mbusReference.close(); } diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedIntermediateSession.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedIntermediateSession.java index 9a50101a492..5c9fab46e34 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedIntermediateSession.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedIntermediateSession.java @@ -97,7 +97,7 @@ public class SharedIntermediateSession extends AbstractResource @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying shared intermediate session."); + log.log(Level.FINE, "Destroying shared intermediate session."); session.destroy(); mbusReference.close(); } diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedMessageBus.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedMessageBus.java index 8c084f0f9e4..dd135a51378 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedMessageBus.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedMessageBus.java @@ -35,7 +35,7 @@ public class SharedMessageBus extends AbstractResource { @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying shared message bus."); + log.log(Level.FINE, "Destroying shared message bus."); mbus.destroy(); } diff --git a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedSourceSession.java b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedSourceSession.java index a75bf6513f9..56071682349 100644 --- a/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedSourceSession.java +++ b/jdisc_messagebus_service/src/main/java/com/yahoo/messagebus/shared/SharedSourceSession.java @@ -50,7 +50,7 @@ public class SharedSourceSession extends AbstractResource implements ClientSessi @Override protected void destroy() { - log.log(LogLevel.DEBUG, "Destroying shared source session."); + log.log(Level.FINE, "Destroying shared source session."); session.close(); mbusReference.close(); } diff --git a/logserver/src/main/java/com/yahoo/logserver/AbstractPluginLoader.java b/logserver/src/main/java/com/yahoo/logserver/AbstractPluginLoader.java index b1d8de1bd98..580c621cb20 100644 --- a/logserver/src/main/java/com/yahoo/logserver/AbstractPluginLoader.java +++ b/logserver/src/main/java/com/yahoo/logserver/AbstractPluginLoader.java @@ -40,7 +40,7 @@ public abstract class AbstractPluginLoader implements PluginLoader { try { plugin.initPlugin(config); - log.log(LogLevel.DEBUG, pname + ": plugin loaded"); + log.log(Level.FINE, pname + ": plugin loaded"); } catch (Exception e) { log.log(LogLevel.ERROR, pname + ": init failed", e); } diff --git a/logserver/src/main/java/com/yahoo/logserver/BuiltinPluginLoader.java b/logserver/src/main/java/com/yahoo/logserver/BuiltinPluginLoader.java index c67dbe3bce8..3a87ec920a8 100644 --- a/logserver/src/main/java/com/yahoo/logserver/BuiltinPluginLoader.java +++ b/logserver/src/main/java/com/yahoo/logserver/BuiltinPluginLoader.java @@ -17,12 +17,12 @@ public class BuiltinPluginLoader extends AbstractPluginLoader { private static final Logger log = Logger.getLogger(BuiltinPluginLoader.class.getName()); public void loadPlugins() { - log.log(LogLevel.DEBUG, "starting to load builtin plugins"); + log.log(Level.FINE, "starting to load builtin plugins"); loadFromClass(ArchiverPlugin.class); loadFromClass(LogMetricsPlugin.class); - log.log(LogLevel.DEBUG, "done loading builtin plugins"); + log.log(Level.FINE, "done loading builtin plugins"); } } diff --git a/logserver/src/main/java/com/yahoo/logserver/Flusher.java b/logserver/src/main/java/com/yahoo/logserver/Flusher.java index 8958d350a89..b155c8eb893 100644 --- a/logserver/src/main/java/com/yahoo/logserver/Flusher.java +++ b/logserver/src/main/java/com/yahoo/logserver/Flusher.java @@ -46,7 +46,7 @@ public class Flusher extends Thread { h.flush(); } if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Flushing " + h); + log.log(Level.FINE, "Flushing " + h); } } } diff --git a/logserver/src/main/java/com/yahoo/logserver/LogDispatcher.java b/logserver/src/main/java/com/yahoo/logserver/LogDispatcher.java index e74fa7a81f0..7c34963ae4f 100644 --- a/logserver/src/main/java/com/yahoo/logserver/LogDispatcher.java +++ b/logserver/src/main/java/com/yahoo/logserver/LogDispatcher.java @@ -118,7 +118,7 @@ public class LogDispatcher implements LogHandler { for (LogHandler h : handlers) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Flushing " + h.toString()); + log.log(Level.FINE, "Flushing " + h.toString()); } h.flush(); } @@ -138,7 +138,7 @@ public class LogDispatcher implements LogHandler { } handlers.clear(); - log.log(LogLevel.DEBUG, "Logdispatcher shut down. Handled " + messageCount + " messages"); + log.log(Level.FINE, "Logdispatcher shut down. Handled " + messageCount + " messages"); } /** 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 e73ae531ecc..ea6883cbe29 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 @@ -212,12 +212,12 @@ public class ArchiverHandler extends AbstractLogHandler { // ensure that root dir exists if (root.isDirectory()) { - log.log(LogLevel.DEBUG, "Using " + absoluteRootDir + " as root"); + log.log(Level.FINE, "Using " + absoluteRootDir + " as root"); } else { if (! root.mkdirs()) { log.log(LogLevel.ERROR, "Unable to create directory " + absoluteRootDir); } else { - log.log(LogLevel.DEBUG, "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 8635534ba7b..9d550a16a7e 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(LogLevel.DEBUG, "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/DynamicThrottlePolicy.java b/messagebus/src/main/java/com/yahoo/messagebus/DynamicThrottlePolicy.java index d2e3c84baab..db464c1cd99 100644 --- a/messagebus/src/main/java/com/yahoo/messagebus/DynamicThrottlePolicy.java +++ b/messagebus/src/main/java/com/yahoo/messagebus/DynamicThrottlePolicy.java @@ -101,7 +101,7 @@ public class DynamicThrottlePolicy extends StaticThrottlePolicy { localMaxThroughput = throughput; windowSize += weight*windowSizeIncrement; if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "windowSize " + windowSize + " throughput " + throughput + " local max " + localMaxThroughput); + log.log(Level.FINE, "windowSize " + windowSize + " throughput " + throughput + " local max " + localMaxThroughput); } } else { // scale up/down throughput for comparing to window size @@ -120,7 +120,7 @@ public class DynamicThrottlePolicy extends StaticThrottlePolicy { windowSize += weight*windowSizeIncrement; } if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "windowSize " + windowSize + " throughput " + throughput + " local max " + localMaxThroughput + " efficiency " + efficiency); + log.log(Level.FINE, "windowSize " + windowSize + " throughput " + throughput + " local max " + localMaxThroughput + " efficiency " + efficiency); } } windowSize = Math.max(minWindowSize, windowSize); diff --git a/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java b/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java index da143877083..77bbd662cc4 100644 --- a/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java +++ b/messagebus/src/main/java/com/yahoo/messagebus/SendProxy.java @@ -59,7 +59,7 @@ public class SendProxy implements MessageHandler, ReplyHandler { Trace trace = msg.getTrace(); if (logTrace) { if (reply.hasErrors()) { - log.log(LogLevel.DEBUG, "Trace for reply with error(s):\n" + reply.getTrace()); + log.log(Level.FINE, "Trace for reply with error(s):\n" + reply.getTrace()); } else if (log.isLoggable(LogLevel.SPAM)) { log.log(LogLevel.SPAM, "Trace for reply:\n" + reply.getTrace()); } diff --git a/messagebus/src/main/java/com/yahoo/messagebus/network/rpc/RPCTarget.java b/messagebus/src/main/java/com/yahoo/messagebus/network/rpc/RPCTarget.java index 9cab213b628..b8faafe54bb 100755 --- a/messagebus/src/main/java/com/yahoo/messagebus/network/rpc/RPCTarget.java +++ b/messagebus/src/main/java/com/yahoo/messagebus/network/rpc/RPCTarget.java @@ -102,12 +102,12 @@ public class RPCTarget implements RequestWaiter { synchronized (this) { if (version != null) { if (shouldLog) { - log.log(LogLevel.DEBUG, "Version already available for target '" + name + "' (version " + version + ")."); + log.log(Level.FINE, "Version already available for target '" + name + "' (version " + version + ")."); } hasVersion = true; } else { if (shouldLog) { - log.log(LogLevel.DEBUG, "Registering version handler '" + handler + "' for target '" + name + "'."); + log.log(Level.FINE, "Registering version handler '" + handler + "' for target '" + name + "'."); } versionHandlers.add(handler); if (!targetInvoked) { @@ -120,7 +120,7 @@ public class RPCTarget implements RequestWaiter { handler.handleVersion(version); } else if (shouldInvoke) { if (shouldLog) { - log.log(LogLevel.DEBUG, "Invoking mbus.getVersion() on target '" + name + "'"); + log.log(Level.FINE, "Invoking mbus.getVersion() on target '" + name + "'"); } Request req = new Request("mbus.getVersion"); target.invokeAsync(req, timeout, this); @@ -138,7 +138,7 @@ public class RPCTarget implements RequestWaiter { try { version = new Version(str); if (shouldLog) { - log.log(LogLevel.DEBUG, "Target '" + name + "' has version " + version + "."); + log.log(Level.FINE, "Target '" + name + "' has version " + version + "."); } } catch (IllegalArgumentException e) { log.log(LogLevel.WARNING, "Failed to parse '" + str + "' as version for target '" + name + "'.", e); diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/http/application/ApplicationMetricsRetriever.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/http/application/ApplicationMetricsRetriever.java index 8edae823a97..4d57e89fc76 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/http/application/ApplicationMetricsRetriever.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/http/application/ApplicationMetricsRetriever.java @@ -69,7 +69,7 @@ public class ApplicationMetricsRetriever extends AbstractComponent { } public Map<Node, List<MetricsPacket.Builder>> getMetrics(ConsumerId consumer) { - log.log(LogLevel.DEBUG, () -> "Retrieving metrics from " + clients.size() + " nodes."); + log.log(Level.FINE, () -> "Retrieving metrics from " + clients.size() + " nodes."); var forkJoinTask = forkJoinPool.submit(() -> clients.parallelStream() .map(client -> getNodeMetrics(client, consumer)) .collect(toMap(Map.Entry::getKey, Map.Entry::getValue))); @@ -77,7 +77,7 @@ public class ApplicationMetricsRetriever extends AbstractComponent { try { var metricsByNode = forkJoinTask.get(taskTimeout.toMillis(), TimeUnit.MILLISECONDS); - log.log(LogLevel.DEBUG, () -> "Finished retrieving metrics from " + clients.size() + " nodes."); + log.log(Level.FINE, () -> "Finished retrieving metrics from " + clients.size() + " nodes."); return metricsByNode; } catch (Exception e) { 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 449309d8a3e..06036aa90d5 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 @@ -58,7 +58,7 @@ public class ConfigSentinelClient extends AbstractComponent { synchronized void ping(VespaService s) { List<VespaService> services = new ArrayList<>(); services.add(s); - log.log(LogLevel.DEBUG, "Ping for service " + s); + log.log(Level.FINE, "Ping for service " + s); try { setStatus(services); } catch (Exception e) { @@ -92,7 +92,7 @@ public class ConfigSentinelClient extends AbstractComponent { //from the sentinel for (VespaService s : services) { if ((!s.getServiceName().equals("configserver")) && !updatedServices.contains(s)) { - log.log(LogLevel.DEBUG,"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 a5c0e0e2395..0a17810d3cc 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 @@ -40,11 +40,11 @@ public abstract class HttpMetricFetcher { String u = "http://localhost:" + port + path; this.url = URI.create(u); - log.log(LogLevel.DEBUG, "Fetching metrics from " + u + " with timeout " + CONNECTION_TIMEOUT); + log.log(Level.FINE, "Fetching metrics from " + u + " with timeout " + CONNECTION_TIMEOUT); } String getJson() throws IOException { - log.log(LogLevel.DEBUG, "Connecting to url " + url + " for service '" + service + "'"); + log.log(Level.FINE, "Connecting to url " + url + " for service '" + service + "'"); return httpClient.execute(new HttpGet(url), new BasicResponseHandler()); } @@ -66,7 +66,7 @@ public abstract class HttpMetricFetcher { if (service.isAlive() && timesFetched > 5) { log.log(LogLevel.INFO, message); } else { - log.log(LogLevel.DEBUG, message); + log.log(Level.FINE, message); } } 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 4bc9055c6a5..1cab1a859a9 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 @@ -64,7 +64,7 @@ public class RemoteHealthMetricFetcher extends HttpMetricFetcher { return HealthMetric.get(code, message); } catch (JSONException e) { - log.log(LogLevel.DEBUG, "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 3e8eeea1268..7620e94fc9e 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 @@ -81,7 +81,7 @@ public class SystemPoller { br.close(); } catch (IOException ex) { - log.log(LogLevel.DEBUG, "Unable to read line from smaps file", ex); + log.log(Level.FINE, "Unable to read line from smaps file", ex); return size; } @@ -101,7 +101,7 @@ public class SystemPoller { return; } - log.log(LogLevel.DEBUG, "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) { @@ -112,10 +112,10 @@ public class SystemPoller { } Metrics metrics = new Metrics(); - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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)); @@ -152,7 +152,7 @@ public class SystemPoller { try { in = new BufferedReader(new FileReader("/proc/" + pid + "/stat")); } catch (FileNotFoundException ex) { - log.log(LogLevel.DEBUG, "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; } @@ -161,7 +161,7 @@ public class SystemPoller { line = in.readLine(); in.close(); } catch (IOException ex) { - log.log(LogLevel.DEBUG, "Unable to read line from process stat file", ex); + log.log(Level.FINE, "Unable to read line from process stat file", ex); return 0; } diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/Telegraf.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/Telegraf.java index 25e2b9068ab..5c7d8b3ce83 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/Telegraf.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/Telegraf.java @@ -76,7 +76,7 @@ public class Telegraf extends AbstractComponent { ProcessResult processResult = uncheck(() -> processExecutor.execute(command)) .orElseThrow(() -> new RuntimeException("Timed out running command: " + command)); - logger.log(LogLevel.DEBUG, () -> String.format("Exit code: %d\nstdOut: %s\nstdErr: %s", + logger.log(Level.FINE, () -> String.format("Exit code: %d\nstdOut: %s\nstdErr: %s", processResult.exitCode, processResult.stdOut, processResult.stdErr)); diff --git a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/TelegrafRegistry.java b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/TelegrafRegistry.java index 0f36bf6125e..3864d25c2a6 100644 --- a/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/TelegrafRegistry.java +++ b/metrics-proxy/src/main/java/ai/vespa/metricsproxy/telegraf/TelegrafRegistry.java @@ -18,12 +18,12 @@ public class TelegrafRegistry { private static final Logger logger = Logger.getLogger(TelegrafRegistry.class.getName()); public void addInstance(Telegraf telegraf) { - logger.log(LogLevel.DEBUG, () -> "Adding Telegraf instance to registry: " + telegraf.hashCode()); + logger.log(Level.FINE, () -> "Adding Telegraf instance to registry: " + telegraf.hashCode()); telegrafInstances.add(telegraf); } public void removeInstance(Telegraf telegraf) { - logger.log(LogLevel.DEBUG, () -> "Removing Telegraf instance from registry: " + telegraf.hashCode()); + logger.log(Level.FINE, () -> "Removing Telegraf instance from registry: " + telegraf.hashCode()); telegrafInstances.remove(telegraf); } diff --git a/node-admin/src/main/java/com/yahoo/vespa/hosted/node/admin/task/util/process/ProcessStarterImpl.java b/node-admin/src/main/java/com/yahoo/vespa/hosted/node/admin/task/util/process/ProcessStarterImpl.java index 66927e6a2b9..3e2c14a2935 100644 --- a/node-admin/src/main/java/com/yahoo/vespa/hosted/node/admin/task/util/process/ProcessStarterImpl.java +++ b/node-admin/src/main/java/com/yahoo/vespa/hosted/node/admin/task/util/process/ProcessStarterImpl.java @@ -17,7 +17,7 @@ public class ProcessStarterImpl implements ProcessStarter { @Override public ProcessApi2 start(ProcessBuilder processBuilder) { if (logger.isLoggable(LogLevel.DEBUG)) { - logger.log(LogLevel.DEBUG, "Spawning process: " + processBuilder.command()); + logger.log(Level.FINE, "Spawning process: " + processBuilder.command()); } Process process = uncheck(processBuilder::start); diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/DnsNameResolver.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/DnsNameResolver.java index aef6cce2a46..6d2c074ab36 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/DnsNameResolver.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/persistence/DnsNameResolver.java @@ -52,7 +52,7 @@ public class DnsNameResolver implements NameResolver { return InetAddresses.isInetAddress(hostname) ? Optional.empty() : Optional.of(hostname); } catch (UnknownHostException e) { // This is not an exceptional state hence the debug level - logger.log(LogLevel.DEBUG, "Unable to resolve ipaddress", e); + logger.log(Level.FINE, "Unable to resolve ipaddress", e); } return Optional.empty(); } 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 df3d2dedb4e..8a31b271406 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 @@ -101,7 +101,7 @@ public class InfraDeployerImpl implements InfraDeployer { prepare(); if (hostSpecs.isEmpty()) { - logger.log(LogLevel.DEBUG, "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(); @@ -112,7 +112,7 @@ public class InfraDeployerImpl implements InfraDeployer { application.getApplicationId(), hostSpecs.stream().map(HostSpec::hostname).map(HostName::from).collect(Collectors.toList())); - logger.log(LogLevel.DEBUG, () -> generateActivationLogMessage(hostSpecs, application.getApplicationId())); + logger.log(Level.FINE, () -> generateActivationLogMessage(hostSpecs, application.getApplicationId())); } } } 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 d48f02e18e8..3532d989d85 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 @@ -166,7 +166,7 @@ public class LoadBalancerProvisioner { reals.add(new Real(HostName.from(node.hostname()), ip)); } } - log.log(LogLevel.DEBUG, "Creating load balancer for " + cluster + " in " + application.toShortString() + + log.log(Level.FINE, "Creating load balancer for " + cluster + " in " + application.toShortString() + ", targeting: " + reals); try { return service.create(application, cluster, reals, force); diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodePrioritizer.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodePrioritizer.java index e8d8cd209f5..590847b8b7e 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodePrioritizer.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodePrioritizer.java @@ -149,7 +149,7 @@ public class NodePrioritizer { if (!hostHasCapacityForWantedFlavor || conflictingCluster) continue; - log.log(LogLevel.DEBUG, "Trying to add new Docker node on " + host); + log.log(Level.FINE, "Trying to add new Docker node on " + host); Optional<IP.Allocation> allocation; try { allocation = host.ipConfig().pool().findAllocation(allNodes, nameResolver); @@ -167,7 +167,7 @@ public class NodePrioritizer { NodeType.tenant); PrioritizableNode nodePri = toPrioritizable(newNode, false, true); if ( ! nodePri.violatesSpares || isAllocatingForReplacement) { - log.log(LogLevel.DEBUG, "Adding new Docker node " + newNode); + log.log(Level.FINE, "Adding new Docker node " + newNode); nodes.put(newNode, nodePri); } } diff --git a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodeRepositoryProvisioner.java b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodeRepositoryProvisioner.java index a74671d4e26..d2e214d9199 100644 --- a/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodeRepositoryProvisioner.java +++ b/node-repository/src/main/java/com/yahoo/vespa/hosted/provision/provisioning/NodeRepositoryProvisioner.java @@ -183,7 +183,7 @@ public class NodeRepositoryProvisioner implements Provisioner { nodes.sort(Comparator.comparingInt(node -> node.allocation().get().membership().index())); List<HostSpec> hosts = new ArrayList<>(nodes.size()); for (Node node : nodes) { - log.log(LogLevel.DEBUG, () -> "Prepared node " + node.hostname() + " - " + node.flavor()); + log.log(Level.FINE, () -> "Prepared node " + node.hostname() + " - " + node.flavor()); Allocation nodeAllocation = node.allocation().orElseThrow(IllegalStateException::new); hosts.add(new HostSpec(node.hostname(), List.of(), @@ -194,7 +194,7 @@ public class NodeRepositoryProvisioner implements Provisioner { requestedResources == NodeResources.unspecified ? Optional.empty() : Optional.of(requestedResources), node.status().dockerImage())); if (nodeAllocation.networkPorts().isPresent()) { - log.log(LogLevel.DEBUG, () -> "Prepared node " + node.hostname() + " has port allocations"); + log.log(Level.FINE, () -> "Prepared node " + node.hostname() + " has port allocations"); } } return hosts; diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/model/StorageNodeImpl.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/model/StorageNodeImpl.java index d79accc5b36..72033e41192 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/model/StorageNodeImpl.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/model/StorageNodeImpl.java @@ -62,7 +62,7 @@ public class StorageNodeImpl implements StorageNode { ConfigId configId = storageService.configId(); int nodeIndex = VespaModelUtil.getStorageNodeIndex(configId); - logger.log(LogLevel.DEBUG, () -> "Setting cluster controller state for " + + logger.log(Level.FINE, () -> "Setting cluster controller state for " + "application " + applicationInstance.reference().asString() + ", host " + hostName() + ", cluster name " + clusterId + diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostResource.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostResource.java index 5d4090fea30..9ed9e1b9063 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostResource.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostResource.java @@ -78,10 +78,10 @@ public class HostResource implements HostApi { applicationUri.toString(), hostServices); } catch (UncheckedTimeoutException e) { - log.log(LogLevel.DEBUG, "Failed to get host " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to get host " + hostName + ": " + e.getMessage()); throw webExceptionFromTimeout("getHost", hostName, e); } catch (HostNameNotFoundException e) { - log.log(LogLevel.DEBUG, "Host not found: " + hostName); + log.log(Level.FINE, "Host not found: " + hostName); throw new NotFoundException(e); } } @@ -101,14 +101,14 @@ public class HostResource implements HostApi { try { orchestrator.setNodeStatus(hostName, state); } catch (HostNameNotFoundException e) { - log.log(LogLevel.DEBUG, "Host not found: " + hostName); + log.log(Level.FINE, "Host not found: " + hostName); throw new NotFoundException(e); } catch (UncheckedTimeoutException e) { - log.log(LogLevel.DEBUG, "Failed to patch " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to patch " + hostName + ": " + e.getMessage()); throw webExceptionFromTimeout("patch", hostName, e); } catch (OrchestrationException e) { String message = "Failed to set " + hostName + " to " + state + ": " + e.getMessage(); - log.log(LogLevel.DEBUG, message, e); + log.log(Level.FINE, message, e); throw new InternalServerErrorException(message); } } @@ -124,13 +124,13 @@ public class HostResource implements HostApi { try { orchestrator.suspend(hostName); } catch (HostNameNotFoundException e) { - log.log(LogLevel.DEBUG, "Host not found: " + hostName); + log.log(Level.FINE, "Host not found: " + hostName); throw new NotFoundException(e); } catch (UncheckedTimeoutException e) { - log.log(LogLevel.DEBUG, "Failed to suspend " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to suspend " + hostName + ": " + e.getMessage()); throw webExceptionFromTimeout("suspend", hostName, e); } catch (HostStateChangeDeniedException e) { - log.log(LogLevel.DEBUG, "Failed to suspend " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to suspend " + hostName + ": " + e.getMessage()); throw webExceptionWithDenialReason("suspend", hostName, e); } return new UpdateHostResponse(hostName.s(), null); @@ -142,13 +142,13 @@ public class HostResource implements HostApi { try { orchestrator.resume(hostName); } catch (HostNameNotFoundException e) { - log.log(LogLevel.DEBUG, "Host not found: " + hostName); + log.log(Level.FINE, "Host not found: " + hostName); throw new NotFoundException(e); } catch (UncheckedTimeoutException e) { - log.log(LogLevel.DEBUG, "Failed to resume " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to resume " + hostName + ": " + e.getMessage()); throw webExceptionFromTimeout("resume", hostName, e); } catch (HostStateChangeDeniedException e) { - log.log(LogLevel.DEBUG, "Failed to resume " + hostName + ": " + e.getMessage()); + log.log(Level.FINE, "Failed to resume " + hostName + ": " + e.getMessage()); throw webExceptionWithDenialReason("resume", hostName, e); } return new UpdateHostResponse(hostName.s(), null); diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionResource.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionResource.java index 11afb8a849c..3d60d40dfcf 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionResource.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/resources/HostSuspensionResource.java @@ -43,21 +43,21 @@ public class HostSuspensionResource implements HostSuspensionApi { try { orchestrator.suspendAll(parentHostname, hostnames); } catch (BatchHostStateChangeDeniedException e) { - log.log(LogLevel.DEBUG, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); throw createWebApplicationException(e.getMessage(), Response.Status.CONFLICT); } catch (UncheckedTimeoutException e) { - log.log(LogLevel.DEBUG, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); throw createWebApplicationException(e.getMessage(), Response.Status.CONFLICT); } catch (BatchHostNameNotFoundException e) { - log.log(LogLevel.DEBUG, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); // 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 createWebApplicationException(e.getMessage(), Response.Status.BAD_REQUEST); } catch (BatchInternalErrorException e) { - log.log(LogLevel.DEBUG, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); + log.log(Level.FINE, "Failed to suspend nodes " + hostnames + " with parent host " + parentHostname, e); throw createWebApplicationException(e.getMessage(), Response.Status.INTERNAL_SERVER_ERROR); } - log.log(LogLevel.DEBUG, "Suspended " + hostnames + " with parent " + parentHostname); + log.log(Level.FINE, "Suspended " + hostnames + " with parent " + parentHostname); return BatchOperationResult.successResult(); } diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/HostInfosServiceImpl.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/HostInfosServiceImpl.java index d50eb1c7e26..cbb6902066e 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/HostInfosServiceImpl.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/HostInfosServiceImpl.java @@ -109,7 +109,7 @@ public class HostInfosServiceImpl implements HostInfosService { curator.framework().delete().forPath(path); return true; } catch (NoNodeException e) { - log.log(LogLevel.DEBUG, debugLogMessageIfNotExists, e); + log.log(Level.FINE, debugLogMessageIfNotExists, e); return false; } catch (Exception e) { throw new RuntimeException(e); diff --git a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/ZkStatusService.java b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/ZkStatusService.java index 27eea7a685b..21c3c846385 100644 --- a/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/ZkStatusService.java +++ b/orchestrator/src/main/java/com/yahoo/vespa/orchestrator/status/ZkStatusService.java @@ -93,7 +93,7 @@ public class ZkStatusService implements StatusService { return resultSet; } catch (Exception e) { - log.log(LogLevel.DEBUG, "Something went wrong while listing out applications in suspend.", e); + log.log(Level.FINE, "Something went wrong while listing out applications in suspend.", e); throw new RuntimeException(e); } } 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 84aa7f5e72f..dea80254b05 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 @@ -42,7 +42,7 @@ public class DuperModel { void setComplete() { if (!isComplete) { - logger.log(LogLevel.DEBUG, "All applications have been activated: duper model is complete"); + logger.log(Level.FINE, "All applications have been activated: duper model is complete"); isComplete = true; listeners.forEach(DuperModelListener::bootstrapComplete); @@ -95,7 +95,7 @@ public class DuperModel { } else { logPrefix = isComplete ? "Reactivated application " : "Rebootstrapped application "; } - logger.log(LogLevel.DEBUG, 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(LogLevel.DEBUG, "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 552cb09da14..3c6ff8bd903 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 @@ -149,7 +149,7 @@ public class SlobrokMonitorManagerImpl implements SlobrokApi, MonitorManager { case "storagenode": return Optional.of("storage/cluster." + configId.s()); default: - logger.log(LogLevel.DEBUG, "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/vespaclient-container-plugin/src/main/java/com/yahoo/vespa/http/server/ClientFeederV3.java b/vespaclient-container-plugin/src/main/java/com/yahoo/vespa/http/server/ClientFeederV3.java index cdd691b1ac7..6bb74e98fbd 100644 --- a/vespaclient-container-plugin/src/main/java/com/yahoo/vespa/http/server/ClientFeederV3.java +++ b/vespaclient-container-plugin/src/main/java/com/yahoo/vespa/http/server/ClientFeederV3.java @@ -170,7 +170,7 @@ class ClientFeederV3 { operationId = streamReaderV3.getNextOperationId(requestInputStream); } catch (IOException ioe) { if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, Exceptions.toMessageString(ioe), ioe); + log.log(Level.FINE, Exceptions.toMessageString(ioe), ioe); } return Optional.empty(); } diff --git a/vespaclient-core/src/main/java/com/yahoo/feedapi/MessagePropertyProcessor.java b/vespaclient-core/src/main/java/com/yahoo/feedapi/MessagePropertyProcessor.java index 42cff1ff4e7..d5596d02804 100644 --- a/vespaclient-core/src/main/java/com/yahoo/feedapi/MessagePropertyProcessor.java +++ b/vespaclient-core/src/main/java/com/yahoo/feedapi/MessagePropertyProcessor.java @@ -153,7 +153,7 @@ public class MessagePropertyProcessor implements ConfigSubscriber.SingleSubscrib defaultAbortOnSendError = feederOptions.abortOnSendError(); if (log.isLoggable(LogLevel.DEBUG)) { - log.log(LogLevel.DEBUG, "Received new config (" + + log.log(Level.FINE, "Received new config (" + "route: " + (defaultRoute != null ? defaultRoute : "<none>") + ", timeout: " + defaultTimeoutMillis + " ms, retry enabled: " + retryEnabled + ", docproc chain: " + (defaultDocprocChain != null ? defaultDocprocChain : "<none>") + 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 9b83e1d09cb..54307f01258 100755 --- a/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java +++ b/vespaclient-core/src/main/java/com/yahoo/feedapi/SharedSender.java @@ -128,14 +128,14 @@ public class SharedSender implements ReplyHandler { log.log(LogLevel.SPAM, "Received reply for file " + owner.toString() + " count was " + owner.getPending().val()); } if (owner.isAborted()) { - log.log(LogLevel.DEBUG, "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(LogLevel.DEBUG, "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/vespaclient-java/src/main/java/com/yahoo/vespavisit/VdsVisitTarget.java b/vespaclient-java/src/main/java/com/yahoo/vespavisit/VdsVisitTarget.java index 509a588dac9..a1dec70f9df 100644 --- a/vespaclient-java/src/main/java/com/yahoo/vespavisit/VdsVisitTarget.java +++ b/vespaclient-java/src/main/java/com/yahoo/vespavisit/VdsVisitTarget.java @@ -208,7 +208,7 @@ public class VdsVisitTarget { @SuppressWarnings("unchecked") public void run() throws Exception { initShutdownHook(); - log.log(LogLevel.DEBUG, "Starting VdsVisitTarget"); + log.log(Level.FINE, "Starting VdsVisitTarget"); MessageBusParams mbusParams = new MessageBusParams(new LoadTypeSet()); mbusParams.getRPCNetworkParams().setIdentity(new Identity(slobrokAddress)); 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 df1ab24901f..d71e23a0623 100644 --- a/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java +++ b/zkfacade/src/main/java/com/yahoo/vespa/curator/CuratorCompletionWaiter.java @@ -39,9 +39,9 @@ class CuratorCompletionWaiter implements Curator.CompletionWaiter { public void awaitCompletion(Duration timeout) { List<String> respondents; try { - log.log(LogLevel.DEBUG, "Synchronizing on barrier " + barrierPath); + log.log(Level.FINE, "Synchronizing on barrier " + barrierPath); respondents = awaitInternal(timeout); - log.log(LogLevel.DEBUG, "Done synchronizing on barrier " + barrierPath); + log.log(Level.FINE, "Done synchronizing on barrier " + barrierPath); } catch (Exception e) { throw new RuntimeException(e); } |