diff --git a/CHANGELOG.md b/CHANGELOG.md index 66dde68a71..046c821368 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -179,6 +179,10 @@ Current are made available. +- [Added mandatory logging for LoadTask errors](https://github.com/yahoo/fili/pull/553) + * Finalized `run()` in `LoadTask` with mandatory logging of exceptions. + * Created mandatory runInner to replace run in all `LoadTask` instances + - [Substitute preflight method wildcard character with explicit allowed methods](https://github.com/yahoo/fili/pull/545) * Modify ResponseCorsFilter Allowed Methods header to explicitly list allowed methods. Some browsers do not support a wildcard header value. diff --git a/fili-core/src/main/java/com/yahoo/bard/webservice/application/DimensionValueLoadTask.java b/fili-core/src/main/java/com/yahoo/bard/webservice/application/DimensionValueLoadTask.java index 09d273884c..85466ed384 100644 --- a/fili-core/src/main/java/com/yahoo/bard/webservice/application/DimensionValueLoadTask.java +++ b/fili-core/src/main/java/com/yahoo/bard/webservice/application/DimensionValueLoadTask.java @@ -59,7 +59,7 @@ public DimensionValueLoadTask(Collection dimensionRowProvi } @Override - public void run() { + public void runInner() { dimensionRowProviders.forEach(DimensionValueLoader::load); // tell all dimensionRowProviders to load lastRunTimestamp.set(DateTime.now()); diff --git a/fili-core/src/main/java/com/yahoo/bard/webservice/application/LoadTask.java b/fili-core/src/main/java/com/yahoo/bard/webservice/application/LoadTask.java index 3348efcce7..3fd451b602 100644 --- a/fili-core/src/main/java/com/yahoo/bard/webservice/application/LoadTask.java +++ b/fili-core/src/main/java/com/yahoo/bard/webservice/application/LoadTask.java @@ -4,6 +4,7 @@ import com.yahoo.bard.webservice.druid.client.FailureCallback; import com.yahoo.bard.webservice.druid.client.HttpErrorCallback; +import com.yahoo.bard.webservice.web.ErrorMessageFormat; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -18,6 +19,7 @@ * @param The type of the result returned by the task associated with this loader. */ public abstract class LoadTask implements Runnable { + private static final Logger LOG = LoggerFactory.getLogger(LoadTask.class); protected final String loaderName; @@ -26,6 +28,8 @@ public abstract class LoadTask implements Runnable { protected final boolean isPeriodic; protected ScheduledFuture future; + private boolean failed = false; + /** * Creates a one-off loader. * @@ -50,8 +54,22 @@ public LoadTask(String loaderName, long delay, long period) { this.isPeriodic = period > 0; } + /** + * Internal implementation of {@link LoadTask#run()} task that will be used so that {@link LoadTask#run()} can + * add mandatory exception handling. + */ + public abstract void runInner(); + @Override - public abstract void run(); + public final void run() { + try { + runInner(); + } catch (RuntimeException t) { + LOG.error(ErrorMessageFormat.LOAD_TASK_FAILURE.logFormat(getName(), t.getMessage()), t); + failed = true; + throw t; + } + }; /** * Return the name of this loader. @@ -157,4 +175,8 @@ public void invoke(Throwable error) { LOG.error("{}: Async request to druid failed:", getName(), error); } } + + public boolean isFailed() { + return failed; + } } diff --git a/fili-core/src/main/java/com/yahoo/bard/webservice/data/dimension/impl/LuceneSearchProvider.java b/fili-core/src/main/java/com/yahoo/bard/webservice/data/dimension/impl/LuceneSearchProvider.java index 43e20f7f27..6c0989f664 100644 --- a/fili-core/src/main/java/com/yahoo/bard/webservice/data/dimension/impl/LuceneSearchProvider.java +++ b/fili-core/src/main/java/com/yahoo/bard/webservice/data/dimension/impl/LuceneSearchProvider.java @@ -458,7 +458,7 @@ public void clearDimension() { writer.deleteAll(); writer.commit(); } catch (IOException e) { - LOG.error(ErrorMessageFormat.FAIL_TO_WIPTE_LUCENE_INDEX_DIR.format(luceneDirectory)); + LOG.error(ErrorMessageFormat.FAIL_TO_WIPE_LUCENE_INDEX_DIR.format(luceneDirectory)); throw new RuntimeException(e); } diff --git a/fili-core/src/main/java/com/yahoo/bard/webservice/metadata/DataSourceMetadataLoadTask.java b/fili-core/src/main/java/com/yahoo/bard/webservice/metadata/DataSourceMetadataLoadTask.java index 1c55a02994..13fa941ad3 100644 --- a/fili-core/src/main/java/com/yahoo/bard/webservice/metadata/DataSourceMetadataLoadTask.java +++ b/fili-core/src/main/java/com/yahoo/bard/webservice/metadata/DataSourceMetadataLoadTask.java @@ -97,7 +97,7 @@ public DataSourceMetadataLoadTask( } @Override - public void run() { + public void runInner() { physicalTableDictionary.values().stream() .map(PhysicalTable::getDataSourceNames) .flatMap(Set::stream) diff --git a/fili-core/src/main/java/com/yahoo/bard/webservice/web/ErrorMessageFormat.java b/fili-core/src/main/java/com/yahoo/bard/webservice/web/ErrorMessageFormat.java index 1fb859852d..d90a6116ca 100644 --- a/fili-core/src/main/java/com/yahoo/bard/webservice/web/ErrorMessageFormat.java +++ b/fili-core/src/main/java/com/yahoo/bard/webservice/web/ErrorMessageFormat.java @@ -261,9 +261,12 @@ public enum ErrorMessageFormat implements MessageFormatter { UNABLE_TO_CREATE_DIR("Unable to create directory %s."), UNABLE_TO_DELETE_DIR("Unable to delete directory %s."), - FAIL_TO_WIPTE_LUCENE_INDEX_DIR("Failed to wipte Lucene index at directory: %s"), - REQUEST_PROCESSING_EXCEPTION("Exception processing request: %s") + FAIL_TO_WIPE_LUCENE_INDEX_DIR("Failed to wipe Lucene index at directory: %s"), + + REQUEST_PROCESSING_EXCEPTION("Exception processing request: %s"), + + LOAD_TASK_FAILURE("Exception while running %s: %s") ; private final String messageFormat; diff --git a/fili-core/src/test/groovy/com/yahoo/bard/webservice/application/LoadTaskSpec.groovy b/fili-core/src/test/groovy/com/yahoo/bard/webservice/application/LoadTaskSpec.groovy index 621e9ef9d9..0cc68c2224 100644 --- a/fili-core/src/test/groovy/com/yahoo/bard/webservice/application/LoadTaskSpec.groovy +++ b/fili-core/src/test/groovy/com/yahoo/bard/webservice/application/LoadTaskSpec.groovy @@ -5,8 +5,10 @@ package com.yahoo.bard.webservice.application import static spock.util.matcher.HamcrestMatchers.closeTo import static spock.util.matcher.HamcrestSupport.expect +import com.yahoo.bard.webservice.data.dimension.TimeoutException import com.yahoo.bard.webservice.druid.client.FailureCallback import com.yahoo.bard.webservice.druid.client.HttpErrorCallback +import com.yahoo.bard.webservice.logging.TestLogAppender import spock.lang.Ignore import spock.lang.Specification @@ -18,6 +20,8 @@ import java.util.concurrent.TimeUnit @Timeout(30) // Fail test if hangs class LoadTaskSpec extends Specification { + TestLogAppender logAppender = new TestLogAppender() + // All times are in millis unless specified otherwise int expectedDelay = 500 int expectedPeriod = 500 @@ -42,7 +46,7 @@ class LoadTaskSpec extends Specification { } @Override - void run() { + void runInner() { start = System.currentTimeMillis() sleep(expectedDuration) end = System.currentTimeMillis() @@ -60,7 +64,7 @@ class LoadTaskSpec extends Specification { } @Override - void run() { + void runInner() { start = System.currentTimeMillis() sleep(expectedDuration) end = System.currentTimeMillis() @@ -231,4 +235,30 @@ class LoadTaskSpec extends Specification { cleanup: scheduler.shutdownNow() } + + class FailingTestLoadTask extends LoadTaskSpec.OneOffTestLoadTask { + + public static final String UNIQUE_VALUE_1 = "FailingTestLoadTask.UNIQUE_VALUE_1" + + FailingTestLoadTask(long delay) { + super(delay) + } + + @Override + void runInner() { + throw new TimeoutException(UNIQUE_VALUE_1); + } + } + + def "Test error gets logged on failed test"() { + setup: "Instantiate a task scheduler" + TaskScheduler scheduler = new TaskScheduler(2) + LoadTask loader = new FailingTestLoadTask(expectedDelay) + loader.setFuture(scheduler.schedule(loader,1, TimeUnit.MILLISECONDS)) + Thread.sleep(10) + + expect: + loader.failed + logAppender.getMessages().find { it.contains(/FailingTestLoadTask.UNIQUE_VALUE_1/) } + } }