From 419c64317c70a908a5ef5c0658f0823c01feddce Mon Sep 17 00:00:00 2001 From: Jon Marius Venstad Date: Wed, 2 Feb 2022 14:55:57 +0100 Subject: Suppress host status in deploy CLIs, using debug level, and add summary at info instead --- client/go/vespa/target.go | 2 +- .../controller/deployment/InternalStepRunner.java | 48 +++++++++--- .../JobControllerApiHandlerHelperTest.java | 2 +- .../application/responses/staging-test-log.json | 16 +++- .../application/responses/system-test-details.json | 86 ++++++++++++++++++---- .../application/responses/system-test-log.json | 86 ++++++++++++++++++---- 6 files changed, 198 insertions(+), 42 deletions(-) diff --git a/client/go/vespa/target.go b/client/go/vespa/target.go index 204dda6538f..e3e019f3a76 100644 --- a/client/go/vespa/target.go +++ b/client/go/vespa/target.go @@ -412,7 +412,7 @@ func (t *cloudTarget) printLog(response jobResponse, last int64) int64 { var msgs []logMessage for step, stepMsgs := range response.Log { for _, msg := range stepMsgs { - if step == "copyVespaLogs" && LogLevel(msg.Type) > t.logOptions.Level { + if step == "copyVespaLogs" && LogLevel(msg.Type) > t.logOptions.Level || LogLevel(msg.Type) == 3 { continue } msgs = append(msgs, msg) diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java index 408b764afbe..0137d2eedeb 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java @@ -101,6 +101,7 @@ import static com.yahoo.vespa.hosted.controller.deployment.Step.installTester; import static com.yahoo.vespa.hosted.controller.deployment.Step.report; import static java.nio.charset.StandardCharsets.UTF_8; import static java.util.Objects.requireNonNull; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; import static java.util.stream.Collectors.joining; @@ -260,7 +261,7 @@ public class InternalStepRunner implements StepRunner { return result; case LOAD_BALANCER_NOT_READY: case PARENT_HOST_NOT_READY: - logger.log(e.message()); + logger.log(e.message()); // Consider splitting these messages in summary and details, on config server. return result; case OUT_OF_CAPACITY: logger.log(e.message()); @@ -279,7 +280,7 @@ public class InternalStepRunner implements StepRunner { switch (e.type()) { case CERT_NOT_AVAILABLE: // Same as CERTIFICATE_NOT_READY above, only from the controller - logger.log("Waiting for certificate to become valid: New application, or old one has expired"); + logger.log("Waiting for certificate to become valid: new application, or old one has expired"); if (startTime.plus(timeouts.endpointCertificate()).isBefore(controller.clock().instant())) { logger.log(WARNING, "Controller could not validate certificate within " + timeouts.endpointCertificate() + ": " + Exceptions.toMessageString(e)); @@ -303,7 +304,7 @@ public class InternalStepRunner implements StepRunner { private Optional installReal(RunId id, boolean setTheStage, DualLogger logger) { Optional deployment = deployment(id.application(), id.type()); if (deployment.isEmpty()) { - logger.log(INFO, "Deployment expired before installation was successful."); + logger.log("Deployment expired before installation was successful."); return Optional.of(installationFailed); } @@ -326,15 +327,32 @@ public class InternalStepRunner implements StepRunner { List parents = controller.serviceRegistry().configServer().nodeRepository().list(id.type().zone(controller.system()), NodeFilter.all() .hostnames(parentHostnames)); - NodeList nodeList = NodeList.of(nodes, parents, services.get()); boolean firstTick = run.convergenceSummary().isEmpty(); + NodeList nodeList = NodeList.of(nodes, parents, services.get()); + ConvergenceSummary summary = nodeList.summary(); if (firstTick) { // Run the first time (for each convergence step). logger.log("######## Details for all nodes ########"); logger.log(nodeList.asList().stream() .flatMap(node -> nodeDetails(node, true)) .collect(toList())); } - ConvergenceSummary summary = nodeList.summary(); + else if ( ! summary.converged()) { + logger.log("Waiting for convergence of " + summary.services() + " services across " + summary.nodes() + " nodes"); + if (summary.needPlatformUpgrade() > 0) + logger.log(summary.upgradingPlatform() + "/" + summary.needPlatformUpgrade() + " nodes upgrading platform"); + if (summary.needReboot() > 0) + logger.log(summary.rebooting() + "/" + summary.needReboot() + " nodes rebooting"); + if (summary.needRestart() > 0) + logger.log(summary.restarting() + "/" + summary.needRestart() + " nodes restarting"); + if (summary.retiring() > 0) + logger.log(summary.retiring() + " nodes retiring"); + if (summary.upgradingFirmware() > 0) + logger.log(summary.upgradingFirmware() + " nodes upgrading firmware"); + if (summary.upgradingOs() > 0) + logger.log(summary.upgradingOs() + " nodes upgrading OS"); + if (summary.needNewConfig() > 0) + logger.log(summary.needNewConfig() + " application services upgrading"); + } if (summary.converged()) { controller.jobController().locked(id, lockedRun -> lockedRun.withSummary(null)); if (endpointsAvailable(id.application(), id.type().zone(controller.system()), logger)) { @@ -398,10 +416,10 @@ public class InternalStepRunner implements StepRunner { } if ( ! firstTick) - logger.log(nodeList.expectedDown().and(nodeList.needsNewConfig()).asList().stream() - .distinct() - .flatMap(node -> nodeDetails(node, false)) - .collect(toList())); + logger.log(FINE, nodeList.expectedDown().and(nodeList.needsNewConfig()).asList().stream() + .distinct() + .flatMap(node -> nodeDetails(node, false)) + .collect(toList())); controller.jobController().locked(id, lockedRun -> { Instant noNodesDownSince = nodeList.allowedDown().size() == 0 ? lockedRun.noNodesDownSince().orElse(controller.clock().instant()) : null; @@ -1005,7 +1023,11 @@ public class InternalStepRunner implements StepRunner { } private void log(String... messages) { - log(List.of(messages)); + log(INFO, List.of(messages)); + } + + private void log(Level level, String... messages) { + log(level, List.of(messages)); } private void logAll(List messages) { @@ -1013,7 +1035,11 @@ public class InternalStepRunner implements StepRunner { } private void log(List messages) { - controller.jobController().log(id, step, INFO, messages); + log(INFO, messages); + } + + private void log(Level level, List messages) { + controller.jobController().log(id, step, level, messages); } private void log(Level level, String message) { diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelperTest.java b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelperTest.java index 2ae755ac8fe..4935ab22586 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelperTest.java +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelperTest.java @@ -192,7 +192,7 @@ public class JobControllerApiHandlerHelperTest { private void compare(HttpResponse response, String expected) throws IOException { ByteArrayOutputStream baos = new ByteArrayOutputStream(); response.render(baos); - JsonTestHelper.assertJsonEquals(expected, baos.toString()); + JsonTestHelper.assertJsonEquals(baos.toString(), expected); } private void assertResponse(HttpResponse response, String fileName) { diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/staging-test-log.json b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/staging-test-log.json index 0525f059dd0..6b1d48f4a08 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/staging-test-log.json +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/staging-test-log.json @@ -117,16 +117,26 @@ { "at": 14503000, "type": "info", - "message": "host-tenant:application:default-staging.us-east-3: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 14503000, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 14503000, + "type": "debug", + "message": "host-tenant:application:default-staging.us-east-3: unorchestrated" + }, + { + "at": 14503000, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 14503000, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { @@ -150,7 +160,7 @@ } ] }, - "lastId": 27, + "lastId": 29, "steps": { "deployTester": { "status": "succeeded", diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-details.json b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-details.json index 7ee3952a8b5..065ca3c1020 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-details.json +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-details.json @@ -137,91 +137,151 @@ { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": "(ignore)", "type": "info", - "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": "(ignore)", "type": "info", + "message": "1 application services upgrading" + }, + { + "at": "(ignore)", + "type": "debug", + "message": "host-tenant1:application1:instance1-test.us-east-1: unorchestrated" + }, + { + "at": "(ignore)", + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": "(ignore)", - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { @@ -294,7 +354,7 @@ } ] }, - "lastId": 54, + "lastId": 66, "steps": { "deployTester": { "status": "succeeded", diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-log.json b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-log.json index 6c6092cbd88..66173ec4976 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-log.json +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/restapi/application/responses/system-test-log.json @@ -132,91 +132,151 @@ { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { "at": 0, "type": "info", - "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + "message": "Waiting for convergence of 1 services across 1 nodes" }, { "at": 0, "type": "info", + "message": "1 application services upgrading" + }, + { + "at": 0, + "type": "debug", + "message": "host-tenant:application:default-test.us-east-1: unorchestrated" + }, + { + "at": 0, + "type": "debug", "message": "--- platform vespa/vespa:6.1" }, { "at": 0, - "type": "info", + "type": "debug", "message": "--- container on port 43 has config generation 1, wanted is 2" }, { @@ -289,7 +349,7 @@ } ] }, - "lastId": 54, + "lastId": 66, "steps": { "deployTester": { "status": "succeeded", -- cgit v1.2.3 From 3ad4066d51c24a19f1b8e31ff095d2652f4765a3 Mon Sep 17 00:00:00 2001 From: Jon Marius Venstad Date: Wed, 2 Feb 2022 15:34:16 +0100 Subject: Improve wording --- .../yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java index 0137d2eedeb..88e9e56ad8d 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunner.java @@ -280,7 +280,7 @@ public class InternalStepRunner implements StepRunner { switch (e.type()) { case CERT_NOT_AVAILABLE: // Same as CERTIFICATE_NOT_READY above, only from the controller - logger.log("Waiting for certificate to become valid: new application, or old one has expired"); + logger.log("Waiting for certificate to become valid: new application, or old certificate has expired"); if (startTime.plus(timeouts.endpointCertificate()).isBefore(controller.clock().instant())) { logger.log(WARNING, "Controller could not validate certificate within " + timeouts.endpointCertificate() + ": " + Exceptions.toMessageString(e)); -- cgit v1.2.3