feat(expressions): Including expressions errors to show in UI (#1595)

- Merging general exception errors with expression errors when stage completes
- This allows to automatically show all expressions failures in UI
- Including field containing failed expression in error description
- Updated error messaging verbiage

orca-core/src/main/groovy/com/netflix/spinnaker/orca/exceptions/ExceptionHandler.java

@@ -83,7 +83,7 @@ static Map<String, Object> responseDetails(String error) {
   static Map<String, Object> responseDetails(String error, List<String> errors) {
     Map<String, Object> details = new HashMap<>();
     details.put("error", error);
-    details.put("errors", errors == null ? Collections.emptyList() : Collections.unmodifiableList(errors));
+    details.put("errors", errors == null ? Collections.emptyList() : errors);
     return details;
   }
 

orca-core/src/main/groovy/com/netflix/spinnaker/orca/pipeline/expressions/ExpressionEvaluationSummary.java

@@ -27,7 +27,7 @@
  * INFO unresolved value returned that doesn't throw
  */
 public class ExpressionEvaluationSummary {
-  private Map<String, List<Result>> expressionResult;
+  private Map<String, Set<Result>> expressionResult;
   private Set<String> attempts;
   private AtomicInteger failureCount;
   private AtomicInteger totalEvaluated;
@@ -47,12 +47,12 @@ public int getFailureCount() {
     return failureCount.get();
   }
 
-  public Map<String, List<Result>> getExpressionResult() {
+  public Map<String, Set<Result>> getExpressionResult() {
     return expressionResult;
   }
 
   public void add(String escapedExpression, Result.Level level, String description, Class<?> exceptionType) {
-    List<Result> messages = expressionResult.getOrDefault(escapedExpression, new ArrayList<>());
+    Set<Result> messages = expressionResult.getOrDefault(escapedExpression, new HashSet<>());
     messages.add(new Result(level, System.currentTimeMillis(), description, exceptionType));
     expressionResult.put(escapedExpression, messages);
     failureCount.incrementAndGet();
@@ -136,5 +136,25 @@ public String toString() {
         ", level=" + level +
         '}';
     }
+
+    @Override
+    public boolean equals(Object o) {
+      if (this == o) return true;
+      if (o == null || getClass() != o.getClass()) return false;
+
+      Result result = (Result) o;
+
+      return (description != null ? description.equals(result.description) : result.description == null)
+        && (exceptionType != null ? exceptionType.equals(result.exceptionType) : result.exceptionType == null)
+        && level == result.level;
+    }
+
+    @Override
+    public int hashCode() {
+      int result = description != null ? description.hashCode() : 0;
+      result = 31 * result + (exceptionType != null ? exceptionType.hashCode() : 0);
+      result = 31 * result + (level != null ? level.hashCode() : 0);
+      return result;
+    }
   }
 }

orca-core/src/main/groovy/com/netflix/spinnaker/orca/pipeline/expressions/ExpressionTransform.groovy

@@ -23,6 +23,9 @@ import org.springframework.expression.ExpressionParser
 import org.springframework.expression.ParserContext
 import org.springframework.expression.common.CompositeStringExpression
 
+import java.util.stream.Collectors
+import java.util.stream.Stream
+
 @Slf4j
 class ExpressionTransform {
   private static final List<String> EXECUTION_AWARE_FUNCTIONS = ["judgment", "judgement", "stage"]
@@ -42,14 +45,15 @@ class ExpressionTransform {
    * @param summary
    * @return the transformed source object
    */
-  def <T> T transform(T source, EvaluationContext evaluationContext, ExpressionEvaluationSummary summary) {
+  def <T> T transform(T source, EvaluationContext evaluationContext, ExpressionEvaluationSummary summary, Map<String, ?> additionalContext = [:]) {
     if (source == null) {
       return null
     }
 
     if (source instanceof Map) {
+      Map<String, ?> copy = Collections.unmodifiableMap(source)
       source.collectEntries { k, v ->
-        [ transform(k, evaluationContext, summary), transform(v, evaluationContext, summary) ]
+        [ transform(k, evaluationContext, summary, copy), transform(v, evaluationContext, summary, copy) ]
       } as T
     } else if (source instanceof List) {
       source.collect {
@@ -69,13 +73,15 @@ class ExpressionTransform {
         escapedExpressionString = escapeExpression(exp)
         result = exp.getValue(evaluationContext) as T
       } catch (Exception e) {
-        log.info("Failed to resolve $source, returning raw value {}", e.getMessage())
+        log.info("Failed to evaluate $source, returning raw value {}", e.getMessage())
         exception = e
       } finally {
         escapedExpressionString = escapedExpressionString?: escapeSimpleExpression(source as String)
         if (exception) {
+          def fields = getKeys(literalExpression, additionalContext)?: literalExpression
+          String errorDescription = String.format("Failed to evaluate %s ", fields)
           Throwable originalException = unwrapOriginalException(exception)
-          String errorDescription = exception.getMessage() == originalException?.getMessage()?
+          errorDescription += exception.getMessage() in originalException?.getMessage()?
             exception.getMessage() :originalException?.getMessage() + " - " + exception.getMessage()
 
           summary.add(
@@ -87,10 +93,12 @@ class ExpressionTransform {
 
           result = source
         } else if (result == null) {
+          def fields = getKeys(literalExpression, additionalContext)?: literalExpression
+          String errorDescription = String.format("Failed to evaluate %s ", fields)
           summary.add(
             escapedExpressionString,
             ExpressionEvaluationSummary.Result.Level.INFO,
-            "$escapedExpressionString did not resolve, returning raw value. Value not found",
+            "$errorDescription: $escapedExpressionString not found",
             null
           )
 
@@ -107,6 +115,31 @@ class ExpressionTransform {
     }
   }
 
+  /**
+   * finds parent keys by value in a nested map
+   */
+  private static Set<String> getKeys(Object value, final Map<String, ?> map) {
+    if (!map) {
+      return [] as Set
+    }
+
+    return map.entrySet()
+      .findAll { value in flatten(it.value).collect(Collectors.toSet()).flatten() }*.key as Set
+  }
+
+  private static Stream<?> flatten(Object o) {
+    if (o instanceof Map) {
+      Map<?, ?> map = o as Map
+      return (map.keySet() + map.values())
+        .stream()
+        .flatMap {
+          flatten(it)
+        }
+    }
+
+    return Stream.of(o)
+  }
+
   /**
    * Finds the original exception in the exception hierarchy
    */

orca-core/src/main/groovy/com/netflix/spinnaker/orca/pipeline/expressions/ExpressionsSupport.java

@@ -173,7 +173,7 @@ static String toJson(Object o) {
     try {
       String converted = mapper.writeValueAsString(o);
       if (converted!= null && converted.contains(parserContext.getExpressionPrefix())) {
-        throw new SpelHelperFunctionException(String.format("Json string cannot be contained in result %s", o));
+        throw new SpelHelperFunctionException("result for toJson cannot contain an expression");
       }
 
       return converted;

orca-core/src/main/groovy/com/netflix/spinnaker/orca/pipeline/expressions/PipelineExpressionEvaluator.java

@@ -39,6 +39,7 @@ public class PipelineExpressionEvaluator extends ExpressionsSupport implements E
   private static final String SPEL_EVALUATOR = "spelEvaluator";
   private final ExpressionParser parser = new SpelExpressionParser();
   private static String spelEvaluator = V1;
+  public static final String ERROR = "Failed Expression Evaluation";
 
   public interface ExpressionEvaluationVersion {
     String V2 = "v2";

orca-core/src/test/groovy/com/netflix/spinnaker/orca/pipeline/util/v2/ContextParameterProcessorSpec.groovy

@@ -17,7 +17,6 @@
 package com.netflix.spinnaker.orca.pipeline.util.v2
 
 import com.netflix.spinnaker.orca.ExecutionStatus
-import com.netflix.spinnaker.orca.pipeline.expressions.ExpressionEvaluationSummary
 import com.netflix.spinnaker.orca.pipeline.expressions.ExpressionTransform
 import com.netflix.spinnaker.orca.pipeline.expressions.ExpressionsSupport
 import com.netflix.spinnaker.orca.pipeline.expressions.SpelHelperFunctionException
@@ -27,6 +26,8 @@ import org.springframework.expression.spel.SpelEvaluationException
 import spock.lang.Specification
 import spock.lang.Subject
 import spock.lang.Unroll
+
+import static com.netflix.spinnaker.orca.pipeline.expressions.ExpressionEvaluationSummary.Result.*
 import static com.netflix.spinnaker.orca.test.model.ExecutionBuilder.pipeline
 import static com.netflix.spinnaker.orca.test.model.ExecutionBuilder.stage
 
@@ -84,7 +85,7 @@ class ContextParameterProcessorSpec extends Specification {
     then:
     result.test == source.test
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
     summary[escapedExpression][0].timestamp != null
 
     where:
@@ -112,7 +113,7 @@ class ContextParameterProcessorSpec extends Specification {
     then:
     //the failure scenario for this test case is the VM halting...
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
 
     where:
     testCase                                  | desc
@@ -134,7 +135,7 @@ class ContextParameterProcessorSpec extends Specification {
     //ensure we failed to interpret the expression and left it as is
     result.test == source.test
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
     summary[escapedExpression][0].exceptionType == SpelEvaluationException
 
     where:
@@ -157,7 +158,7 @@ class ContextParameterProcessorSpec extends Specification {
     //ensure we failed to interpret the expression and left it as is
     result.test == source.test
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
     summary[escapedExpression][0].exceptionType == SpelEvaluationException
 
     where:
@@ -178,7 +179,7 @@ class ContextParameterProcessorSpec extends Specification {
     then:
     result.test == source.test
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
 
     where:
     testCase  | desc
@@ -227,7 +228,7 @@ class ContextParameterProcessorSpec extends Specification {
     then:
     result.test == sourceValue
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.ERROR.name()
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
 
     where:
     sourceValue = '${new rx.internal.util.RxThreadFactory("").newThread(null).getContextClassLoader().toString()}'
@@ -311,9 +312,8 @@ class ContextParameterProcessorSpec extends Specification {
     then:
     result.deployed == '${deployedServerGroups}'
     summary[escapedExpression].size() == 1
-    summary[escapedExpression][0].level as String == ExpressionEvaluationSummary.Result.Level.INFO.name()
-    summary[escapedExpression][0].description == "deployedServerGroups did not resolve, returning raw value. Value not found"
-
+    summary[escapedExpression][0].level as String == Level.INFO.name()
+    summary[escapedExpression][0].description == "Failed to evaluate [deployed] : deployedServerGroups not found"
 
     where:
     execution = [
@@ -632,9 +632,14 @@ class ContextParameterProcessorSpec extends Specification {
 
     when:
     def result = contextParameterProcessor.processV2(stage.context, ctx, true)
+    def summary = result.expressionEvaluationSummary as Map<String, List>
+    def escapedExpression = escapeExpression('${#toJson(execution)}')
 
     then:
     result.comments == '${#toJson(execution)}'
+    summary.size() == 1
+    summary[escapedExpression][0].level as String == Level.ERROR.name()
+    summary[escapedExpression][0].description.contains("Failed to evaluate [comments] result for toJson cannot contain an expression")
   }
 
   def "can read authenticated user in an execution"() {

orca-queue/src/main/kotlin/com/netflix/spinnaker/orca/q/handler/CompleteStageHandler.kt

@@ -22,8 +22,8 @@ import com.netflix.spinnaker.orca.pipeline.model.Stage
 import com.netflix.spinnaker.orca.pipeline.model.SyntheticStageOwner.STAGE_AFTER
 import com.netflix.spinnaker.orca.pipeline.model.SyntheticStageOwner.STAGE_BEFORE
 import com.netflix.spinnaker.orca.pipeline.persistence.ExecutionRepository
+import com.netflix.spinnaker.orca.pipeline.util.ContextParameterProcessor
 import com.netflix.spinnaker.orca.q.*
-import org.slf4j.LoggerFactory
 import org.springframework.context.ApplicationEventPublisher
 import org.springframework.stereotype.Component
 import java.time.Clock
@@ -33,16 +33,16 @@ class CompleteStageHandler(
   override val queue: Queue,
   override val repository: ExecutionRepository,
   private val publisher: ApplicationEventPublisher,
-  private val clock: Clock
-) : MessageHandler<CompleteStage> {
-
-  private val log = LoggerFactory.getLogger(javaClass)
+  private val clock: Clock,
+  override val contextParameterProcessor: ContextParameterProcessor
+) : MessageHandler<CompleteStage>, ExpressionAware {
 
   override fun handle(message: CompleteStage) {
     message.withStage { stage ->
       if (stage.getStatus() in setOf(RUNNING, NOT_STARTED)) {
         stage.setStatus(message.status)
         stage.setEndTime(clock.millis())
+        stage.includeExpressionEvaluationSummary()
         repository.storeStage(stage)
 
         if (message.status in listOf(SUCCEEDED, FAILED_CONTINUE, SKIPPED)) {

orca-queue/src/main/kotlin/com/netflix/spinnaker/orca/q/handler/ExpressionAware.kt

@@ -16,17 +16,23 @@
 
 package com.netflix.spinnaker.orca.q.handler
 
+import com.netflix.spinnaker.orca.exceptions.ExceptionHandler
+import com.netflix.spinnaker.orca.pipeline.expressions.PipelineExpressionEvaluator
 import com.netflix.spinnaker.orca.pipeline.model.Execution
 import com.netflix.spinnaker.orca.pipeline.model.Pipeline
 import com.netflix.spinnaker.orca.pipeline.model.Stage
 import com.netflix.spinnaker.orca.pipeline.util.ContextParameterProcessor
+import org.slf4j.Logger
+import org.slf4j.LoggerFactory
 
 /**
  * Implemented by handlers that support expression evaluation.
  */
 interface ExpressionAware {
 
   val contextParameterProcessor: ContextParameterProcessor
+  val log: Logger
+    get() = LoggerFactory.getLogger(javaClass)
 
   fun Stage<*>.withMergedContext(): Stage<*> {
     val processed = processEntries(this)
@@ -56,6 +62,28 @@ interface ExpressionAware {
     return this
   }
 
+  fun Stage<*>.includeExpressionEvaluationSummary() {
+    when {
+      PipelineExpressionEvaluator.SUMMARY in this.getContext() ->
+        try {
+          val expressionEvaluationSummary = this.getContext()[PipelineExpressionEvaluator.SUMMARY] as Map<*, *>
+          val evaluationErrors: List<String> = expressionEvaluationSummary.values.flatMap { (it as List<*>).map { (it as Map<*, *>)["description"] as String } }
+          this.getContext()["exception"] = mergedExceptionErrors(this.getContext()["exception"] as Map<*, *>?, evaluationErrors)
+        } catch (e: Exception) {
+          log.error("failed to include expression evaluation error in context", e)
+        }
+    }
+  }
+
+  private fun mergedExceptionErrors(exception: Map<*, *>?, errors: List<String>): Map<*, *> =
+    if (exception == null) {
+      mapOf("details" to ExceptionHandler.responseDetails(PipelineExpressionEvaluator.ERROR, errors))
+    } else {
+      val details = exception["details"] as MutableMap<*, *>? ?: mutableMapOf("details" to mutableMapOf("errors" to mutableListOf<String>()))
+      val mergedErrors: List<*> = (details["errors"] as List<*>? ?: mutableListOf<String>()) + errors
+      mapOf("details" to mapOf("errors" to mergedErrors))
+    }
+
   private fun processEntries(stage: Stage<*>) =
     contextParameterProcessor.process(
       stage.getContext(),

orca-queue/src/main/kotlin/com/netflix/spinnaker/orca/q/handler/RunTaskHandler.kt

@@ -34,8 +34,6 @@ import com.netflix.spinnaker.orca.q.*
 import com.netflix.spinnaker.orca.time.toDuration
 import com.netflix.spinnaker.orca.time.toInstant
 import org.apache.commons.lang.time.DurationFormatUtils
-import org.slf4j.Logger
-import org.slf4j.LoggerFactory.getLogger
 import org.springframework.stereotype.Component
 import java.time.Clock
 import java.time.Duration
@@ -56,8 +54,6 @@ class RunTaskHandler(
   private val registry: Registry
 ) : MessageHandler<RunTask>, ExpressionAware, AuthenticationAware {
 
-  private val log: Logger = getLogger(javaClass)
-
   override fun handle(message: RunTask) {
     message.withTask { stage, taskModel, task ->
       val execution = stage.getExecution()

orca-queue/src/main/kotlin/com/netflix/spinnaker/orca/q/handler/StartStageHandler.kt

@@ -30,7 +30,6 @@ import com.netflix.spinnaker.orca.pipeline.util.ContextParameterProcessor
 import com.netflix.spinnaker.orca.pipeline.util.StageNavigator
 import com.netflix.spinnaker.orca.q.*
 import com.netflix.spinnaker.orca.q.StartStage
-import org.slf4j.LoggerFactory
 import org.springframework.beans.factory.annotation.Value
 import org.springframework.context.ApplicationEventPublisher
 import org.springframework.stereotype.Component
@@ -51,7 +50,6 @@ class StartStageHandler(
   @Value("\${queue.retry.delay.ms:15000}") retryDelayMs: Long
 ) : MessageHandler<StartStage>, StageBuilderAware, ExpressionAware, AuthenticationAware {
 
-  private val log = LoggerFactory.getLogger(javaClass)
   private val retryDelay = Duration.ofMillis(retryDelayMs)
 
   override fun handle(message: StartStage) {