diff --git a/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardData.java b/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardData.java index 284f7aa16a..5d96109ed5 100644 --- a/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardData.java +++ b/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardData.java @@ -1,5 +1,5 @@ /** - * Copyright (C) 2013-2017 Expedia Inc. + * Copyright (C) 2013-2018 Expedia Inc. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -174,11 +174,6 @@ private void updateBackendsFromRegistry() { .map(Backend::new) .collect(toList()); } - - @Override - public void onError(Throwable ex) { - // do nothing - } } /** diff --git a/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardDataSupplier.java b/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardDataSupplier.java index 5f933fdd2b..52cbd0847a 100644 --- a/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardDataSupplier.java +++ b/components/proxy/src/main/java/com/hotels/styx/admin/dashboard/DashboardDataSupplier.java @@ -1,5 +1,5 @@ /** - * Copyright (C) 2013-2017 Expedia Inc. + * Copyright (C) 2013-2018 Expedia Inc. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -62,11 +62,6 @@ private DashboardData updateDashboardData(Registry backendServic return new DashboardData(environment.metricRegistry(), backendServices, jvmRouteName, buildInfo, environment.eventBus()); } - @Override - public void onError(Throwable ex) { - // do nothing - } - @Override public DashboardData get() { return data; diff --git a/components/proxy/src/main/java/com/hotels/styx/admin/tasks/OriginsReloadCommandHandler.java b/components/proxy/src/main/java/com/hotels/styx/admin/tasks/OriginsReloadCommandHandler.java index e84b792360..8da3677d8a 100644 --- a/components/proxy/src/main/java/com/hotels/styx/admin/tasks/OriginsReloadCommandHandler.java +++ b/components/proxy/src/main/java/com/hotels/styx/admin/tasks/OriginsReloadCommandHandler.java @@ -1,5 +1,5 @@ /** - * Copyright (C) 2013-2017 Expedia Inc. + * Copyright (C) 2013-2018 Expedia Inc. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -72,6 +72,8 @@ private void reload(Subscriber subscriber) { } else if (result.outcome() == UNCHANGED) { subscriber.onNext(okResponse(format("Origins were not reloaded because %s.\n", result.message()))); subscriber.onCompleted(); + } else { + subscriber.onError(mapError(result)); } } else { subscriber.onNext(errorResponse(exception)); @@ -81,6 +83,14 @@ private void reload(Subscriber subscriber) { }); } + private Throwable mapError(Registry.ReloadResult result) { + if (result.cause().isPresent()) { + return new RuntimeException(result.cause().get()); + } else { + return new RuntimeException("Reload failure"); + } + } + private HttpResponse okResponse(String content) { return response(OK) .contentType(PLAIN_TEXT_UTF_8) diff --git a/components/proxy/src/main/java/com/hotels/styx/infrastructure/AbstractRegistry.java b/components/proxy/src/main/java/com/hotels/styx/infrastructure/AbstractRegistry.java index 12a7a30d74..42a16e2e49 100644 --- a/components/proxy/src/main/java/com/hotels/styx/infrastructure/AbstractRegistry.java +++ b/components/proxy/src/main/java/com/hotels/styx/infrastructure/AbstractRegistry.java @@ -54,11 +54,6 @@ protected void notifyListeners(Changes changes) { announcer.announce().onChange(changes); } - protected void notifyListenersOnError(Throwable cause) { - LOG.info("notifying about error={} to listeners={}", cause, announcer.listeners()); - announcer.announce().onError(cause); - } - @Override public Registry addListener(ChangeListener changeListener) { announcer.addListener(changeListener); diff --git a/components/proxy/src/main/java/com/hotels/styx/infrastructure/FileBackedRegistry.java b/components/proxy/src/main/java/com/hotels/styx/infrastructure/FileBackedRegistry.java index 419615609d..1b619d1530 100644 --- a/components/proxy/src/main/java/com/hotels/styx/infrastructure/FileBackedRegistry.java +++ b/components/proxy/src/main/java/com/hotels/styx/infrastructure/FileBackedRegistry.java @@ -15,6 +15,7 @@ */ package com.hotels.styx.infrastructure; +import com.google.common.annotations.VisibleForTesting; import com.google.common.hash.HashCode; import com.hotels.styx.api.Identifiable; import com.hotels.styx.api.Resource; @@ -22,15 +23,22 @@ import java.io.IOException; import java.io.InputStream; +import java.nio.file.Paths; +import java.nio.file.attribute.FileTime; +import java.util.Optional; import java.util.concurrent.CompletableFuture; +import java.util.function.Supplier; import static com.google.common.base.Preconditions.checkNotNull; import static com.google.common.base.Throwables.propagate; import static com.google.common.hash.HashCode.fromLong; import static com.google.common.hash.Hashing.md5; import static com.google.common.io.ByteStreams.toByteArray; +import static com.hotels.styx.infrastructure.Registry.ReloadResult.failed; import static com.hotels.styx.infrastructure.Registry.ReloadResult.reloaded; import static com.hotels.styx.infrastructure.Registry.ReloadResult.unchanged; +import static java.lang.String.format; +import static java.nio.file.Files.getLastModifiedTime; import static java.util.Objects.requireNonNull; import static java.util.concurrent.CompletableFuture.supplyAsync; import static java.util.concurrent.Executors.newSingleThreadExecutor; @@ -45,11 +53,18 @@ public class FileBackedRegistry extends AbstractRegistry private static final Logger LOG = getLogger(FileBackedRegistry.class); private final Resource configurationFile; private final Reader reader; + private final Supplier modifyTimeSupplier; private HashCode fileHash = fromLong(0); - public FileBackedRegistry(Resource configurationFile, Reader reader) { + @VisibleForTesting + FileBackedRegistry(Resource configurationFile, Reader reader, Supplier modifyTimeSupplier) { this.configurationFile = requireNonNull(configurationFile); this.reader = checkNotNull(reader); + this.modifyTimeSupplier = modifyTimeSupplier; + } + + public FileBackedRegistry(Resource configurationFile, Reader reader) { + this(configurationFile, reader, fileModificationTimeProvider(configurationFile)); } public String fileName() { @@ -61,30 +76,50 @@ public CompletableFuture reload() { return supplyAsync(() -> { byte[] content = readFile(); HashCode hashCode = md5().hashBytes(content); + String modifyTime = fileModificationTime().map(FileTime::toString).orElse("NA"); + + String logPrefix = format("timestamp=%s, md5-hash=%s", modifyTime, hashCode); if (hashCode.equals(fileHash)) { LOG.info("Not reloading {} as content did not change", configurationFile.absolutePath()); - return unchanged("file content did not change"); + return unchanged(format("%s, Identical file content.", logPrefix)); } else { try { boolean changesPerformed = updateResources(content, hashCode); if (!changesPerformed) { LOG.info("Not firing change event for {} as content was not semantically different", configurationFile.absolutePath()); - return unchanged("file content was not semantically different"); + return unchanged(format("%s, No semantic changes.", logPrefix)); } else { LOG.debug("Changes applied!"); - return reloaded("Changes applied!"); + return reloaded(format("%s, File reloaded.", logPrefix)); } } catch (Exception e) { LOG.error("Not reloading {} as there was an error reading content", configurationFile.absolutePath(), e); - notifyListenersOnError(e); - throw e; + return failed(format("%s, Reload failure.", logPrefix), e); } } }, newSingleThreadExecutor()); } + private static Supplier fileModificationTimeProvider(Resource path) { + return () -> { + try { + return getLastModifiedTime(Paths.get(path.path())); + } catch (Throwable cause) { + throw new RuntimeException(cause); + } + }; + } + + private Optional fileModificationTime() { + try { + return Optional.of(modifyTimeSupplier.get()); + } catch (Throwable cause) { + return Optional.empty(); + } + } + private boolean updateResources(byte[] content, HashCode hashCode) { Iterable resources = reader.read(content); diff --git a/components/proxy/src/main/java/com/hotels/styx/infrastructure/Registry.java b/components/proxy/src/main/java/com/hotels/styx/infrastructure/Registry.java index d6d9c50e0a..3effeef4b0 100644 --- a/components/proxy/src/main/java/com/hotels/styx/infrastructure/Registry.java +++ b/components/proxy/src/main/java/com/hotels/styx/infrastructure/Registry.java @@ -23,11 +23,13 @@ import java.util.EventListener; import java.util.Objects; +import java.util.Optional; import java.util.concurrent.CompletableFuture; import java.util.function.Supplier; import static com.google.common.base.Objects.toStringHelper; import static com.google.common.base.Preconditions.checkNotNull; +import static com.hotels.styx.infrastructure.Registry.Outcome.FAILED; import static com.hotels.styx.infrastructure.Registry.Outcome.RELOADED; import static com.hotels.styx.infrastructure.Registry.Outcome.UNCHANGED; import static java.util.Arrays.asList; @@ -71,10 +73,7 @@ interface Factory extends ServiceFactory> { * @param The type of configuration referred to by this ChangeListener */ interface ChangeListener extends EventListener { - void onChange(Changes changes); - - void onError(Throwable ex); } /** @@ -203,28 +202,34 @@ public Changes build() { */ enum Outcome { RELOADED, - UNCHANGED + UNCHANGED, + FAILED } /** * Result of registry reload. */ class ReloadResult { + private final Outcome outcome; + private final String message; + private final Throwable cause; - Outcome outcome; - String message; - - private ReloadResult(Outcome outcome, String message) { + private ReloadResult(Outcome outcome, String message, Throwable cause) { this.outcome = outcome; this.message = message; + this.cause = cause; } public static ReloadResult reloaded(String message) { - return new ReloadResult(RELOADED, message); + return new ReloadResult(RELOADED, message, null); + } + + public static ReloadResult failed(String message, Throwable cause) { + return new ReloadResult(FAILED, message, cause); } public static ReloadResult unchanged(String message) { - return new ReloadResult(UNCHANGED, message); + return new ReloadResult(UNCHANGED, message, null); } public Outcome outcome() { @@ -235,6 +240,10 @@ public String message() { return message; } + public Optional cause() { + return Optional.ofNullable(cause); + } + @Override public boolean equals(Object o) { if (this == o) { @@ -246,21 +255,20 @@ public boolean equals(Object o) { } ReloadResult that = (ReloadResult) o; - return outcome == that.outcome && Objects.equals(message, that.message); + return outcome == that.outcome && Objects.equals(message, that.message) && Objects.equals(cause, that.cause); } @Override public int hashCode() { - return Objects.hash(outcome, message); + return Objects.hash(outcome, message, cause); } @Override public String toString() { - final StringBuilder sb = new StringBuilder("ReloadResult{"); - sb.append("outcome=").append(outcome); - sb.append(", message='").append(message).append('\''); - sb.append('}'); - return sb.toString(); + return "ReloadResult{" + "outcome=" + outcome + + ", message='" + message + '\'' + + ", cause='" + cause + "\'" + + '}'; } } } diff --git a/components/proxy/src/main/java/com/hotels/styx/proxy/BackendServicesRouter.java b/components/proxy/src/main/java/com/hotels/styx/proxy/BackendServicesRouter.java index 77a354c869..af754a9941 100644 --- a/components/proxy/src/main/java/com/hotels/styx/proxy/BackendServicesRouter.java +++ b/components/proxy/src/main/java/com/hotels/styx/proxy/BackendServicesRouter.java @@ -224,11 +224,6 @@ private static OriginHealthCheckFunction originHealthCheckFunction( return new UrlRequestHealthCheck(healthCheckUri, client, metricRegistry); } - @Override - public void onError(Throwable ex) { - LOG.warn("Error from registry", ex); - } - private static class ProxyToClientPipeline implements HttpHandler2 { private final HttpClient client; private final OriginsInventory originsInventory; diff --git a/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistry.java b/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistry.java index 222dc5101b..31bcb8e5c9 100644 --- a/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistry.java +++ b/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistry.java @@ -27,6 +27,8 @@ import com.hotels.styx.infrastructure.Registry; import com.hotels.styx.infrastructure.YamlReader; import com.hotels.styx.proxy.backends.file.FileChangeMonitor.FileMonitorSettings; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import java.util.List; import java.util.concurrent.CompletableFuture; @@ -35,6 +37,7 @@ import static com.google.common.base.Throwables.propagate; import static com.hotels.styx.api.io.ResourceFactory.newResource; import static com.hotels.styx.client.applications.BackendServices.newBackendServices; +import static com.hotels.styx.infrastructure.Registry.Outcome.FAILED; import static java.lang.String.format; import static java.util.Objects.requireNonNull; @@ -42,6 +45,7 @@ * File backed {@link com.hotels.styx.client.applications.BackendService} registry. */ public class FileBackedBackendServicesRegistry extends AbstractStyxService implements Registry, FileChangeMonitor.Listener { + private static final Logger LOGGER = LoggerFactory.getLogger(FileBackedBackendServicesRegistry.class); private final FileBackedRegistry fileBackedRegistry; private final FileMonitor fileChangeMonitor; @@ -80,7 +84,8 @@ public Registry removeListener(ChangeListener ch @Override public CompletableFuture reload() { - return this.fileBackedRegistry.reload(); + return this.fileBackedRegistry.reload() + .thenApply(outcome -> logReloadAttempt("Admin Interface", outcome)); } @Override @@ -98,8 +103,11 @@ protected CompletableFuture startService() { return x; } return this.fileBackedRegistry.reload() + .thenApply(result -> logReloadAttempt("Initial load", result)) .thenAccept(result -> { - // Swallow the result + if (result.outcome() == FAILED) { + throw new RuntimeException(result.cause().orElse(null)); + } }); } @@ -115,7 +123,19 @@ FileMonitor monitor() { @Override public void fileChanged() { - this.fileBackedRegistry.reload(); + this.fileBackedRegistry.reload() + .thenApply(outcome -> logReloadAttempt("File Monitor", outcome)); + } + + private ReloadResult logReloadAttempt(String reason, ReloadResult outcome) { + String fileName = this.fileBackedRegistry.fileName(); + if (outcome.outcome() == Outcome.RELOADED || outcome.outcome() == Outcome.UNCHANGED) { + LOGGER.info("Backend services reloaded. reason='{}', {}, file='{}'", new Object[]{reason, outcome.message(), fileName}); + } else if (outcome.outcome() == FAILED) { + LOGGER.error("Backend services reload failed. reason='{}', {}, file='{}'", + new Object[]{reason, outcome.message(), fileName, outcome.cause().get()}); + } + return outcome; } /** diff --git a/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileChangeMonitor.java b/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileChangeMonitor.java index 99a0abd62c..c24904b512 100644 --- a/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileChangeMonitor.java +++ b/components/proxy/src/main/java/com/hotels/styx/proxy/backends/file/FileChangeMonitor.java @@ -82,6 +82,12 @@ public void start(Listener listener) { } } + public void stop() { + if (monitoredTask != null) { + monitoredTask.cancel(true); + } + } + private Runnable detectFileChangesTask(Listener listener) { return () -> { if (!exists(monitoredFile)) { diff --git a/components/proxy/src/test/java/com/hotels/styx/infrastructure/FileBackedRegistryTest.java b/components/proxy/src/test/java/com/hotels/styx/infrastructure/FileBackedRegistryTest.java index 1ec918d92c..7816b0bd50 100644 --- a/components/proxy/src/test/java/com/hotels/styx/infrastructure/FileBackedRegistryTest.java +++ b/components/proxy/src/test/java/com/hotels/styx/infrastructure/FileBackedRegistryTest.java @@ -26,16 +26,17 @@ import java.io.ByteArrayInputStream; import java.io.IOException; -import java.util.concurrent.ExecutionException; +import java.nio.file.attribute.FileTime; +import java.util.function.Supplier; import static com.hotels.styx.api.client.Origin.newOriginBuilder; import static com.hotels.styx.common.StyxFutures.await; -import static com.hotels.styx.infrastructure.FileBackedRegistry.changes; import static com.hotels.styx.infrastructure.Registry.ReloadResult.reloaded; import static com.hotels.styx.infrastructure.Registry.ReloadResult.unchanged; import static java.nio.charset.StandardCharsets.UTF_8; import static java.util.Collections.singletonList; import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.instanceOf; import static org.hamcrest.Matchers.is; import static org.mockito.Matchers.eq; import static org.mockito.Mockito.mock; @@ -43,13 +44,14 @@ import static org.mockito.Mockito.when; import static org.mockito.Mockito.withSettings; -public class FileBackedRegistryTest { +public class FileBackedRegistryTest { private byte[] originalContent; private byte[] newContent; private BackendService backendService; private FileBackedRegistry registry; private Registry.ChangeListener listener; + private Supplier timeSupplier; @BeforeMethod public void setUp() { @@ -57,27 +59,27 @@ public void setUp() { newContent = "... new file ...".getBytes(UTF_8); backendService = new BackendService.Builder().build(); listener = mock(Registry.ChangeListener.class, withSettings().verboseLogging()); + timeSupplier = () -> FileTime.fromMillis(1520857740000L); } @Test public void calculatesTheDifferenceBetweenCurrentAndNewResources() { Iterable newResources = singletonList(backendService("one", 9090)); Iterable currentResources = singletonList(backendService("two", 9091)); - - Registry.Changes changes = changes(newResources, currentResources); Registry.Changes expected = new Registry.Changes.Builder<>() .added(backendService("one", 9090)) .removed(backendService("two", 9091)) .build(); + Registry.Changes changes = FileBackedRegistry.changes(newResources, currentResources); assertThat(changes.toString(), is(expected.toString())); } @Test - public void announcesInitialStateWhenStarts() throws IOException, ExecutionException, InterruptedException { + public void announcesInitialStateWhenStarts() throws IOException { Resource configurationFile = mockResource("/styx/config", new ByteArrayInputStream(originalContent)); - registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService)); + registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService), timeSupplier); registry.addListener(listener); await(registry.reload()); @@ -85,7 +87,6 @@ public void announcesInitialStateWhenStarts() throws IOException, ExecutionExcep verify(listener).onChange(eq(changeSet().added(backendService).build())); } - @Test public void announcesNoMeaningfulChangesWhenFileDidNotChange() throws Exception { Resource configurationFile = mockResource("/styx/config", @@ -93,13 +94,13 @@ public void announcesNoMeaningfulChangesWhenFileDidNotChange() throws Exception new ByteArrayInputStream(originalContent) ); - registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService)); + registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService), timeSupplier); registry.addListener(listener); await(registry.reload()); verify(listener).onChange(eq(changeSet().added(backendService).build())); ReloadResult result = registry.reload().get(); - assertThat(result, is(unchanged("file content did not change"))); + assertThat(result, is(unchanged("timestamp=2018-03-12T12:29:00Z, md5-hash=c346e70114eff08dceb13562f9abaa48, Identical file content."))); // Still only one invocation, because reload didn't introduce any changes to configuration verify(listener).onChange(eq(changeSet().added(backendService).build())); @@ -109,7 +110,7 @@ public void announcesNoMeaningfulChangesWhenFileDidNotChange() throws Exception public void announcesNoMeaningfulChangesWhenNoSemanticChanges() throws Exception { Resource configurationFile = mockResource("/styx/config", new ByteArrayInputStream(originalContent)); - registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService)); + registry = new FileBackedRegistry<>(configurationFile, bytes -> ImmutableList.of(backendService), timeSupplier); registry.addListener(listener); await(registry.reload()); @@ -117,7 +118,7 @@ public void announcesNoMeaningfulChangesWhenNoSemanticChanges() throws Exception when(configurationFile.inputStream()).thenReturn(new ByteArrayInputStream(newContent)); ReloadResult result = registry.reload().get(); - assertThat(result, is(unchanged("file content was not semantically different"))); + assertThat(result, is(unchanged("timestamp=2018-03-12T12:29:00Z, md5-hash=24996b9d53b21a60c35dcb7ca3fb331a, No semantic changes."))); // Still only one invocation, because reload didn't introduce any changes to configuration verify(listener).onChange(eq(changeSet().added(backendService).build())); @@ -140,7 +141,8 @@ public void announcesChanges() throws Exception { } else { return ImmutableList.of(backendService2); } - }); + }, + timeSupplier); registry.addListener(listener); verify(listener).onChange(eq(changeSet().build())); @@ -149,18 +151,14 @@ public void announcesChanges() throws Exception { verify(listener).onChange(eq(changeSet().added(backendService1).build())); ReloadResult result = registry.reload().get(); - assertThat(result, is(reloaded("Changes applied!"))); + assertThat(result, is(reloaded("timestamp=2018-03-12T12:29:00Z, md5-hash=24996b9d53b21a60c35dcb7ca3fb331a, File reloaded."))); assertThat(backendService1.equals(backendService2), is(false)); verify(listener).onChange(eq(changeSet().updated(backendService2).build())); } - private Registry.Changes.Builder changeSet() { - return new Registry.Changes.Builder<>(); - } - - @Test(expectedExceptions = RuntimeException.class, expectedExceptionsMessageRegExp = "java.util.concurrent.ExecutionException: java.lang.RuntimeException: Something went wrong...") + @Test public void completesWithExceptionWhenErrorsDuringReload() throws Exception { Resource configurationFile = mockResource("/styx/config", new ByteArrayInputStream(originalContent), @@ -174,18 +172,43 @@ public void completesWithExceptionWhenErrorsDuringReload() throws Exception { } else { throw new RuntimeException("Something went wrong..."); } - }); + }, + timeSupplier); registry.addListener(listener); - await(registry.reload()); + ReloadResult outcome = await(registry.reload()); + assertThat(outcome, is(reloaded("timestamp=2018-03-12T12:29:00Z, md5-hash=c346e70114eff08dceb13562f9abaa48, File reloaded."))); verify(listener).onChange(eq(changeSet().added(backendService).build())); - - await(registry.reload()); + outcome = await(registry.reload()); + assertThat(outcome.outcome(), is(Registry.Outcome.FAILED)); + assertThat(outcome.message(), is("timestamp=2018-03-12T12:29:00Z, md5-hash=24996b9d53b21a60c35dcb7ca3fb331a, Reload failure.")); + assertThat(outcome.cause().get(), instanceOf(RuntimeException.class)); // Noting changed verify(listener).onChange(eq(changeSet().added(backendService).build())); } + @Test + public void modifyTimeProviderHandlesExceptions() throws Exception { + registry = new FileBackedRegistry<>( + mockResource("/styx/config", new ByteArrayInputStream(originalContent)), + bytes -> ImmutableList.of(new BackendService.Builder().id("x").path("/x").build()), + () -> { + throw new RuntimeException("something went wrong"); + } + ); + + registry.addListener(listener); + verify(listener).onChange(eq(changeSet().build())); + + ReloadResult result = registry.reload().get(); + assertThat(result, is(reloaded("timestamp=NA, md5-hash=c346e70114eff08dceb13562f9abaa48, File reloaded."))); + } + + private Registry.Changes.Builder changeSet() { + return new Registry.Changes.Builder<>(); + } + private Resource mockResource(String path, ByteArrayInputStream content) throws IOException { Resource configuration = mock(Resource.class); when(configuration.absolutePath()).thenReturn(path); diff --git a/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistryTest.java b/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistryTest.java index 37ca12e9e9..da505383e8 100644 --- a/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistryTest.java +++ b/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileBackedBackendServicesRegistryTest.java @@ -22,20 +22,30 @@ import com.hotels.styx.infrastructure.Registry; import com.hotels.styx.infrastructure.Registry.ReloadResult; import com.hotels.styx.proxy.backends.file.FileBackedBackendServicesRegistry.YAMLBackendServicesReader; +import com.hotels.styx.support.matchers.LoggingTestSupport; +import org.testng.annotations.AfterMethod; +import org.testng.annotations.BeforeMethod; import org.testng.annotations.Test; import java.io.IOException; import java.util.Optional; import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletionException; +import java.util.concurrent.ExecutionException; +import static ch.qos.logback.classic.Level.ERROR; +import static ch.qos.logback.classic.Level.INFO; import static com.google.common.collect.Lists.newArrayList; import static com.google.common.io.ByteStreams.toByteArray; import static com.hotels.styx.api.io.ResourceFactory.newResource; import static com.hotels.styx.common.StyxFutures.await; +import static com.hotels.styx.infrastructure.Registry.ReloadResult.failed; import static com.hotels.styx.infrastructure.Registry.ReloadResult.reloaded; +import static com.hotels.styx.infrastructure.Registry.ReloadResult.unchanged; +import static com.hotels.styx.support.matchers.LoggingEventMatcher.loggingEvent; import static java.util.concurrent.CompletableFuture.completedFuture; import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.hasItem; import static org.hamcrest.Matchers.instanceOf; import static org.hamcrest.Matchers.is; import static org.mockito.Matchers.eq; @@ -46,10 +56,22 @@ public class FileBackedBackendServicesRegistryTest { FileBackedBackendServicesRegistry registry; + LoggingTestSupport log; + + @BeforeMethod + public void setUp() { + log = new LoggingTestSupport(FileBackedBackendServicesRegistry.class); + } + + @AfterMethod + public void tearDown() { + log.stop(); + } @Test public void relaysReloadToRegistryDelegate() { FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.reload()).thenReturn(CompletableFuture.completedFuture(ReloadResult.reloaded("relaod ok"))); registry = new FileBackedBackendServicesRegistry(delegate); registry.reload(); @@ -157,6 +179,164 @@ public void monitorsFileChanges() { verify(delegate, times(3)).reload(); } + @Test + public void serviceStarts_logsInfoWhenReloadSucceeds() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()).thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + assertThat(log.log(), hasItem( + loggingEvent(INFO, "Backend services reloaded. reason='Initial load', md5-hash: 9034890345289043, Successfully reloaded, file='/monitored/origins.yml'") + )); + } + + @Test(expectedExceptions = ExecutionException.class, + expectedExceptionsMessageRegExp = "java.lang.RuntimeException: java.lang.RuntimeException: something went wrong") + public void serviceStarts_failsToStartWhenReloadFails() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()).thenReturn( + completedFuture(failed( + "md5-hash: 9034890345289043, Failed to load file", + new RuntimeException("something went wrong")))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + } + + @Test + public void serviceStarts_logsInfoWhenReloadFails() { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()).thenReturn( + completedFuture(failed( + "md5-hash: 9034890345289043, Failed to load file", + new RuntimeException("something went wrong")))); + + registry = new FileBackedBackendServicesRegistry(delegate); + + try { + registry.startService().get(); + } catch (Throwable any) { + // pass + } finally { + assertThat(log.lastMessage(), is( + loggingEvent( + ERROR, + "Backend services reload failed. reason='Initial load', md5-hash: 9034890345289043, Failed to load file, file='/monitored/origins.yml'", + RuntimeException.class, + "something went wrong") + )); + } + } + + @Test + public void reload_logsInfoWhenFileIsUnchanged() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(unchanged("md5-hash: 9034890345289043, No changes detected"))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.reload().get(); + assertThat(log.log(), hasItem( + loggingEvent(INFO, "Backend services reloaded. reason='Admin Interface', md5-hash: 9034890345289043, No changes detected, file='/monitored/origins.yml'") + )); + } + + @Test + public void reload_logsInfoWhenFailsToReadFile() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(failed("md5-hash: 9034890345289043, Failed to load file", new RuntimeException("error occurred")))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.reload().get(); + assertThat(log.log(), hasItem( + loggingEvent(ERROR, "Backend services reload failed. reason='Admin Interface', md5-hash: 9034890345289043, Failed to load file, file='/monitored/origins.yml'", + RuntimeException.class, "error occurred") + )); + } + + @Test + public void reload_logsInfoOnSuccessfulReload() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(reloaded("md5-hash: 3428432789453897, Successfully reloaded"))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.reload().get(); + assertThat(log.log(), hasItem( + loggingEvent(INFO, "Backend services reloaded. reason='Admin Interface', md5-hash: 3428432789453897, Successfully reloaded, file='/monitored/origins.yml'") + )); + } + + @Test + public void fileChanged_logsInfoWhenFileIsUnchanged() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(unchanged("md5-hash: 9034890345289043, Unchanged"))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.fileChanged(); + assertThat(log.lastMessage(), is( + loggingEvent(INFO, "Backend services reloaded. reason='File Monitor', md5-hash: 9034890345289043, Unchanged, file='/monitored/origins.yml'") + )); + } + + @Test + public void fileChanged_logsInfoWhenFailsToReadFile() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(failed("md5-hash: 9034890345289043, Failed to reload", new RuntimeException("something went wrong")))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.fileChanged(); + assertThat(log.lastMessage(), is( + loggingEvent(ERROR, "Backend services reload failed. reason='File Monitor', md5-hash: 9034890345289043, Failed to reload, file='/monitored/origins.yml'", + RuntimeException.class, "something went wrong") + )); + } + + @Test + public void fileChanged_logsInfoOnSuccessfulReload() throws Exception { + FileBackedRegistry delegate = mock(FileBackedRegistry.class); + when(delegate.fileName()).thenReturn("/monitored/origins.yml"); + when(delegate.reload()) + .thenReturn(completedFuture(reloaded("md5-hash: 9034890345289043, Successfully reloaded"))) + .thenReturn(completedFuture(reloaded("md5-hash: 3428432789453897, Successfully reloaded"))); + + registry = new FileBackedBackendServicesRegistry(delegate); + registry.startService().get(); + + registry.fileChanged(); + assertThat(log.lastMessage(), is( + loggingEvent(INFO, "Backend services reloaded. reason='File Monitor', md5-hash: 3428432789453897, Successfully reloaded, file='/monitored/origins.yml'") + )); + } + private CompletableFuture failedFuture(Throwable cause) { CompletableFuture future = new CompletableFuture<>(); future.completeExceptionally(cause); diff --git a/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileChangeMonitorTest.java b/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileChangeMonitorTest.java index a4a6a84e80..b051cda710 100644 --- a/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileChangeMonitorTest.java +++ b/components/proxy/src/test/java/com/hotels/styx/proxy/backends/file/FileChangeMonitorTest.java @@ -16,7 +16,6 @@ package com.hotels.styx.proxy.backends.file; import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import org.testng.annotations.AfterMethod; import org.testng.annotations.BeforeMethod; import org.testng.annotations.Test; @@ -26,6 +25,7 @@ import java.nio.file.Path; import java.nio.file.Paths; +import static ch.qos.logback.classic.Level.INFO; import static com.google.common.io.Files.createTempDir; import static java.lang.String.format; import static java.nio.charset.StandardCharsets.UTF_8; @@ -36,10 +36,11 @@ import static org.mockito.Mockito.mock; import static org.mockito.Mockito.timeout; import static org.mockito.Mockito.verify; +import static org.slf4j.LoggerFactory.getLogger; public class FileChangeMonitorTest { - private static final Logger LOGGER = LoggerFactory.getLogger(FileChangeMonitorTest.class); + private static final Logger LOGGER = getLogger(FileChangeMonitorTest.class); private File tempDir; private Path monitoredFile; @@ -53,10 +54,12 @@ public void setUp() throws Exception { write(monitoredFile, "content-v0"); listener = mock(FileChangeMonitor.Listener.class); monitor = new FileChangeMonitor(monitoredFile.toString(), 250, MILLISECONDS); + ((ch.qos.logback.classic.Logger) getLogger(FileChangeMonitor.class)).setLevel(INFO); } @AfterMethod public void tearDown() throws Exception { + monitor.stop(); try { delete(monitoredFile); } catch (java.nio.file.NoSuchFileException cause) { diff --git a/system-tests/e2e-suite/src/test/resources/conf/logback/logback-debug-stdout.xml b/system-tests/e2e-suite/src/test/resources/conf/logback/logback-debug-stdout.xml index c3e2c41593..05396f81c2 100644 --- a/system-tests/e2e-suite/src/test/resources/conf/logback/logback-debug-stdout.xml +++ b/system-tests/e2e-suite/src/test/resources/conf/logback/logback-debug-stdout.xml @@ -8,6 +8,7 @@ + diff --git a/system-tests/e2e-suite/src/test/resources/conf/logback/logback-suppress-errors.xml b/system-tests/e2e-suite/src/test/resources/conf/logback/logback-suppress-errors.xml index f682a521d8..1daf833224 100644 --- a/system-tests/e2e-suite/src/test/resources/conf/logback/logback-suppress-errors.xml +++ b/system-tests/e2e-suite/src/test/resources/conf/logback/logback-suppress-errors.xml @@ -9,6 +9,7 @@ + diff --git a/system-tests/e2e-suite/src/test/resources/conf/logback/logback.xml b/system-tests/e2e-suite/src/test/resources/conf/logback/logback.xml index efea60bafb..325c357a3b 100644 --- a/system-tests/e2e-suite/src/test/resources/conf/logback/logback.xml +++ b/system-tests/e2e-suite/src/test/resources/conf/logback/logback.xml @@ -8,6 +8,7 @@ + diff --git a/system-tests/e2e-suite/src/test/scala/com/hotels/styx/admin/OriginsReloadCommandSpec.scala b/system-tests/e2e-suite/src/test/scala/com/hotels/styx/admin/OriginsReloadCommandSpec.scala index d85daccc10..2c2d254e9f 100644 --- a/system-tests/e2e-suite/src/test/scala/com/hotels/styx/admin/OriginsReloadCommandSpec.scala +++ b/system-tests/e2e-suite/src/test/scala/com/hotels/styx/admin/OriginsReloadCommandSpec.scala @@ -19,8 +19,8 @@ import java.nio.file.StandardCopyOption.REPLACE_EXISTING import java.nio.file.{Files, Paths} import com.google.common.io.Files.createTempDir -import com.hotels.styx.api.HttpRequest -import com.hotels.styx.api.messages.HttpResponseStatus.BAD_REQUEST +import com.hotels.styx.api.HttpRequest.Builder.post +import com.hotels.styx.api.messages.HttpResponseStatus.INTERNAL_SERVER_ERROR import com.hotels.styx.proxy.backends.file.FileBackedBackendServicesRegistry import com.hotels.styx.support.ResourcePaths.fixturesHome import com.hotels.styx.support.configuration._ @@ -44,7 +44,7 @@ class OriginsReloadCommandSpec extends FunSpec val styxOriginsFile = Paths.get(tempDir.toString, "origins.yml") var styxServer: StyxServer = _ - it("Responds with BAD_REQUEST when the origins cannot be read") { + it("Responds with INTERNAL_SERVER_ERROR when the origins cannot be read") { val fileBasedBackendsRegistry = FileBackedBackendServicesRegistry.create(styxOriginsFile.toString) styxServer = StyxConfig().startServer(fileBasedBackendsRegistry) @@ -52,8 +52,8 @@ class OriginsReloadCommandSpec extends FunSpec Files.copy(originsNok, styxOriginsFile, REPLACE_EXISTING) - val resp = decodedRequest(HttpRequest.Builder.post(styxServer.adminURL("/admin/tasks/origins/reload")).build()) - resp.status() should be(BAD_REQUEST) + val resp = decodedRequest(post(styxServer.adminURL("/admin/tasks/origins/reload")).build()) + resp.status() should be(INTERNAL_SERVER_ERROR) BackendService.fromJava(fileBasedBackendsRegistry.get().asScala.head) should be( BackendService(