runtime-v2: do not log stack trace for EL MethodNotFound exception an…

…d unify the error messages

common/src/main/java/com/walmartlabs/concord/common/ExceptionUtils.java

@@ -9,9 +9,9 @@
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
  * You may obtain a copy of the License at
- * 
+ *
  *      http://www.apache.org/licenses/LICENSE-2.0
- * 
+ *
  * Unless required by applicable law or agreed to in writing, software
  * distributed under the License is distributed on an "AS IS" BASIS,
  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
@@ -36,12 +36,17 @@ public static List<Throwable> getExceptionList(Throwable e) {
     }
 
     @SuppressWarnings("unchecked")
-    public static <T> T filterException(Exception e, Class<T> clazz) {
-        return getExceptionList(e).stream()
-                .filter(clazz::isInstance)
-                .map(c -> (T)c)
-                .findAny()
-                .orElse(null);
+    public static <T extends Throwable> T findLastException(T e, Class<T> clazz) {
+        var exceptions = getExceptionList(e);
+
+        for (int i = exceptions.size() - 1; i >= 0; i--) {
+            var ex = exceptions.get(i);
+            if (clazz.isInstance(ex)) {
+                return (T) ex;
+            }
+        }
+
+        return e;
     }
 
     private ExceptionUtils() {

runtime/v2/runner-test/src/test/java/com/walmartlabs/concord/runtime/v2/runner/LogExceptionsTest.java

@@ -50,7 +50,7 @@ public void shouldLogExceptionStackTraceWhenTaskThrowsException() throws Excepti
         // error
         assertLog(runtime.lastLog(), ".*" + quote("(concord.yaml): Error @ line: 3, col: 7. boom!") + ".*");
         // stacktrace
-        assertLog(runtime.lastLog(), ".*at com.walmartlabs.concord.runtime.v2.runner.LogExceptionsTest.shouldLogExceptionStackTraceWhenTaskThrowsException.*");
+        assertLog(runtime.lastLog(), ".*" + quote("at com.walmartlabs.concord.runtime.v2.runner.tasks.Tasks$FaultyTask2.execute") + ".*");
     }
 
     @Test
@@ -69,9 +69,9 @@ public void shouldLogExceptionStackTraceWhenExpressionThrowsException() throws E
 
         // error
         // TODO: "javax.el.ELException: java.lang.Exception: ..." remove javax.el.ELException?
-        assertLog(runtime.lastLog(), ".*" + quote("Error @ line: 3, col: 7. while evaluating expression '${faultyTask.exception('BOOM')}': javax.el.ELException: java.lang.Exception: BOOM") + ".*");
+        assertLog(runtime.lastLog(), ".*" + quote("Error @ line: 3, col: 7. while evaluating expression '${faultyTask.exception('BOOM')}': BOOM") + ".*");
         // stacktrace
-        assertLog(runtime.lastLog(), ".*at com.walmartlabs.concord.runtime.v2.runner.LogExceptionsTest.shouldLogExceptionStackTraceWhenExpressionThrowsException.*");
+        assertLog(runtime.lastLog(), ".*" + quote("at com.walmartlabs.concord.runtime.v2.runner.tasks.Tasks$FaultyTask") + ".*");
     }
 
     @Test
@@ -134,7 +134,7 @@ public void noStacktraceForUserDefinedExceptionFromExpression() throws Exception
         }
 
         // error
-        assertLog(runtime.lastLog(), ".*" + quote("(concord.yaml): Error @ line: 3, col: 7. BOOM") + ".*");
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${userDefinedExceptionTask.exception('BOOM')}': BOOM") + ".*");
 
         // no single exception message
         assertNoLog(runtime.lastLog(), quote("BOOM"));
@@ -190,4 +190,46 @@ public void noStacktraceForTaskFailReturn() throws Exception {
         assertNoLog(runtime.lastLog(), ".*noStacktraceForTaskFailReturn.*");
         assertNoLog(runtime.lastLog(), ".*" + quote("at com.walmartlabs.concord.runtime.v2.runner.tasks.Tasks$FaultyTask.execute") + ".*");
     }
+
+    @Test
+    public void noStackTraceForMethodNotFound() throws Exception {
+        runtime.deploy("logExceptionTests/methodNotFound");
+
+        runtime.save(ProcessConfiguration.builder()
+                .build());
+
+        try {
+            runtime.run();
+            fail("Exception expected");
+        } catch (Exception e) {
+            // ignore
+        }
+
+        // error
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${faultyTask.unknownMethod('BOOM')}': Can't find 'unknownMethod()' method in com.walmartlabs.concord.runtime.v2.runner.tasks.Tasks$FaultyTask") + ".*");
+
+        // no stacktrace
+        assertNoLog(runtime.lastLog(), ".*" + quote("at com.walmartlabs.concord.runtime.v2.runner.el.LazyExpressionEvaluator.evalExpr") + ".*");
+    }
+
+    @Test
+    public void noStackTraceForVariableNotFound() throws Exception {
+        runtime.deploy("logExceptionTests/variableNotFound");
+
+        runtime.save(ProcessConfiguration.builder()
+                .build());
+
+        try {
+            runtime.run();
+            fail("Exception expected");
+        } catch (Exception e) {
+            // ignore
+        }
+
+        // error
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${unknown}': Can't find a variable 'unknown' used in '${unknown}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'unknown'") + ".*");
+
+        // no stacktrace
+        assertNoLog(runtime.lastLog(), ".*" + quote("at com.walmartlabs.concord.runtime.v2.runner.el.LazyExpressionEvaluator.evalExpr") + ".*");
+    }
 }

runtime/v2/runner-test/src/test/java/com/walmartlabs/concord/runtime/v2/runner/LogSegmentsTest.java

@@ -256,7 +256,7 @@ public void taskOutInvalidTest() throws Exception {
 
         // invalid task out definition -> log into task segment
         assertSegmentLog(runtime.lastLog(), 1, "[INFO ] test");
-        assertSegmentLog(runtime.lastLog(), 1, "[ERROR] (concord.yaml): Error @ line: 3, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSegmentLog(runtime.lastLog(), 1, "[ERROR] (concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
         assertSegmentStatusError(runtime.lastLog(), 1);
 
         assertNoMoreSegments();
@@ -276,7 +276,7 @@ public void taskLoopInvalidTest() throws Exception {
             // ignore
         }
 
-        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
 
         assertNoMoreSegments();
     }
@@ -389,7 +389,7 @@ public void taskWithInvalidName() throws Exception {
             // ignore
         }
 
-        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 4, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 4, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
         assertNoMoreSegments();
     }
 
@@ -431,7 +431,7 @@ public void taskWithRetryInvalid() throws Exception {
         }
 
         // logs to the system segment
-        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
         assertNoMoreSegments();
     }
 
@@ -451,7 +451,7 @@ public void checkpointInvalidTest() throws Exception {
         }
 
         // error into system segment
-        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
     }
 
     @Test
@@ -499,7 +499,7 @@ public void exprInvalidTest() throws Exception {
         }
 
         // error into system segment
-        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. Can't find a variable 'undefined' used in '${undefined}'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
+        assertSystemSegment(runtime.lastLog(), "[ERROR] (concord.yaml): Error @ line: 3, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'");
     }
 
     @Test

runtime/v2/runner-test/src/test/java/com/walmartlabs/concord/runtime/v2/runner/MainTest.java

@@ -1344,7 +1344,7 @@ public void testThrowExpression() throws Exception {
             run();
             fail("exception expected");
         } catch (Exception e) {
-            assertEquals("42 not found", e.getMessage());
+            assertEquals("while evaluating expression '${items.stream().filter(i -> i == 42).findFirst().orElseGet(() -> throw('42 not found'))}': 42 not found", e.getMessage());
         }
     }
 
@@ -1412,7 +1412,7 @@ public void testInvalidExpressionError() throws Exception {
         }
 
         String logString = new String(runtime.lastLog());
-        String expected = "[ERROR] (concord.yml): Error @ line: 9, col: 7. Error Parsing: ${str.split('\\n')}. Encountered \"\\'\\\\n\" at line 1, column 13.\n" +
+        String expected = "[ERROR] (concord.yml): Error @ line: 9, col: 7. while parsing expression '${str.split('\\n')}': Encountered \"\\'\\\\n\" at line 1, column 13.\n" +
                 "Was expecting one of:\n" +
                 "    \"{\" ...\n" +
                 "    <INTEGER_LITERAL> ...\n" +
@@ -1466,7 +1466,7 @@ public void testExpressionThrowUserDefinedError() throws Exception {
         } catch (Exception e) {
             // ignore
         }
-        assertLog(runtime.lastLog(), ".*" + Pattern.quote("[ERROR] (concord.yml): Error @ line: 3, col: 7. BOOM"));
+        assertLog(runtime.lastLog(), ".*" + Pattern.quote("[ERROR] (concord.yml): Error @ line: 3, col: 7. while evaluating expression '${faultyTask.fail('BOOM')}': BOOM"));
     }
 
     @Test
@@ -1483,7 +1483,7 @@ public void testExpressionThrowException() throws Exception {
             // ignore
         }
 
-        String expected = "[ERROR] (concord.yml): Error @ line: 3, col: 7. while evaluating expression '${faultyTask.exception('BOOM')}': javax.el.ELException: java.lang.Exception: BOOM";
+        String expected = "[ERROR] (concord.yml): Error @ line: 3, col: 7. while evaluating expression '${faultyTask.exception('BOOM')}': BOOM";
         assertLog(runtime.lastLog(), ".*" + Pattern.quote(expected));
     }
 
@@ -1517,7 +1517,7 @@ public void testUnresolvedVarInStepName() throws Exception {
         } catch (Exception e) {
         }
 
-        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 4, col: 7. Can't find a variable 'undefined' used in '${undefined}'") + ".*");
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 4, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'") + ".*");
     }
 
     @Test
@@ -1533,7 +1533,7 @@ public void testUnresolvedVarInLoop() throws Exception {
         } catch (Exception e) {
         }
 
-        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 6, col: 7. Can't find a variable 'undefined' used in '${undefined}'") + ".*");
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 6, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'") + ".*");
     }
 
     @Test
@@ -1549,7 +1549,7 @@ public void testUnresolvedVarInRetry() throws Exception {
         } catch (Exception e) {
         }
 
-        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 6, col: 7. Can't find a variable 'undefined' used in '${undefined}'") + ".*");
+        assertLog(runtime.lastLog(), ".*" + quote("(concord.yml): Error @ line: 6, col: 7. while evaluating expression '${undefined}': Can't find a variable 'undefined'. Check if it is defined in the current scope. Details: ELResolver cannot handle a null base Object with identifier 'undefined'") + ".*");
     }
 
     @Test

runtime/v2/runner-test/src/test/resources/com/walmartlabs/concord/runtime/v2/runner/logExceptionTests/methodNotFound/concord.yaml

@@ -0,0 +1,3 @@
+flows:
+  default:
+    - expr: "${faultyTask.unknownMethod('BOOM')}"

runtime/v2/runner-test/src/test/resources/com/walmartlabs/concord/runtime/v2/runner/logExceptionTests/variableNotFound/concord.yaml

@@ -0,0 +1,3 @@
+flows:
+  default:
+    - expr: "${unknown}"

runtime/v2/runner/src/main/java/com/walmartlabs/concord/runtime/v2/runner/el/LazyExpressionEvaluator.java

@@ -27,6 +27,7 @@
 import com.walmartlabs.concord.runtime.v2.runner.el.resolvers.MapELResolver;
 import com.walmartlabs.concord.runtime.v2.runner.el.resolvers.*;
 import com.walmartlabs.concord.runtime.v2.runner.tasks.TaskProviders;
+import com.walmartlabs.concord.runtime.v2.runner.vm.WrappedException;
 import com.walmartlabs.concord.runtime.v2.sdk.*;
 
 import javax.el.*;
@@ -139,8 +140,8 @@ public FunctionMapper getFunctionMapper() {
         };
         sc.putContext(ExpressionFactory.class, expressionFactory);
 
-        ValueExpression x = expressionFactory.createValueExpression(sc, expr, type);
         try {
+            ValueExpression x = expressionFactory.createValueExpression(sc, expr, type);
             Object v = withEvalContext(ctx, () -> x.getValue(sc));
             return type.cast(v);
         } catch (PropertyNotFoundException e) {
@@ -152,20 +153,28 @@ public FunctionMapper getFunctionMapper() {
 
             String propName = propertyNameFromException(e);
             if (propName != null) {
-                errorMessage = String.format("Can't find a variable %s used in '%s'. " +
-                        "Check if it is defined in the current scope. Details: %s", propName, expr, e.getMessage());
+                errorMessage = String.format("Can't find a variable %s. " +
+                        "Check if it is defined in the current scope. Details: %s", propName, e.getMessage());
             } else {
-                errorMessage = String.format("Can't find the specified variable in '%s'. " +
-                        "Check if it is defined in the current scope. Details: %s", expr, e.getMessage());
+                errorMessage = String.format("Can't find the specified variable. " +
+                        "Check if it is defined in the current scope. Details: %s", e.getMessage());
             }
 
-            throw new UserDefinedException(errorMessage);
-        } catch (Exception e) {
-            UserDefinedException u = ExceptionUtils.filterException(e, UserDefinedException.class);
-            if (u != null) {
-                throw u;
+            throw new UserDefinedException(exceptionPrefix(expr) + errorMessage);
+        } catch (UserDefinedException e) {
+            throw new UserDefinedException(exceptionPrefix(expr) + e.getMessage());
+        } catch (javax.el.ELException e) {
+            if (e.getCause() instanceof com.sun.el.parser.ParseException pe) {
+                throw new WrappedException("while parsing expression '" + expr + "': ", pe);
+            }
+
+            var lastElException = ExceptionUtils.findLastException(e, javax.el.ELException.class);
+            if (lastElException.getCause() instanceof Exception ee) {
+                throw new WrappedException(exceptionPrefix(expr), ee);
             }
-            throw new RuntimeException("while evaluating expression '" + expr + "': " + e.getMessage());
+            throw lastElException;
+        } catch (Exception e) {
+            throw new WrappedException(exceptionPrefix(expr), e);
         }
     }
 
@@ -250,6 +259,10 @@ private static Map<String, Object> mergeWithVariables(EvalContext ctx, Map<Strin
         return result;
     }
 
+    private static String exceptionPrefix(String expr) {
+        return "while evaluating expression '" + expr + "': ";
+    }
+
     private static final String PROP_NOT_FOUND_EL_MESSAGE = "ELResolver cannot handle a null base Object with identifier ";
 
     private static String propertyNameFromException(PropertyNotFoundException e) {

runtime/v2/runner/src/main/java/com/walmartlabs/concord/runtime/v2/runner/el/MethodNotFoundException.java

@@ -20,6 +20,7 @@
  * =====
  */
 
+import com.walmartlabs.concord.runtime.v2.sdk.UserDefinedException;
 import org.apache.commons.text.similarity.LevenshteinDistance;
 
 import javax.el.ELException;
@@ -30,7 +31,7 @@
 import java.util.List;
 import java.util.stream.Collectors;
 
-public class MethodNotFoundException extends ELException {
+public class MethodNotFoundException extends UserDefinedException {
 
     private static final long serialVersionUID = 1L;
 

runtime/v2/runner/src/main/java/com/walmartlabs/concord/runtime/v2/runner/el/resolvers/TaskMethodResolver.java

@@ -90,14 +90,12 @@ public Object invoke(ELContext elContext, Object base, Object method, Class<?>[]
                     });
         } catch (javax.el.MethodNotFoundException e) {
             throw new MethodNotFoundException(invocation.taskClass(), method, paramTypes);
-        } catch (javax.el.ELException e) {
-            if (e.getCause() instanceof RuntimeException) {
-                throw (RuntimeException) e.getCause();
-            }
-            throw e;
         } catch (RuntimeException e) {
             throw e;
         } catch (TaskException e) {
+            if (e.getCause() instanceof RuntimeException re) {
+                throw re;
+            }
             throw new RuntimeException(e.getCause());
         } catch (Exception e) {
             throw new RuntimeException(e);

runtime/v2/runner/src/main/java/com/walmartlabs/concord/runtime/v2/runner/tasks/TaskCallInterceptor.java

@@ -30,6 +30,7 @@
 import com.walmartlabs.concord.svm.ThreadId;
 import org.immutables.value.Value;
 
+import javax.el.MethodNotFoundException;
 import javax.inject.Inject;
 import java.io.Serializable;
 import java.lang.annotation.Annotation;
@@ -49,7 +50,7 @@ public TaskCallInterceptor(Set<TaskCallListener> listeners) {
         this.listeners = listeners;
     }
 
-    public <T> T invoke(CallContext ctx, Method method, Callable<T> callable) throws Exception {
+    public <T> T invoke(CallContext ctx, Method method, Callable<T> callable) throws TaskException {
         // record the PRE event
         TaskCallEvent preEvent = eventBuilder(Phase.PRE, method, ctx).build();
         listeners.forEach(l -> l.onEvent(preEvent));
@@ -124,7 +125,7 @@ default List<List<Annotation>> annotations() {
             return Collections.emptyList();
         }
 
-        static Method of(Class<? extends Task> taskClass, String methodName, List<Object> params) {
+        static Method of(Class<? extends Task> taskClass, String methodName, List<Object> params) throws javax.el.MethodNotFoundException {
             List<List<Annotation>> annotations = Collections.emptyList();
             var m = ReflectionUtil.findMethod(taskClass, methodName, null, params.toArray());
             if (m != null && !m.isVarArgs()) {