Implementing mandatory uncaught exception logging on loader tasks.

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.
 

fili-core/src/main/java/com/yahoo/bard/webservice/application/DimensionValueLoadTask.java

@@ -59,7 +59,7 @@ public DimensionValueLoadTask(Collection<DimensionValueLoader> dimensionRowProvi
     }
 
     @Override
-    public void run() {
+    public void runInner() {
         dimensionRowProviders.forEach(DimensionValueLoader::load);
         // tell all dimensionRowProviders to load
         lastRunTimestamp.set(DateTime.now());

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 <V>  The type of the result returned by the task associated with this loader.
  */
 public abstract class LoadTask<V> implements Runnable {
+
     private static final Logger LOG = LoggerFactory.getLogger(LoadTask.class);
 
     protected final String loaderName;
@@ -26,6 +28,8 @@ public abstract class LoadTask<V> 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;
+    }
 }

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);
             }
 

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)

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;

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<Boolean> 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/) }
+    }
 }