diff options
author | Jon Marius Venstad <jvenstad@yahoo-inc.com> | 2018-08-23 11:05:46 +0200 |
---|---|---|
committer | Jon Marius Venstad <jvenstad@yahoo-inc.com> | 2018-08-23 11:09:08 +0200 |
commit | 366fb4304f150b2aec83ab7fa5a673f3876696d3 (patch) | |
tree | e3e064381fcd6c018510f6644bbd3380a72a293d /controller-server | |
parent | c1230b52de0f86705a606d9aeae9cd4be510bbaa (diff) |
Replaced LogRecord LogEntry, and use a chunked Curator buffer for logs
Diffstat (limited to 'controller-server')
16 files changed, 494 insertions, 192 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 ead9388fc3b..799077028e0 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 @@ -27,19 +27,14 @@ import com.yahoo.vespa.hosted.controller.application.ApplicationVersion; import com.yahoo.vespa.hosted.controller.application.DeploymentJobs; import com.yahoo.yolean.Exceptions; -import java.io.ByteArrayOutputStream; import java.io.IOException; -import java.io.PrintStream; import java.io.UncheckedIOException; import java.net.URI; -import java.text.SimpleDateFormat; import java.time.Duration; -import java.util.Date; import java.util.List; import java.util.Map; import java.util.NoSuchElementException; import java.util.Optional; -import java.util.TimeZone; import java.util.function.Supplier; import java.util.logging.Level; import java.util.logging.LogRecord; @@ -51,7 +46,6 @@ import static com.yahoo.vespa.hosted.controller.api.integration.configserver.Con import static com.yahoo.vespa.hosted.controller.api.integration.configserver.ConfigServerException.ErrorCode.APPLICATION_LOCK_FAILURE; import static com.yahoo.vespa.hosted.controller.api.integration.configserver.ConfigServerException.ErrorCode.OUT_OF_CAPACITY; import static com.yahoo.vespa.hosted.controller.api.integration.configserver.Node.State.active; -import static com.yahoo.vespa.hosted.controller.api.integration.configserver.Node.State.failed; import static com.yahoo.vespa.hosted.controller.api.integration.configserver.Node.State.reserved; import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.deploymentFailed; import static com.yahoo.vespa.hosted.controller.deployment.RunStatus.error; @@ -73,6 +67,8 @@ import static java.util.logging.Level.WARNING; */ public class InternalStepRunner implements StepRunner { + private static final Logger logger = Logger.getLogger(InternalStepRunner.class.getName()); + static final Duration endpointTimeout = Duration.ofMinutes(15); static final Duration installationTimeout = Duration.ofMinutes(150); @@ -93,7 +89,7 @@ public class InternalStepRunner implements StepRunner { @Override public Optional<RunStatus> run(LockedStep step, RunId id) { - ByteArrayLogger logger = ByteArrayLogger.of(id.application(), id.type(), step.get()); + DualLogger logger = new DualLogger(id, step.get()); try { switch (step.get()) { case deployInitialReal: return deployInitialReal(id, logger); @@ -122,12 +118,9 @@ public class InternalStepRunner implements StepRunner { } return Optional.of(error); } - finally { - controller.jobController().log(id, step.get(), logger.getLog()); - } } - private Optional<RunStatus> deployInitialReal(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> deployInitialReal(RunId id, DualLogger logger) { Versions versions = controller.jobController().run(id).get().versions(); logger.log("Deploying platform version " + versions.sourcePlatform().orElse(versions.targetPlatform()) + @@ -136,14 +129,14 @@ public class InternalStepRunner implements StepRunner { return deployReal(id, true, logger); } - private Optional<RunStatus> deployReal(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> deployReal(RunId id, DualLogger logger) { Versions versions = controller.jobController().run(id).get().versions(); logger.log("Deploying platform version " + versions.targetPlatform() + " and application version " + versions.targetApplication().id() + " ..."); return deployReal(id, false, logger); } - private Optional<RunStatus> deployReal(RunId id, boolean setTheStage, ByteArrayLogger logger) { + private Optional<RunStatus> deployReal(RunId id, boolean setTheStage, DualLogger logger) { return deploy(id.application(), id.type(), () -> controller.applications().deploy(id.application(), @@ -156,7 +149,7 @@ public class InternalStepRunner implements StepRunner { logger); } - private Optional<RunStatus> deployTester(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> deployTester(RunId id, DualLogger logger) { // TODO jvenstad: Consider deploying old version of tester for initial staging feeding? logger.log("Deploying the tester container ..."); return deploy(testerOf(id.application()), @@ -171,7 +164,7 @@ public class InternalStepRunner implements StepRunner { logger); } - private Optional<RunStatus> deploy(ApplicationId id, JobType type, Supplier<ActivateResult> deployment, ByteArrayLogger logger) { + private Optional<RunStatus> deploy(ApplicationId id, JobType type, Supplier<ActivateResult> deployment, DualLogger logger) { try { PrepareResponse prepareResponse = deployment.get().prepareResponse(); if ( ! prepareResponse.configChangeActions.refeedActions.stream().allMatch(action -> action.allowed)) { @@ -219,15 +212,15 @@ public class InternalStepRunner implements StepRunner { } } - private Optional<RunStatus> installInitialReal(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> installInitialReal(RunId id, DualLogger logger) { return installReal(id, true, logger); } - private Optional<RunStatus> installReal(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> installReal(RunId id, DualLogger logger) { return installReal(id, false, logger); } - private Optional<RunStatus> installReal(RunId id, boolean setTheStage, ByteArrayLogger logger) { + private Optional<RunStatus> installReal(RunId id, boolean setTheStage, DualLogger logger) { if (expired(id.application(), id.type())) { logger.log(INFO, "Deployment expired before installation was successful."); return Optional.of(installationFailed); @@ -252,7 +245,7 @@ public class InternalStepRunner implements StepRunner { return Optional.empty(); } - private Optional<RunStatus> installTester(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> installTester(RunId id, DualLogger logger) { logger.log("Checking installation of tester container ..."); if (expired(id.application(), id.type())) { logger.log(INFO, "Deployment expired before tester was installed."); @@ -273,7 +266,7 @@ public class InternalStepRunner implements StepRunner { return Optional.empty(); } - private boolean nodesConverged(ApplicationId id, JobType type, Version target, ByteArrayLogger logger) { + private boolean nodesConverged(ApplicationId id, JobType type, Version target, DualLogger logger) { List<Node> nodes = controller.configServer().nodeRepository().list(type.zone(controller.system()), id, ImmutableSet.of(active, reserved)); for (Node node : nodes) logger.log(String.format("%70s: %-16s%-25s%-32s%s", @@ -297,7 +290,7 @@ public class InternalStepRunner implements StepRunner { .orElse(false); } - private Optional<RunStatus> startTests(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> startTests(RunId id, DualLogger logger) { logger.log("Attempting to find endpoints ..."); if (expired(id.application(), id.type())) { logger.log(INFO, "Deployment expired before tests could start."); @@ -340,7 +333,7 @@ public class InternalStepRunner implements StepRunner { return Optional.empty(); } - private Optional<RunStatus> endTests(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> endTests(RunId id, DualLogger logger) { URI testerEndpoint = testerEndpoint(id) .orElseThrow(() -> new NoSuchElementException("Endpoint for tester vanished again before tests were complete!")); @@ -366,13 +359,13 @@ public class InternalStepRunner implements StepRunner { return Optional.of(status); } - private Optional<RunStatus> deactivateReal(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> deactivateReal(RunId id, DualLogger logger) { logger.log("Deactivating deployment of " + id.application() + " in " + id.type().zone(controller.system()) + " ..."); controller.applications().deactivate(id.application(), id.type().zone(controller.system())); return Optional.of(running); } - private Optional<RunStatus> deactivateTester(RunId id, ByteArrayLogger logger) { + private Optional<RunStatus> deactivateTester(RunId id, DualLogger logger) { logger.log("Deactivating tester of " + id.application() + " in " + id.type().zone(controller.system()) + " ..."); controller.jobController().deactivateTester(id.application(), id.type()); return Optional.of(running); @@ -516,53 +509,32 @@ public class InternalStepRunner implements StepRunner { } } - /** Logger which logs all records to a private byte array, as well as to its parent. */ - static class ByteArrayLogger extends Logger { - - private static final Logger parent = Logger.getLogger(InternalStepRunner.class.getName()); - private static final SimpleDateFormat timestampFormat = new SimpleDateFormat("[HH:mm:ss.SSS] "); - static { timestampFormat.setTimeZone(TimeZone.getTimeZone("UTC")); } - - private final ByteArrayOutputStream bytes; - private final PrintStream out; + /** Logger which logs to a {@link JobController}, as well as to the parent class' {@link Logger}. */ + private class DualLogger { - private ByteArrayLogger(Logger parent, String suffix) { - super(parent.getName() + suffix, null); - setParent(parent); - - bytes = new ByteArrayOutputStream(); - out = new PrintStream(bytes); - } - - static ByteArrayLogger of(ApplicationId id, JobType type, Step step) { - return new ByteArrayLogger(parent, String.format(".%s.%s.%s", id.toString(), type.jobName(), step)); - } + private final RunId id; + private final Step step; + private final String prefix; - @Override - public void log(LogRecord record) { - // TODO jvenstad: Store log records in a serialised format. - String timestamp = timestampFormat.format(new Date(record.getMillis())); - for (String line : record.getMessage().split("\n")) - out.println(timestamp + ": " + line); - if (record.getThrown() != null) - record.getThrown().printStackTrace(out); - - record.setSourceClassName(null); // Makes the root logger's ConsoleHandler use the logger name instead, when printing. - getParent().log(record); + private DualLogger(RunId id, Step step) { + this.id = id; + this.step = step; + this.prefix = step + " of " + id; } - public void log(String message) { + private void log(String message) { log(DEBUG, message); } - @Override - public boolean isLoggable(Level __) { - return true; + private void log(Level level, String message) { + log(level, message, null); } - public byte[] getLog() { - out.flush(); - return bytes.toByteArray(); + private void log(Level level, String message, Throwable thrown) { + LogRecord record = new LogRecord(level, message); + record.setThrown(thrown); + logger.log(record); + controller.jobController().log(id, step, record); } } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/JobController.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/JobController.java index 6063b99178a..6c95c4ed8cd 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/JobController.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/JobController.java @@ -16,23 +16,27 @@ import com.yahoo.vespa.hosted.controller.application.Deployment; import com.yahoo.vespa.hosted.controller.application.DeploymentJobs; import com.yahoo.vespa.hosted.controller.application.JobStatus; import com.yahoo.vespa.hosted.controller.application.SourceRevision; +import com.yahoo.vespa.hosted.controller.persistence.BufferedLogStore; import com.yahoo.vespa.hosted.controller.persistence.CuratorDb; -import java.util.HashMap; +import java.util.Collections; import java.util.HashSet; import java.util.List; import java.util.Map; +import java.util.NoSuchElementException; import java.util.Optional; import java.util.Set; import java.util.concurrent.TimeoutException; import java.util.concurrent.atomic.AtomicReference; import java.util.function.Consumer; import java.util.function.UnaryOperator; +import java.util.logging.LogRecord; import java.util.stream.Stream; import static com.google.common.collect.ImmutableList.copyOf; import static com.yahoo.vespa.hosted.controller.deployment.Step.deactivateTester; import static com.yahoo.vespa.hosted.controller.deployment.InternalStepRunner.testerOf; +import static com.yahoo.vespa.hosted.controller.deployment.Step.endTests; /** * A singleton owned by the controller, which contains the state and methods for controlling deployment jobs. @@ -51,12 +55,12 @@ public class JobController { private final Controller controller; private final CuratorDb curator; - private final RunDataStore logs; + private final BufferedLogStore logs; public JobController(Controller controller, RunDataStore runDataStore) { this.controller = controller; this.curator = controller.curator(); - this.logs = runDataStore; + this.logs = new BufferedLogStore(curator, runDataStore); } @@ -70,28 +74,44 @@ public class JobController { } } - /** Returns the details currently logged for the given run, if known. */ - public Optional<RunDetails> details(RunId id) { - Run run = runs(id.application(), id.type()).get(id); - if (run == null) - return Optional.empty(); - - Map<Step, byte[]> details = new HashMap<>(); - for (Step step : run.steps().keySet()) { - byte[] log = logs.get(id, step.name()); - if (log.length > 0) - details.put(step, log); - } - return Optional.of(new RunDetails(details)); + /** Returns all entries currently logged for the given run. */ + public Optional<RunLog> details(RunId id) { + return details(id, -1); } - /** Appends the given log bytes to the currently stored bytes for the given run and step. */ - public void log(RunId id, Step step, byte[] log) { + /** Returns the logged entries for the given run, which are after the given id threshold. */ + public Optional<RunLog> details(RunId id, long after) { try (Lock __ = curator.lock(id.application(), id.type())) { - logs.append(id, step.name(), log); + Run run = runs(id.application(), id.type()).get(id); + if (run == null) + return Optional.empty(); + + return active(id).isPresent() + ? Optional.of(logs.readActive(id.application(), id.type(), after)) + : logs.readFinished(id, after); } } + /** Stores the given log record for the given run and step. */ + public void log(RunId id, Step step, LogRecord record) { + locked(id, __ -> { + logs.append(id.application(), id.type(), step, Collections.singletonList(LogEntry.of(record))); + return __; + }); + } + + /** Stores the given test log records, and records the id of the last of these, for continuation. */ + public void logTestRecords(RunId id, List<LogEntry> entries) { + if (entries.isEmpty()) + return; + + locked(id, run -> { + long lastTestRecord = entries.stream().mapToLong(LogEntry::id).max().getAsLong(); + logs.append(id.application(), id.type(), endTests, entries); + return run.with(lastTestRecord); + }); + } + /** Returns a list of all application which have registered. */ public List<ApplicationId> applications() { return copyOf(controller.applications().asList().stream() @@ -153,6 +173,7 @@ public class JobController { locked(id, run -> { // Store the modified run after it has been written to the collection, in case the latter fails. Run finishedRun = run.finished(controller.clock().instant()); locked(id.application(), id.type(), runs -> runs.put(run.id(), finishedRun)); + logs.flush(id); return finishedRun; }); } @@ -238,14 +259,15 @@ public class JobController { locked(id, type, deactivateTester, __ -> { try (Lock ___ = curator.lock(id, type)) { deactivateTester(id, type); - curator.deleteJobData(id, type); + curator.deleteRunData(id, type); + logs.delete(id); } }); } catch (TimeoutException e) { return; // Don't remove the data if we couldn't deactivate all testers. } - curator.deleteJobData(id); + curator.deleteRunData(id); }); } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/LogEntry.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/LogEntry.java index e224a9c277a..fed5a9b84b1 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/LogEntry.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/LogEntry.java @@ -2,6 +2,7 @@ package com.yahoo.vespa.hosted.controller.deployment; import com.yahoo.log.LogLevel; +import java.util.Objects; import java.util.logging.Level; import java.util.logging.LogRecord; @@ -45,4 +46,30 @@ public class LogEntry { return message; } + @Override + public String toString() { + return "LogEntry{" + + "id=" + id + + ", at=" + at + + ", level=" + level + + ", message='" + message + '\'' + + '}'; + } + + @Override + public boolean equals(Object o) { + if (this == o) return true; + if (!(o instanceof LogEntry)) return false; + LogEntry entry = (LogEntry) o; + return id == entry.id && + at == entry.at && + Objects.equals(level, entry.level) && + Objects.equals(message, entry.message); + } + + @Override + public int hashCode() { + return Objects.hash(id, at, level, message); + } + } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/Run.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/Run.java index 70670430bf4..9f70792fc53 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/Run.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/Run.java @@ -78,6 +78,13 @@ public class Run { return new Run(id, new EnumMap<>(steps), versions, start, end, aborted, lastTestRecord); } + public Run with(long lastTestRecord) { + if (hasEnded()) + throw new AssertionError("This run ended at " + end.get() + " -- it can't be further modified!"); + + return new Run(id, new EnumMap<>(steps), versions, start, end, status, lastTestRecord); + } + /** Returns the id of this run. */ public RunId id() { return id; diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/RunLog.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/RunLog.java index 615d6e444da..9b9a32c6e65 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/RunLog.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/deployment/RunLog.java @@ -10,35 +10,35 @@ import java.util.Optional; import java.util.OptionalLong; /** - * Immutable class which contains details about a deployment job run. + * Immutable class which contains the log of a deployment job run. * * @author jonmv */ -public class RunDetails { +public class RunLog { - private static final RunDetails empty = RunDetails.of(Collections.emptyMap()); + private static final RunLog empty = RunLog.of(Collections.emptyMap()); private final Map<Step, List<LogEntry>> log; private final OptionalLong lastId; - private RunDetails(OptionalLong lastId, Map<Step, List<LogEntry>> log) { + private RunLog(OptionalLong lastId, Map<Step, List<LogEntry>> log) { this.log = log; this.lastId = lastId; } - /** Creates a RunDetails which contains a deep copy of the given logs. */ - public static RunDetails of(Map<Step, List<LogEntry>> logs) { + /** Creates a RunLog which contains a deep copy of the given log. */ + public static RunLog of(Map<Step, List<LogEntry>> log) { ImmutableMap.Builder<Step, List<LogEntry>> builder = ImmutableMap.builder(); - logs.forEach((step, entries) -> builder.put(step, ImmutableList.copyOf(entries))); - OptionalLong lastId = logs.values().stream() - .flatMap(List::stream) - .mapToLong(LogEntry::id) - .max(); - return new RunDetails(lastId, builder.build()); + log.forEach((step, entries) -> builder.put(step, ImmutableList.copyOf(entries))); + OptionalLong lastId = log.values().stream() + .flatMap(List::stream) + .mapToLong(LogEntry::id) + .max(); + return new RunLog(lastId, builder.build()); } - /** Returns an empty RunDetails. */ - public static RunDetails empty() { + /** Returns an empty RunLog. */ + public static RunLog empty() { return empty; } @@ -47,7 +47,7 @@ public class RunDetails { return Optional.ofNullable(log.get(step)); } - /** Returns the id of the last log entry in this. */ + /** Returns the id of the last log entry in this, if it has any. */ public OptionalLong lastId() { return lastId; } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStore.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStore.java index f87cfef373c..b70c1283862 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStore.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStore.java @@ -1,5 +1,99 @@ package com.yahoo.vespa.hosted.controller.persistence; -public class BufferingLogStore { +import com.yahoo.config.provision.ApplicationId; +import com.yahoo.vespa.hosted.controller.api.integration.RunDataStore; +import com.yahoo.vespa.hosted.controller.api.integration.deployment.JobType; +import com.yahoo.vespa.hosted.controller.api.integration.deployment.RunId; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; +import com.yahoo.vespa.hosted.controller.deployment.RunLog; +import com.yahoo.vespa.hosted.controller.deployment.Step; + +import java.util.ArrayList; +import java.util.Arrays; +import java.util.List; +import java.util.Map; +import java.util.Optional; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.stream.Collectors; +import java.util.stream.LongStream; + +/** + * Stores logs in bite-sized chunks using a {@link CuratorDb}, and flushes to a + * {@link com.yahoo.vespa.hosted.controller.api.integration.RunDataStore} when the log is final. + * + * @author jonmv + */ +public class BufferedLogStore { + + static final int chunkSize = 1 << 17; + + private final CuratorDb buffer; + private final RunDataStore store; + private final LogSerializer logSerializer = new LogSerializer(); + + public BufferedLogStore(CuratorDb buffer, RunDataStore store) { + this.buffer = buffer; + this.store = store; + } + + /** Appends to the log of the given, active run, reassigning IDs as counted here, and converting to Vespa log levels. */ + public void append(ApplicationId id, JobType type, Step step, List<LogEntry> entries) { + if (entries.isEmpty()) + return; + + // Start a new chunk if the previous one is full, or if none have been written yet. + // The id of a chunk is the id of the first entry in it. + long lastEntryId = buffer.readLastLogEntryId(id, type).orElse(-1L); + long lastChunkId = buffer.getLogChunkIds(id, type).max().orElse(0); + byte[] emptyChunk = "[]".getBytes(); + byte[] lastChunk = buffer.readLog(id, type, lastChunkId).orElse(emptyChunk); + if (lastChunk.length > chunkSize) { + lastChunkId = lastEntryId + 1; + lastChunk = emptyChunk; + } + Map<Step, List<LogEntry>> log = logSerializer.fromJson(lastChunk, -1); + List<LogEntry> stepEntries = log.computeIfAbsent(step, __ -> new ArrayList<>()); + for (LogEntry entry : entries) + stepEntries.add(new LogEntry(++lastEntryId, entry.at(), entry.level(), entry.message())); + + buffer.writeLog(id, type, lastChunkId, logSerializer.toJson(log)); + buffer.writeLastLogEntryId(id, type, lastEntryId); + } + + /** Reads all log entries after the given threshold, from the buffered log, i.e., for an active run. */ + public RunLog readActive(ApplicationId id, JobType type, long after) { + return buffer.readLastLogEntryId(id, type).orElse(-1L) <= after + ? RunLog.empty() + : RunLog.of(readChunked(id, type, after)); + } + + /** Reads all log entries after the given threshold, from the stored log, i.e., for a finished run. */ + public Optional<RunLog> readFinished(RunId id, long after) { + return store.get(id).map(json -> RunLog.of(logSerializer.fromJson(json, after))); + } + + /** Writes the buffered log of the now finished run to the long-term store, and clears the buffer. */ + public void flush(RunId id) { + store.put(id, logSerializer.toJson(readChunked(id.application(), id.type(), -1))); + buffer.deleteLog(id.application(), id.type()); + } + + /** Deletes all logs for the given application. */ + public void delete(ApplicationId id) { + for (JobType type : JobType.values()) + buffer.deleteLog(id, type); + store.delete(id); + } + + private Map<Step, List<LogEntry>> readChunked(ApplicationId id, JobType type, long after) { + long[] chunkIds = buffer.getLogChunkIds(id, type).toArray(); + int firstChunk = chunkIds.length; + while (firstChunk > 0 && chunkIds[--firstChunk] > after + 1); + return logSerializer.fromJson(Arrays.stream(chunkIds, firstChunk, chunkIds.length) + .mapToObj(chunkId -> buffer.readLog(id, type, chunkId)) + .filter(Optional::isPresent).map(Optional::get) + .collect(Collectors.toList()), + after); + } } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/CuratorDb.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/CuratorDb.java index 2ed69ad9be8..cf244c38565 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/CuratorDb.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/CuratorDb.java @@ -45,6 +45,12 @@ import java.util.function.Predicate; import java.util.logging.Level; import java.util.logging.Logger; import java.util.stream.Collectors; +import java.util.stream.LongStream; + +import static java.util.stream.Collectors.collectingAndThen; +import static java.util.stream.Collectors.groupingBy; +import static java.util.stream.Collectors.reducing; +import static java.util.stream.Collectors.toMap; /** * Curator backed database for storing the persistence state of controllers. This maps controller specific operations @@ -52,6 +58,7 @@ import java.util.stream.Collectors; * * @author bratseth * @author mpolden + * @author jonmv */ public class CuratorDb { @@ -296,7 +303,7 @@ public class CuratorDb { .map(this::readTenant) .filter(Optional::isPresent) .map(Optional::get) - .collect(Collectors.collectingAndThen(Collectors.toList(), Collections::unmodifiableList)); + .collect(collectingAndThen(Collectors.toList(), Collections::unmodifiableList)); } public void removeTenant(TenantName name) { @@ -328,7 +335,7 @@ public class CuratorDb { .map(this::readApplication) .filter(Optional::isPresent) .map(Optional::get) - .collect(Collectors.collectingAndThen(Collectors.toList(), Collections::unmodifiableList)); + .collect(collectingAndThen(Collectors.toList(), Collections::unmodifiableList)); } public void removeApplication(ApplicationId application) { @@ -342,7 +349,7 @@ public class CuratorDb { } public void writeHistoricRuns(ApplicationId id, JobType type, Iterable<Run> runs) { - curator.set(jobPath(id, type), asJson(runSerializer.toSlime(runs))); + curator.set(runsPath(id, type), asJson(runSerializer.toSlime(runs))); } public Optional<Run> readLastRun(ApplicationId id, JobType type) { @@ -351,15 +358,15 @@ public class CuratorDb { public Map<RunId, Run> readHistoricRuns(ApplicationId id, JobType type) { // TODO jvenstad: Add, somewhere, a retention filter based on age or count. - return readSlime(jobPath(id, type)).map(runSerializer::runsFromSlime).orElse(new LinkedHashMap<>()); + return readSlime(runsPath(id, type)).map(runSerializer::runsFromSlime).orElse(new LinkedHashMap<>()); } - public void deleteJobData(ApplicationId id, JobType type) { - curator.delete(jobPath(id, type)); + public void deleteRunData(ApplicationId id, JobType type) { + curator.delete(runsPath(id, type)); curator.delete(lastRunPath(id, type)); } - public void deleteJobData(ApplicationId id) { + public void deleteRunData(ApplicationId id) { curator.delete(jobRoot.append(id.serializedForm())); } @@ -369,6 +376,33 @@ public class CuratorDb { .collect(Collectors.toList()); } + + public Optional<byte[]> readLog(ApplicationId id, JobType type, long chunkId) { + return curator.getData(logPath(id, type, chunkId)); + } + + public void writeLog(ApplicationId id, JobType type, long chunkId, byte[] log) { + curator.set(logPath(id, type, chunkId), log); + } + + public void deleteLog(ApplicationId id, JobType type) { + curator.delete(runsPath(id, type).append("logs")); + } + + public Optional<Long> readLastLogEntryId(ApplicationId id, JobType type) { + return curator.getData(lastLogPath(id, type)) + .map(String::new).map(Long::parseLong); + } + + public void writeLastLogEntryId(ApplicationId id, JobType type, long lastId) { + curator.set(lastLogPath(id, type), Long.toString(lastId).getBytes()); + } + + public LongStream getLogChunkIds(ApplicationId id, JobType type) { + return curator.getChildren(runsPath(id, type).append("logs")).stream() + .mapToLong(Long::parseLong); + } + // -------------- Provisioning (called by internal code) ------------------ @SuppressWarnings("unused") @@ -501,12 +535,20 @@ public class CuratorDb { return applicationRoot.append(application.serializedForm()); } - private static Path jobPath(ApplicationId id, JobType type) { + private static Path runsPath(ApplicationId id, JobType type) { return jobRoot.append(id.serializedForm()).append(type.jobName()); } private static Path lastRunPath(ApplicationId id, JobType type) { - return jobPath(id, type).append("last"); + return runsPath(id, type).append("last"); + } + + private static Path logPath(ApplicationId id, JobType type, long first) { + return runsPath(id, type).append("logs").append(Long.toString(first)); + } + + private static Path lastLogPath(ApplicationId id, JobType type) { + return runsPath(id, type).append("logs"); } private static Path controllerPath(String hostname) { diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializer.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializer.java index f582b240260..0117ae9ca40 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializer.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializer.java @@ -1,64 +1,93 @@ package com.yahoo.vespa.hosted.controller.persistence; -import com.google.common.collect.ImmutableList; -import com.google.common.collect.ImmutableMap; import com.yahoo.log.LogLevel; import com.yahoo.slime.ArrayTraverser; import com.yahoo.slime.Cursor; import com.yahoo.slime.Inspector; import com.yahoo.slime.ObjectTraverser; import com.yahoo.slime.Slime; +import com.yahoo.vespa.config.SlimeUtils; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; import com.yahoo.vespa.hosted.controller.deployment.Step; +import java.io.IOException; +import java.io.UncheckedIOException; +import java.util.ArrayList; +import java.util.Collections; +import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.logging.LogRecord; +import java.util.stream.Collectors; /** * Serialisation of LogRecord objects. Not all fields are stored! * * @author jonmv */ -class LogRecordSerializer { +class LogSerializer { private static final String idField = "id"; private static final String levelField = "level"; private static final String timestampField = "at"; private static final String messageField = "message"; - Slime recordsToSlime(Map<Step, List<LogRecord>> stepRecords) { + byte[] toJson(Map<Step, List<LogEntry>> log) { + try { + return SlimeUtils.toJsonBytes(toSlime(log)); + } + catch (IOException e) { + throw new UncheckedIOException(e); + } + } + + Slime toSlime(Map<Step, List<LogEntry>> log) { Slime root = new Slime(); - Cursor recordsObject = root.setObject(); - stepRecords.forEach((step, records) -> { - Cursor recordsArray = recordsObject.setArray(RunSerializer.valueOf(step)); - records.forEach(record -> toSlime(record, recordsArray.addObject())); + Cursor logObject = root.setObject(); + log.forEach((step, entries) -> { + Cursor recordsArray = logObject.setArray(RunSerializer.valueOf(step)); + entries.forEach(entry -> toSlime(entry, recordsArray.addObject())); }); return root; } - void toSlime(LogRecord record, Cursor recordObject) { - recordObject.setLong(idField, record.getSequenceNumber()); - recordObject.setString(levelField, LogLevel.getVespaLogLevel(record.getLevel()).getName()); - recordObject.setLong(timestampField, record.getMillis()); - recordObject.setString(messageField, record.getMessage()); + private void toSlime(LogEntry entry, Cursor entryObject) { + entryObject.setLong(idField, entry.id()); + entryObject.setLong(timestampField, entry.at()); + entryObject.setString(levelField, entry.level().getName()); + entryObject.setString(messageField, entry.message()); } - Map<Step, List<LogRecord>> recordsFromSlime(Slime slime) { - ImmutableMap.Builder<Step, List<LogRecord>> stepRecords = ImmutableMap.builder(); - slime.get().traverse((ObjectTraverser) (step, recordsArray) -> { - ImmutableList.Builder<LogRecord> records = ImmutableList.builder(); - recordsArray.traverse((ArrayTraverser) (__, recordObject) -> records.add(fromSlime(recordObject))); - stepRecords.put(RunSerializer.stepOf(step), records.build()); - }); - return stepRecords.build(); + Map<Step, List<LogEntry>> fromJson(byte[] logJson, long after) { + return fromJson(Collections.singletonList(logJson), after); + } + + Map<Step, List<LogEntry>> fromJson(List<byte[]> logJsons, long after) { + return fromSlime(logJsons.stream() + .map(SlimeUtils::jsonToSlime) + .collect(Collectors.toList()), + after); + } + + Map<Step, List<LogEntry>> fromSlime(List<Slime> slimes, long after) { + Map<Step, List<LogEntry>> log = new HashMap<>(); + slimes.forEach(slime -> slime.get().traverse((ObjectTraverser) (stepName, entryArray) -> { + Step step = RunSerializer.stepOf(stepName); + List<LogEntry> entries = log.computeIfAbsent(step, __ -> new ArrayList<>()); + entryArray.traverse((ArrayTraverser) (__, entryObject) -> { + LogEntry entry = fromSlime(entryObject); + if (entry.id() > after) + entries.add(entry); + }); + })); + return log; } - private LogRecord fromSlime(Inspector recordObject) { - LogRecord record = new LogRecord(LogLevel.parse(recordObject.field(levelField).asString()), - recordObject.field(messageField).asString()); - record.setSequenceNumber(recordObject.field(idField).asLong()); - record.setMillis(recordObject.field(timestampField).asLong()); - return record; + private LogEntry fromSlime(Inspector entryObject) { + return new LogEntry(entryObject.field(idField).asLong(), + entryObject.field(timestampField).asLong(), + LogLevel.parse(entryObject.field(levelField).asString()), + entryObject.field(messageField).asString()); } } diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/ApplicationApiHandler.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/ApplicationApiHandler.java index 3391eee4d62..25fb15b283c 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/ApplicationApiHandler.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/ApplicationApiHandler.java @@ -174,7 +174,7 @@ public class ApplicationApiHandler extends LoggingRequestHandler { if (path.matches("/application/v4/tenant/{tenant}/application/{application}")) return application(path.get("tenant"), path.get("application"), request); if (path.matches("/application/v4/tenant/{tenant}/application/{application}/instance/{instance}/job")) return JobControllerApiHandlerHelper.jobTypeResponse(jobTypes(path), latestRuns(path), request.getUri()); if (path.matches("/application/v4/tenant/{tenant}/application/{application}/instance/{instance}/job/{jobtype}")) return JobControllerApiHandlerHelper.runResponse(controller.jobController().runs(appIdFromPath(path), jobTypeFromPath(path)), request.getUri()); - if (path.matches("/application/v4/tenant/{tenant}/application/{application}/instance/{instance}/job/{jobtype}/run/{number}")) return JobControllerApiHandlerHelper.runDetailsResponse(controller.jobController(), runIdFromPath(path)); + if (path.matches("/application/v4/tenant/{tenant}/application/{application}/instance/{instance}/job/{jobtype}/run/{number}")) return JobControllerApiHandlerHelper.runDetailsResponse(controller.jobController(), runIdFromPath(path), request.getProperty("after")); if (path.matches("/application/v4/tenant/{tenant}/application/{application}/environment/{environment}/region/{region}/instance/{instance}")) return deployment(path.get("tenant"), path.get("application"), path.get("instance"), path.get("environment"), path.get("region"), request); if (path.matches("/application/v4/tenant/{tenant}/application/{application}/environment/{environment}/region/{region}/instance/{instance}/service")) return services(path.get("tenant"), path.get("application"), path.get("instance"), path.get("environment"), path.get("region"), request); if (path.matches("/application/v4/tenant/{tenant}/application/{application}/environment/{environment}/region/{region}/instance/{instance}/service/{service}/{*}")) return service(path.get("tenant"), path.get("application"), path.get("instance"), path.get("environment"), path.get("region"), path.get("service"), path.getRest(), request); diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelper.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelper.java index 1304ebf9e1c..3ed4163a503 100644 --- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelper.java +++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/restapi/application/JobControllerApiHandlerHelper.java @@ -10,7 +10,8 @@ import com.yahoo.vespa.hosted.controller.api.integration.deployment.RunId; import com.yahoo.vespa.hosted.controller.application.ApplicationVersion; import com.yahoo.vespa.hosted.controller.application.SourceRevision; import com.yahoo.vespa.hosted.controller.deployment.JobController; -import com.yahoo.vespa.hosted.controller.deployment.RunDetails; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; +import com.yahoo.vespa.hosted.controller.deployment.RunLog; import com.yahoo.vespa.hosted.controller.deployment.Run; import com.yahoo.vespa.hosted.controller.deployment.Step; import com.yahoo.vespa.hosted.controller.restapi.SlimeJsonResponse; @@ -101,21 +102,35 @@ class JobControllerApiHandlerHelper { /** * @return Response with logs from a single run */ - static HttpResponse runDetailsResponse(JobController jobController, RunId runId) { + static HttpResponse runDetailsResponse(JobController jobController, RunId runId, String after) { Slime slime = new Slime(); Cursor logsObject = slime.setObject(); - RunDetails runDetails = jobController.details(runId).orElseThrow(() -> - new NotExistsException(String.format( + logsObject.setBool("active", jobController.active(runId).isPresent()); + + RunLog runLog = (after == null ? jobController.details(runId) : jobController.details(runId, Long.parseLong(after))) + .orElseThrow(() -> new NotExistsException(String.format( "No run details exist for application: %s, job type: %s, number: %d", runId.application().toShortString(), runId.type().jobName(), runId.number()))); + for (Step step : Step.values()) { - runDetails.get(step).ifPresent(stepLog -> logsObject.setString(step.name(), stepLog)); + runLog.get(step).ifPresent(entries -> toSlime(logsObject.setArray(step.name()), entries)); } + runLog.lastId().ifPresent(id -> logsObject.setLong("lastId", id)); return new SlimeJsonResponse(slime); } + private static void toSlime(Cursor entryArray, List<LogEntry> entries) { + entries.forEach(entry -> toSlime(entryArray.addObject(), entry)); + } + + private static void toSlime(Cursor entryObject, LogEntry entry) { + entryObject.setLong("at", entry.at()); + entryObject.setString("level", entry.level().getName()); + entryObject.setString("message", entry.message()); + } + /** * Unpack payload and submit to job controller. Defaults instance to 'default' and renders the * application version on success. 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 ba0607892e6..42d4beedb0b 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 @@ -37,7 +37,9 @@ import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; import java.time.Duration; +import java.util.Arrays; import java.util.Collections; +import java.util.List; import java.util.Optional; import java.util.logging.Logger; import java.util.stream.Collectors; @@ -367,12 +369,10 @@ public class InternalStepRunnerTest { } private void assertLogMessages(RunId id, Step step, String... messages) { - String pattern = Stream.of(messages) - .map(message -> "\\[[^]]*] : " + message + "\n") - .collect(Collectors.joining()); - String logs = new String(jobs.details(id).get().get(step).get()); - if ( ! logs.matches(pattern)) - throw new AssertionError("Expected a match for\n'''\n" + pattern + "\n'''\nbut got\n'''\n" + logs + "\n'''"); + assertEquals(Arrays.asList(messages), + jobs.details(id).get().get(step).get().stream() + .map(LogEntry::message) + .collect(Collectors.toList())); } private RunId startSystemTestTests() { diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStoreTest.java b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStoreTest.java index 2438bbbd947..35a6ab2aaec 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStoreTest.java +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/BufferedLogStoreTest.java @@ -1,5 +1,84 @@ package com.yahoo.vespa.hosted.controller.persistence; +import com.yahoo.config.provision.ApplicationId; +import com.yahoo.vespa.hosted.controller.api.integration.RunDataStore; +import com.yahoo.vespa.hosted.controller.api.integration.deployment.JobType; +import com.yahoo.vespa.hosted.controller.api.integration.deployment.RunId; +import com.yahoo.vespa.hosted.controller.api.integration.stubs.MockRunDataStore; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; +import com.yahoo.vespa.hosted.controller.deployment.RunLog; +import com.yahoo.vespa.hosted.controller.deployment.Step; +import org.junit.Test; + +import java.util.Arrays; +import java.util.Collections; +import java.util.Optional; +import java.util.logging.Level; + +import static org.junit.Assert.assertArrayEquals; +import static org.junit.Assert.assertEquals; + public class BufferedLogStoreTest { + @Test + public void chunkingAndFlush() { + CuratorDb buffer = new MockCuratorDb(); + RunDataStore store = new MockRunDataStore(); + BufferedLogStore logs = new BufferedLogStore(buffer, store); + RunId id = new RunId(ApplicationId.from("tenant", "application", "instance"), + JobType.productionUsWest1, + 123); + + byte[] manyBytes = new byte[BufferedLogStore.chunkSize / 2 + 1]; // One fits, and two (over-)fills. + Arrays.fill(manyBytes, (byte) 'O'); + LogEntry entry = new LogEntry(0, 123, Level.WARNING, new String(manyBytes)); + + // Log entries are re-sequenced by the log store, by enumeration. + LogEntry entry0 = new LogEntry(0, entry.at(), entry.level(), entry.message()); + LogEntry entry1 = new LogEntry(1, entry.at(), entry.level(), entry.message()); + LogEntry entry2 = new LogEntry(2, entry.at(), entry.level(), entry.message()); + + assertEquals(Optional.empty(), logs.readFinished(id, -1)); + assertEquals(RunLog.empty(), logs.readActive(id.application(), id.type(), -1)); + + logs.append(id.application(), id.type(), Step.deployReal, Collections.singletonList(entry)); + assertEquals(Arrays.asList(entry0), + logs.readActive(id.application(), id.type(), -1).get(Step.deployReal).get()); + assertEquals(RunLog.empty(), logs.readActive(id.application(), id.type(), 0)); + + logs.append(id.application(), id.type(), Step.deployReal, Collections.singletonList(entry)); + assertEquals(Arrays.asList(entry0, entry1), + logs.readActive(id.application(), id.type(), -1).get(Step.deployReal).get()); + assertEquals(Arrays.asList(entry1), + logs.readActive(id.application(), id.type(), 0).get(Step.deployReal).get()); + assertEquals(RunLog.empty(), logs.readActive(id.application(), id.type(), 1)); + + logs.append(id.application(), id.type(), Step.deployReal, Collections.singletonList(entry)); + assertEquals(Arrays.asList(entry0, entry1, entry2), + logs.readActive(id.application(), id.type(), -1).get(Step.deployReal).get()); + assertEquals(Arrays.asList(entry1, entry2), + logs.readActive(id.application(), id.type(), 0).get(Step.deployReal).get()); + assertEquals(Arrays.asList(entry2), + logs.readActive(id.application(), id.type(), 1).get(Step.deployReal).get()); + assertEquals(RunLog.empty(), logs.readActive(id.application(), id.type(), 2)); + + // We should now have two chunks, with two and one entries. + assertEquals(Optional.of(2L), buffer.readLastLogEntryId(id.application(), id.type())); + assertArrayEquals(new long[]{0, 2}, buffer.getLogChunkIds(id.application(), id.type()).toArray()); + + // Flushing clears the buffer entirely, and stores its aggregated content in the data store. + logs.flush(id); + assertEquals(Optional.empty(), buffer.readLastLogEntryId(id.application(), id.type())); + assertArrayEquals(new long[]{}, buffer.getLogChunkIds(id.application(), id.type()).toArray()); + assertEquals(RunLog.empty(), logs.readActive(id.application(), id.type(), -1)); + + assertEquals(Arrays.asList(entry0, entry1, entry2), + logs.readFinished(id, -1).get().get(Step.deployReal).get()); + assertEquals(Arrays.asList(entry1, entry2), + logs.readFinished(id, 0).get().get(Step.deployReal).get()); + assertEquals(Arrays.asList(entry2), + logs.readFinished(id, 1).get().get(Step.deployReal).get()); + assertEquals(Collections.emptyList(), logs.readFinished(id, 2).get().get(Step.deployReal).get()); + } + } diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializerTest.java b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializerTest.java index 554e30637f9..982d32bdda4 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializerTest.java +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/LogSerializerTest.java @@ -1,9 +1,7 @@ package com.yahoo.vespa.hosted.controller.persistence; -import com.google.common.collect.ImmutableList; -import com.google.common.collect.ImmutableMap; import com.yahoo.log.LogLevel; -import com.yahoo.vespa.config.SlimeUtils; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; import com.yahoo.vespa.hosted.controller.deployment.Step; import org.junit.Test; @@ -11,10 +9,11 @@ import java.io.IOException; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.HashMap; import java.util.List; import java.util.Map; -import java.util.logging.Level; -import java.util.logging.LogRecord; import static com.yahoo.vespa.hosted.controller.deployment.Step.deployReal; import static com.yahoo.vespa.hosted.controller.deployment.Step.deployTester; @@ -25,41 +24,38 @@ import static org.junit.Assert.assertEquals; */ public class LogSerializerTest { - private static final LogRecordSerializer serializer = new LogRecordSerializer(); + private static final LogSerializer serializer = new LogSerializer(); private static final Path logsFile = Paths.get("src/test/java/com/yahoo/vespa/hosted/controller/persistence/testdata/logs.json"); @Test public void testSerialization() throws IOException { - // Local, because it's not supposed to be used for anything else than verifying equality here! - class EgalitarianLogRecord extends LogRecord { - private EgalitarianLogRecord(Level level, String msg) { - super(level, msg); - } - @Override - public boolean equals(Object o) { - if ( ! (o instanceof LogRecord)) return false; - LogRecord record = (LogRecord) o; - return getSequenceNumber() == record.getSequenceNumber() - && getLevel() == record.getLevel() - && getMillis() == record.getMillis() - && getMessage().equals(record.getMessage()); - } - @Override - public int hashCode() { throw new AssertionError(); } - } + byte[] logJson = Files.readAllBytes(logsFile); - LogRecord first = new EgalitarianLogRecord(LogLevel.INFO, "First"); first.setMillis( 0); first.setSequenceNumber(1); - LogRecord second = new EgalitarianLogRecord(LogLevel.INFO, "Second"); second.setMillis( 0); second.setSequenceNumber(2); - LogRecord third = new EgalitarianLogRecord(LogLevel.DEBUG, "Third"); third.setMillis(1000); third.setSequenceNumber(3); - LogRecord fourth = new EgalitarianLogRecord(LogLevel.WARNING, "Fourth"); fourth.setMillis(2000); fourth.setSequenceNumber(4); + LogEntry first = new LogEntry(0, 0, LogLevel.INFO, "First"); + LogEntry second = new LogEntry(1, 0, LogLevel.INFO, "Second"); + LogEntry third = new LogEntry(2, 1000, LogLevel.DEBUG, "Third"); + LogEntry fourth = new LogEntry(3, 2000, LogLevel.WARNING, "Fourth"); - Map<Step, List<LogRecord>> expected = ImmutableMap.of(deployReal, ImmutableList.of(first, third), - deployTester, ImmutableList.of(second, fourth)); + Map<Step, List<LogEntry>> expected = new HashMap<>(); + expected.put(deployReal, new ArrayList<>()); + expected.get(deployReal).add(third); + expected.put(deployTester, new ArrayList<>()); + expected.get(deployTester).add(fourth); - Map<Step, List<LogRecord>> stepRecords = serializer.recordsFromSlime(SlimeUtils.jsonToSlime(Files.readAllBytes(logsFile))); - assertEquals(expected, stepRecords); + assertEquals(expected, serializer.fromJson(logJson, 1)); - assertEquals(expected, serializer.recordsFromSlime(serializer.recordsToSlime(stepRecords))); + expected.get(deployReal).add(0, first); + expected.get(deployTester).add(0, second); + assertEquals(expected, serializer.fromJson(logJson, -1)); + + assertEquals(expected, serializer.fromJson(serializer.toJson(expected), -1)); + + expected.get(deployReal).add(first); + expected.get(deployReal).add(third); + expected.get(deployTester).add(second); + expected.get(deployTester).add(fourth); + + assertEquals(expected, serializer.fromJson(Arrays.asList(logJson, logJson), -1)); } } diff --git a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/testdata/logs.json b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/testdata/logs.json index 1135e63e464..a6a092109a1 100644 --- a/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/testdata/logs.json +++ b/controller-server/src/test/java/com/yahoo/vespa/hosted/controller/persistence/testdata/logs.json @@ -2,13 +2,13 @@ "deployReal": [ { - "id": 1, + "id": 0, "level": "info", "at": 0, "message": "First" }, { - "id": 3, + "id": 2, "level": "debug", "at": 1000, "message": "Third" @@ -17,13 +17,13 @@ "deployTester": [ { - "id": 2, + "id": 1, "level": "info", "at": 0, "message": "Second" }, { - "id": 4, + "id": 3, "level": "warning", "at": 2000, "message": "Fourth" 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 1eec4890a35..fd749d07491 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 @@ -11,10 +11,12 @@ import com.yahoo.vespa.hosted.controller.api.integration.stubs.MockRunDataStore; import com.yahoo.vespa.hosted.controller.application.ApplicationVersion; import com.yahoo.vespa.hosted.controller.application.SourceRevision; import com.yahoo.vespa.hosted.controller.deployment.JobController; +import com.yahoo.vespa.hosted.controller.deployment.LogEntry; import com.yahoo.vespa.hosted.controller.deployment.Run; import com.yahoo.vespa.hosted.controller.deployment.RunStatus; import com.yahoo.vespa.hosted.controller.deployment.Step; import com.yahoo.vespa.hosted.controller.deployment.Versions; +import com.yahoo.vespa.hosted.controller.persistence.BufferedLogStore; import org.json.JSONException; import org.json.JSONObject; import org.junit.Assert; @@ -33,6 +35,7 @@ import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.Optional; +import java.util.logging.Level; import static org.junit.Assert.fail; @@ -90,19 +93,21 @@ public class JobControllerApiHandlerHelperTest { @Test public void runDetailsResponse() { ControllerTester tester = new ControllerTester(); - MockRunDataStore logStore = new MockRunDataStore(); - JobController jobController = new JobController(tester.controller(), logStore); + MockRunDataStore dataStore = new MockRunDataStore(); + JobController jobController = new JobController(tester.controller(), dataStore); + BufferedLogStore logStore = new BufferedLogStore(tester.curator(), dataStore); RunId runId = new RunId(appId, JobType.systemTest, 42); tester.curator().writeHistoricRuns( runId.application(), runId.type(), Collections.singleton(createRun(JobType.systemTest, 42, 44, lastStep, Optional.of(RunStatus.running)))); - logStore.append(runId, Step.deployTester.name(), "INFO\t1234567890\tSUCCESS".getBytes()); - logStore.append(runId, Step.installTester.name(), "INFO\t1234598760\tSUCCESS".getBytes()); - logStore.append(runId, Step.deactivateTester.name(), "INFO\t1234678901\tERROR: Something went wrong".getBytes()); + logStore.append(appId, JobType.systemTest, Step.deployTester, Collections.singletonList(new LogEntry(0, 1, Level.INFO, "SUCCESS"))); + logStore.append(appId, JobType.systemTest, Step.installTester, Collections.singletonList(new LogEntry(0, 12, Level.FINE, "SUCCESS"))); + logStore.append(appId, JobType.systemTest, Step.deactivateTester, Collections.singletonList(new LogEntry(0, 123, Level.WARNING, "ERROR"))); + logStore.flush(runId); - HttpResponse response = JobControllerApiHandlerHelper.runDetailsResponse(jobController, runId); + HttpResponse response = JobControllerApiHandlerHelper.runDetailsResponse(jobController, runId,"0"); assertFile(response, "job/run-details-response.json"); } diff --git a/controller-server/src/test/resources/job/run-details-response.json b/controller-server/src/test/resources/job/run-details-response.json index 3ba9bff049e..06f02565a75 100644 --- a/controller-server/src/test/resources/job/run-details-response.json +++ b/controller-server/src/test/resources/job/run-details-response.json @@ -1,5 +1,19 @@ { - "deployTester":"INFO\t1234567890\tSUCCESS", - "installTester":"INFO\t1234598760\tSUCCESS", - "deactivateTester":"INFO\t1234678901\tERROR: Something went wrong" + "active":false, + "lastId":2, + "deployTester":[], + "installTester":[ + { + "at":12, + "level":"DEBUG", + "message":"SUCCESS" + } + ], + "deactivateTester":[ + { + "at":123, + "level":"WARNING", + "message":"ERROR" + } + ] } |