Merge pull request #1518 from NASA-AMMOS/feature/sim_error_stacktrace

Include the Sim Error Activity Type Stack trace

e2e-tests/src/test/java/gov/nasa/jpl/aerie/e2e/SimulationTests.java

@@ -469,8 +469,13 @@ void directiveIdIncluded() throws IOException {
       final var exception = reason.data();
 
       // The error includes the directive id that was executing
+      // and the executing activity type and stack trace
       assertTrue(exception.containsKey("executingDirectiveId"));
+      assertTrue(exception.containsKey("executingActivityType"));
       assertEquals(dirId, exception.getInt("executingDirectiveId"));
+      assertEquals("DaemonCheckerActivity", exception.getString("executingActivityType"));
+      assertTrue(exception.containsKey("activityStackTrace"));
+      assertEquals("DaemonCheckerActivity", exception.getString("activityStackTrace"));
 
       // The error message is correct
       assertEquals("Minutes elapsed is incorrect. TimeTrackerDaemon may have stopped.\n\tExpected: 1 Actual: 59",
@@ -496,7 +501,7 @@ void directiveIdOnDescendant() throws IOException {
       // Setup: Insert a directive that will throw
       int dirId = hasura.insertActivity(
           fooPlan,
-          "DaemonCheckerSpawner",
+          "DaemonTaskActivity",
           "01:00:00",
           Json.createObjectBuilder().add("minutesElapsed", 1).add("spawnDelay", 1).build());
 
@@ -512,21 +517,29 @@ void directiveIdOnDescendant() throws IOException {
       final var exception = reason.data();
 
       // The error includes the directive id that was executing
+      // and the executing activity type and stack trace
       assertTrue(exception.containsKey("executingDirectiveId"));
       assertEquals(dirId, exception.getInt("executingDirectiveId"));
+      assertTrue(exception.containsKey("executingActivityType"));
+      assertEquals(dirId, exception.getInt("executingDirectiveId"));
+      assertEquals("DaemonTaskActivity", exception.getString("executingActivityType"));
+      assertTrue(exception.containsKey("activityStackTrace"));
+      assertEquals("DaemonTaskActivity\n"
+                   + "|-DaemonCheckerSpawner\n"
+                   + "|--DaemonCheckerActivity", exception.getString("activityStackTrace"));
 
       // The error message is correct
-      assertEquals("Minutes elapsed is incorrect. TimeTrackerDaemon may have stopped.\n\tExpected: 1 Actual: 60",
+      assertEquals("Minutes elapsed is incorrect. TimeTrackerDaemon may have stopped.\n\tExpected: 1 Actual: 61",
                    reason.message());
 
       // The error was thrown at the correct time
       assertTrue(exception.containsKey("utcTimeDoy"));
-      assertEquals("2023-001T01:01:00", exception.getString("utcTimeDoy"));
+      assertEquals("2023-001T01:02:00", exception.getString("utcTimeDoy"));
 
       // The trace starts at the original exception and doesn't include the intermediary SpanException and SimulationException
       final var expectedStart = """
           java.lang.RuntimeException: Minutes elapsed is incorrect. TimeTrackerDaemon may have stopped.
-          \tExpected: 1 Actual: 60
+          \tExpected: 1 Actual: 61
           \tat gov.nasa.jpl.aerie.foomissionmodel.activities.DaemonCheckerActivity.run(DaemonCheckerActivity.java""";
       assertTrue(reason.trace().startsWith(expectedStart));
     }
@@ -551,8 +564,11 @@ void noDirectiveIdOnDaemon() throws IOException {
 
       final var exception = reason.data();
 
-      // The error does not include any directive ids
+      // The error does not include any directive ids,
+      // executingActivityType, and activityStackTrace
       assertFalse(exception.containsKey("executingDirectiveId"));
+      assertFalse(exception.containsKey("executingActivityType"));
+      assertFalse(exception.containsKey("activityStackTrace"));
 
       // The error message is correct
       assertEquals("Daemon task exception raised.", reason.message());
@@ -594,8 +610,11 @@ void noDirectiveIdDaemonMidDirective() throws IOException {
 
       final var exception = reason.data();
 
-      // The error does not include any directive ids
+      // The error does not include any directive ids,
+      // executingActivityType, and activityStackTrace
       assertFalse(exception.containsKey("executingDirectiveId"));
+      assertFalse(exception.containsKey("executingActivityType"));
+      assertFalse(exception.containsKey("activityStackTrace"));
 
       // The error message is correct
       assertEquals("Daemon task exception raised.", reason.message());

examples/foo-missionmodel/src/main/java/gov/nasa/jpl/aerie/foomissionmodel/activities/DaemonTaskActivity.java

@@ -0,0 +1,25 @@
+package gov.nasa.jpl.aerie.foomissionmodel.activities;
+
+import gov.nasa.jpl.aerie.foomissionmodel.Mission;
+import gov.nasa.jpl.aerie.merlin.framework.annotations.ActivityType;
+import gov.nasa.jpl.aerie.merlin.protocol.types.Duration;
+
+import static gov.nasa.jpl.aerie.foomissionmodel.generated.ActivityActions.call;
+import static gov.nasa.jpl.aerie.merlin.framework.ModelActions.delay;
+
+/**
+ * An activity that spawns a DaemonCheckerSpawner which spawns a DaemonCheckerActivity after delaying.
+ * Useful for testing the behavior of exceptions thrown by child activities and the stack trace back
+ * to this activity.
+ *
+ * @param minutesElapsed The expected number of minutes elapsed when the DaemonCheckerActivity begins
+ * @param spawnDelay The number of minutes to delay between the start of this activity and spawning the DaemonCheckerActivity
+ */
+@ActivityType("DaemonTaskActivity")
+public record DaemonTaskActivity(int minutesElapsed, int spawnDelay) {
+  @ActivityType.EffectModel
+  public void run(final Mission mission) {
+    delay(Duration.of(spawnDelay, Duration.MINUTE));
+    call(mission, new DaemonCheckerSpawner(minutesElapsed,spawnDelay));
+  }
+}

examples/foo-missionmodel/src/main/java/gov/nasa/jpl/aerie/foomissionmodel/package-info.java

@@ -16,6 +16,7 @@
 @WithActivityType(ZeroDurationUncontrollableActivity.class)
 @WithActivityType(DaemonCheckerActivity.class)
 @WithActivityType(DaemonCheckerSpawner.class)
+@WithActivityType(DaemonTaskActivity.class)
 
 @WithActivityType(DecompositionTestActivities.ParentActivity.class)
 @WithActivityType(DecompositionTestActivities.ChildActivity.class)
@@ -30,6 +31,7 @@
 import gov.nasa.jpl.aerie.foomissionmodel.activities.ControllableDurationActivity;
 import gov.nasa.jpl.aerie.foomissionmodel.activities.DaemonCheckerActivity;
 import gov.nasa.jpl.aerie.foomissionmodel.activities.DaemonCheckerSpawner;
+import gov.nasa.jpl.aerie.foomissionmodel.activities.DaemonTaskActivity;
 import gov.nasa.jpl.aerie.foomissionmodel.activities.DecompositionTestActivities;
 import gov.nasa.jpl.aerie.foomissionmodel.activities.FooActivity;
 import gov.nasa.jpl.aerie.foomissionmodel.activities.LateRiserActivity;

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/CachedSimulationEngine.java

@@ -40,9 +40,14 @@ public static CachedSimulationEngine empty(final MissionModel<?> missionModel, f
     } catch (SpanException ex) {
       // Swallowing the spanException as the internal `spanId` is not user meaningful info.
       final var topics = missionModel.getTopics();
-      final var directiveId = engine.getDirectiveIdFromSpan(activityTopic, topics, ex.spanId);
-      if (directiveId.isPresent()) {
-        throw new SimulationException(Duration.ZERO, simulationStartTime, directiveId.get(), ex.cause);
+      final var directiveDetail = engine.getDirectiveDetailsFromSpan(activityTopic, topics, ex.spanId);
+      if (directiveDetail.directiveId().isPresent()) {
+        throw new SimulationException(
+            Duration.ZERO,
+            simulationStartTime,
+            directiveDetail.directiveId().get(),
+            directiveDetail.activityStackTrace(),
+            ex.cause);
       }
       throw new SimulationException(Duration.ZERO, simulationStartTime, ex.cause);
     } catch (Throwable ex) {

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/CheckpointSimulationDriver.java

@@ -305,9 +305,14 @@ public static <Model> SimulationResultsComputerInputs simulateWithCheckpoints(
       elapsedTime = engine.getElapsedTime();
       // Swallowing the spanException as the internal `spanId` is not user meaningful info.
       final var topics = missionModel.getTopics();
-      final var directiveId = engine.getDirectiveIdFromSpan(activityTopic, topics, ex.spanId);
-      if (directiveId.isPresent()) {
-        throw new SimulationException(elapsedTime, simulationStartTime, directiveId.get(), ex.cause);
+      final var directiveDetail = engine.getDirectiveDetailsFromSpan(activityTopic, topics, ex.spanId);
+      if (directiveDetail.directiveId().isPresent()) {
+        throw new SimulationException(
+            elapsedTime,
+            simulationStartTime,
+            directiveDetail.directiveId().get(),
+            directiveDetail.activityStackTrace(),
+            ex.cause);
       }
       throw new SimulationException(elapsedTime, simulationStartTime, ex.cause);
     } catch (Throwable ex) {

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/SimulationDriver.java

@@ -109,9 +109,14 @@ public static <Model> SimulationResults simulate(
       } catch (SpanException ex) {
         // Swallowing the spanException as the internal `spanId` is not user meaningful info.
         final var topics = missionModel.getTopics();
-        final var directiveId = engine.getDirectiveIdFromSpan(activityTopic, topics, ex.spanId);
-        if(directiveId.isPresent()) {
-          throw new SimulationException(engine.getElapsedTime(), simulationStartTime, directiveId.get(), ex.cause);
+        final var directiveDetail = engine.getDirectiveDetailsFromSpan(activityTopic, topics, ex.spanId);
+        if(directiveDetail.directiveId().isPresent()) {
+          throw new SimulationException(
+              engine.getElapsedTime(),
+              simulationStartTime,
+              directiveDetail.directiveId().get(),
+              directiveDetail.activityStackTrace(),
+              ex.cause);
         }
         throw new SimulationException(engine.getElapsedTime(), simulationStartTime, ex.cause);
       } catch (Throwable ex) {

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/SimulationException.java

@@ -7,7 +7,9 @@
 import java.time.format.DateTimeFormatter;
 import java.time.format.DateTimeFormatterBuilder;
 import java.time.temporal.ChronoField;
+import java.util.List;
 import java.util.Optional;
+import java.util.stream.Collectors;
 
 import static gov.nasa.jpl.aerie.merlin.protocol.types.Duration.HOUR;
 import static gov.nasa.jpl.aerie.merlin.protocol.types.Duration.MICROSECOND;
@@ -28,20 +30,34 @@ public class SimulationException extends RuntimeException {
   public final Instant instant;
   public final Throwable cause;
   public final Optional<ActivityDirectiveId> directiveId;
+  public final Optional<String> activityType;
+  public final Optional<String> activityStackTrace;
 
   public SimulationException(final Duration elapsedTime, final Instant startTime, final Throwable cause) {
     super("Exception occurred " + formatDuration(elapsedTime) + " into the simulation at " + formatInstant(addDurationToInstant(startTime, elapsedTime)), cause);
     this.directiveId = Optional.empty();
+    this.activityType = Optional.empty();
+    this.activityStackTrace = Optional.empty();
     this.elapsedTime = elapsedTime;
     this.instant = addDurationToInstant(startTime, elapsedTime);
     this.cause = cause;
   }
 
-  public SimulationException(final Duration elapsedTime, final Instant startTime, final ActivityDirectiveId directiveId, final Throwable cause) {
+  public SimulationException(
+      final Duration elapsedTime,
+      final Instant startTime,
+      final ActivityDirectiveId directiveId,
+      final List<SerializedActivity> activityStackTrace,
+      final Throwable cause) {
     super("Exception occurred " + formatDuration(elapsedTime)
             + " into the simulation at " + formatInstant(addDurationToInstant(startTime, elapsedTime))
             + " while simulating activity directive with id " +directiveId.id(), cause);
     this.directiveId = Optional.of(directiveId);
+    this.activityType = activityStackTrace.isEmpty() ? Optional.empty() : Optional.of(activityStackTrace.getFirst().getTypeName());
+    this.activityStackTrace = activityStackTrace.isEmpty() ? Optional.empty(): Optional.of(activityStackTrace.stream().map( serializedActivity -> {
+        final var index = activityStackTrace.indexOf(serializedActivity);
+        return (index > 0 ? "|" : "") +"-".repeat(index) + serializedActivity.getTypeName();
+      }).collect(Collectors.joining("\n")));
     this.elapsedTime = elapsedTime;
     this.instant = addDurationToInstant(startTime, elapsedTime);
     this.cause = cause;

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/engine/DirectiveDetail.java

@@ -0,0 +1,10 @@
+package gov.nasa.jpl.aerie.merlin.driver.engine;
+
+import gov.nasa.jpl.aerie.merlin.driver.ActivityDirectiveId;
+import gov.nasa.jpl.aerie.merlin.driver.SerializedActivity;
+import gov.nasa.jpl.aerie.merlin.protocol.types.SerializedValue;
+
+import java.util.List;
+import java.util.Optional;
+
+public record DirectiveDetail(Optional<ActivityDirectiveId> directiveId, List<SerializedActivity> activityStackTrace) {}

merlin-driver/src/main/java/gov/nasa/jpl/aerie/merlin/driver/engine/SimulationEngine.java

@@ -53,6 +53,7 @@
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.function.Consumer;
+import java.util.stream.Collectors;
 
 /**
  * A representation of the work remaining to do during a simulation, and its accumulated results.
@@ -676,29 +677,36 @@ void extractOutput(final SerializableTopic<T> topic, final Event ev, final SpanI
     }
   }
 
+
   /**
    * Get an Activity Directive Id from a SpanId, if the span is a descendent of a directive.
    */
-  public Optional<ActivityDirectiveId> getDirectiveIdFromSpan(
+  public DirectiveDetail getDirectiveDetailsFromSpan(
       final Topic<ActivityDirectiveId> activityTopic,
       final Iterable<SerializableTopic<?>> serializableTopics,
       final SpanId spanId
   ) {
     // Collect per-span information from the event graph.
-    final var spanInfo = new SpanInfo();
-    for (final var point : this.timeline) {
-      if (!(point instanceof TemporalEventSource.TimePoint.Commit p)) continue;
-
-      final var trait = new SpanInfo.Trait(serializableTopics, activityTopic);
-      p.events().evaluate(trait, trait::atom).accept(spanInfo);
-    }
+    final var spanInfo = computeSpanInfo(activityTopic, serializableTopics, this.timeline);
 
-    // Identify the nearest ancestor directive
+    // Identify the nearest ancestor directive by walking up the parent
+    // span tree. Save the activity trace along the way
     Optional<SpanId> directiveSpanId = Optional.of(spanId);
+    final var activityStackTrace = new LinkedList<SerializedActivity>();
     while (directiveSpanId.isPresent() && !spanInfo.isDirective(directiveSpanId.get())) {
+      activityStackTrace.add(spanInfo.input().get(directiveSpanId.get()));
       directiveSpanId = this.getSpan(directiveSpanId.get()).parent();
     }
-    return directiveSpanId.map(spanInfo::getDirective);
+
+    // Add final top level parent activity to the stack trace if present
+    if (directiveSpanId.isPresent()) {
+      activityStackTrace.add(spanInfo.input().get(directiveSpanId.get()));
+    }
+
+    return new DirectiveDetail(
+        directiveSpanId.map(spanInfo::getDirective),
+        // remove null activities from the stack trace and reverse order
+        activityStackTrace.stream().filter(a -> a != null).collect(Collectors.toList()).reversed());
   }
 
   public record SimulationActivityExtract(

merlin-server/src/main/java/gov/nasa/jpl/aerie/merlin/server/services/SimulationAgent.java

@@ -97,6 +97,8 @@ public void simulate(
                                       .add("elapsedTime", SimulationException.formatDuration(ex.elapsedTime))
                                       .add("utcTimeDoy", SimulationException.formatInstant(ex.instant));
       ex.directiveId.ifPresent(directiveId -> errorMsgBuilder.add("executingDirectiveId", directiveId.id()));
+      ex.activityType.ifPresent(activityType -> errorMsgBuilder.add("executingActivityType", activityType));
+      ex.activityStackTrace.ifPresent(activityStackTrace -> errorMsgBuilder.add("activityStackTrace", activityStackTrace));
       writer.failWith(b -> b
           .type("SIMULATION_EXCEPTION")
           .message(ex.cause.getMessage())