Implementing mandatory uncaught exception logging on loader tasks.

Author: michael-mclawhorn

CHANGELOG.md

@@ -74,6 +74,11 @@ Current
 
 
 ### Changed:
+
+- [Added mandatory logging for LoadTask errors]
+    * 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

@@ -18,14 +18,18 @@
  * @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);
+    public static final String LOAD_TASK_ERROR_FORMAT = "Exception while running %s: %s";
 
     protected final String loaderName;
     protected final long delay;
     protected final long period;
     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(String.format(LOAD_TASK_ERROR_FORMAT, 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/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/test/groovy/com/yahoo/bard/webservice/application/LoadTaskSpec.groovy

@@ -5,8 +5,12 @@ 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 com.fasterxml.jackson.databind.ObjectMapper
 
 import spock.lang.Ignore
 import spock.lang.Specification
@@ -18,6 +22,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 +48,7 @@ class LoadTaskSpec extends Specification {
         }
 
         @Override
-        void run() {
+        void runInner() {
             start = System.currentTimeMillis()
             sleep(expectedDuration)
             end = System.currentTimeMillis()
@@ -60,7 +66,7 @@ class LoadTaskSpec extends Specification {
         }
 
         @Override
-        void run() {
+        void runInner() {
             start = System.currentTimeMillis()
             sleep(expectedDuration)
             end = System.currentTimeMillis()
@@ -231,4 +237,42 @@ class LoadTaskSpec extends Specification {
         cleanup:
         scheduler.shutdownNow()
     }
+
+    class FailingTestLoadTask extends LoadTaskSpec.OneOffTestLoadTask {
+
+
+        public static final String UNIQUE_VALUE_1 = "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:
+        setup: "Instantiate a task scheduler"
+        ObjectMapper MAPPER = new ObjectMappersSuite().getMapper()
+
+
+        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(/UNIQUE_VALUE_1/) }
+    }
 }