Merge pull request #18526 from vespa-engine/jonmv/retry-no-logs-found

Retry logs ont found for 3 minutes

4 files changed, 42 insertions, 10 deletions

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 a1566a1b5a1..cc29ed5b840 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
@@ -89,6 +89,7 @@ import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.installatio
 import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.outOfCapacity;
 import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.running;
 import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.testFailure;
+import static com.yahoo.vespa.hosted.controller.deployment.Step.copyVespaLogs;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.deactivateReal;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.deactivateTester;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.deployInitialReal;
@@ -636,6 +637,19 @@ public class InternalStepRunner implements StepRunner {
             try {
                 controller.jobController().updateVespaLog(id);
             }
+            // Hitting a config server which doesn't have this particular app loaded causes a 404.
+            catch (ConfigServerException e) {
+                Instant doom = controller.jobController().run(id).get().stepInfo(copyVespaLogs).get().startTime().get()
+                                         .plus(Duration.ofMinutes(3));
+                if (e.code() == ConfigServerException.ErrorCode.NOT_FOUND && controller.clock().instant().isBefore(doom)) {
+                    logger.log(INFO, "Found no logs, but will retry");
+                    return Optional.empty();
+                }
+                else {
+                    logger.log(INFO, "Failure getting vespa logs for " + id, e);
+                    return Optional.of(error);
+                }
+            }
             catch (Exception e) {
                 logger.log(INFO, "Failure getting vespa logs for " + id, e);
                 return Optional.of(error);
diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunnerTest.java b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunnerTest.java
index 14244d7bdda..2819d9970b7 100644
--- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunnerTest.java
+++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/deployment/InternalStepRunnerTest.java
@@ -54,6 +54,7 @@ import static com.yahoo.vespa.hosted.controller.deployment.DeploymentContext.app
 import static com.yahoo.vespa.hosted.controller.deployment.DeploymentTester.instanceId;
 import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.deploymentFailed;
 import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.installationFailed;
+import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.running;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.Status.failed;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.Status.succeeded;
 import static com.yahoo.vespa.hosted.controller.deployment.Step.Status.unfinished;
@@ -383,23 +384,39 @@ public class InternalStepRunnerTest {
 
     @Test
     public void vespaLogIsCopied() {
+        // Tests fail. We should get logs. This fails too, on the first attempt.
         RunId id = app.startSystemTestTests();
         tester.cloud().set(TesterCloud.Status.ERROR);
-        tester.configServer().setLogStream(vespaLog);
+        tester.configServer().setLogStream(() -> { throw new ConfigServerException(ConfigServerException.ErrorCode.NOT_FOUND, "404", "context"); });
         long lastId = tester.jobs().details(id).get().lastId().getAsLong();
         tester.runner().run();
         assertEquals(failed, tester.jobs().run(id).get().stepStatuses().get(Step.endTests));
+        assertEquals(unfinished, tester.jobs().run(id).get().stepStatuses().get(Step.copyVespaLogs));
         assertTestLogEntries(id, Step.copyVespaLogs,
-                             new LogEntry(lastId + 2, Instant.EPOCH.plus(3554970337935104L, ChronoUnit.MICROS), info,
+                             new LogEntry(lastId + 2, tester.clock().instant(), info,
+                                          "Found no logs, but will retry"),
+                             new LogEntry(lastId + 4, tester.clock().instant(), info,
+                                          "Found no logs, but will retry"));
+
+        // Config servers now provide the log, and we get it.
+        tester.configServer().setLogStream(() -> vespaLog);
+        tester.runner().run();
+        assertEquals(failed, tester.jobs().run(id).get().stepStatuses().get(Step.endTests));
+        assertTestLogEntries(id, Step.copyVespaLogs,
+                             new LogEntry(lastId + 2, tester.clock().instant(), info,
+                                          "Found no logs, but will retry"),
+                             new LogEntry(lastId + 4, tester.clock().instant(), info,
+                                          "Found no logs, but will retry"),
+                             new LogEntry(lastId + 5, Instant.EPOCH.plus(3554970337935104L, ChronoUnit.MICROS), info,
                                           "17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\tcontainer\tstdout\n" +
                                           "ERROR: Bundle canary-application [71] Unable to get module class path. (java.lang.NullPointerException)"),
-                             new LogEntry(lastId + 3, Instant.EPOCH.plus(3554970337947777L, ChronoUnit.MICROS), info,
+                             new LogEntry(lastId + 6, Instant.EPOCH.plus(3554970337947777L, ChronoUnit.MICROS), info,
                                           "17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\tcontainer\tstdout\n" +
                                           "ERROR: Bundle canary-application [71] Unable to get module class path. (java.lang.NullPointerException)"),
-                             new LogEntry(lastId + 4, Instant.EPOCH.plus(3554970337947820L, ChronoUnit.MICROS), info,
+                             new LogEntry(lastId + 7, Instant.EPOCH.plus(3554970337947820L, ChronoUnit.MICROS), info,
                                           "17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\tcontainer\tstdout\n" +
                                           "ERROR: Bundle canary-application [71] Unable to get module class path. (java.lang.NullPointerException)"),
-                             new LogEntry(lastId + 5, Instant.EPOCH.plus(3554970337947845L, ChronoUnit.MICROS), warning,
+                             new LogEntry(lastId + 8, Instant.EPOCH.plus(3554970337947845L, ChronoUnit.MICROS), warning,
                                           "17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\tcontainer\tstderr\n" +
                                           "java.lang.NullPointerException\n\tat org.apache.felix.framework.BundleRevisionImpl.calculateContentPath(BundleRevisionImpl.java:438)\n\tat org.apache.felix.framework.BundleRevisionImpl.initializeContentPath(BundleRevisionImpl.java:371)"));
     }
diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/integration/ConfigServerMock.java b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/integration/ConfigServerMock.java
index dca79c43afe..fbe591a6433 100644
--- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/integration/ConfigServerMock.java
+++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/integration/ConfigServerMock.java
@@ -63,6 +63,7 @@ import java.util.Map;
 import java.util.Optional;
 import java.util.Set;
 import java.util.UUID;
+import java.util.function.Supplier;
 import java.util.logging.Level;
 import java.util.stream.Collectors;
 
@@ -95,7 +96,7 @@ public class ConfigServerMock extends AbstractComponent implements ConfigServer
     private Version lastPrepareVersion = null;
     private RuntimeException prepareException = null;
     private ConfigChangeActions configChangeActions = null;
-    private String log = "INFO - All good";
+    private Supplier<String> log = () -> "INFO - All good";
 
     @Inject
     public ConfigServerMock(ZoneRegistryMock zoneRegistry) {
@@ -554,7 +555,7 @@ public class ConfigServerMock extends AbstractComponent implements ConfigServer
 
     @Override
     public InputStream getLogs(DeploymentId deployment, Map<String, String> queryParameters) {
-        return new ByteArrayInputStream(log.getBytes(StandardCharsets.UTF_8));
+        return new ByteArrayInputStream(log.get().getBytes(StandardCharsets.UTF_8));
     }
 
     @Override
@@ -562,7 +563,7 @@ public class ConfigServerMock extends AbstractComponent implements ConfigServer
         return new ProxyResponse("{\"path\":\"" + path + "\"}", "application/json", 200);
     }
 
-    public void setLogStream(String log) {
+    public void setLogStream(Supplier<String> log) {
         this.log = log;
     }
 
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 1be7f16e85f..73fda6ffcc0 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
@@ -151,10 +151,10 @@ public class JobControllerApiHandlerHelperTest {
 
         ZoneId zone = JobType.devUsEast1.zone(tester.controller().system());
         tester.jobs().deploy(app.instanceId(), JobType.devUsEast1, Optional.empty(), applicationPackage());
-        tester.configServer().setLogStream("1554970337.935104\t17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\t5480\tcontainer\tstdout\tinfo\tERROR: Bundle canary-application [71] Unable to get module class path. (java.lang.NullPointerException)\n");
+        tester.configServer().setLogStream(() -> "1554970337.935104\t17491290-v6-1.ostk.bm2.prod.ne1.yahoo.com\t5480\tcontainer\tstdout\tinfo\tERROR: Bundle canary-application [71] Unable to get module class path. (java.lang.NullPointerException)\n");
         assertResponse(JobControllerApiHandlerHelper.runDetailsResponse(tester.jobs(), tester.jobs().last(app.instanceId(), devUsEast1).get().id(), null), "dev-us-east-1-log-first-part.json");
 
-        tester.configServer().setLogStream("Nope, this won't be logged");
+        tester.configServer().setLogStream(() -> "Nope, this won't be logged");
         tester.configServer().convergeServices(app.instanceId(), zone);
         tester.runner().run();