logstash Implements safe evaluation of conditional expressions, logging the error without killing the pipeline

Release notes

Fix if statement expression evaluation against runtime errors that could crash the pipeline, just logging the offending event and continuing with the next in the batch.

What does this PR do?

Translates the org.jruby.exceptions.TypeError, IllegalArgumentException, org.jruby.exceptions.ArgumentError that could happen during EventCodition evaluation into a custom ConditionalEvaluationError which bubbles up on AST tree nodes. It's catched in the SplitDataset node. Updates the generation of the SplitDataset so that the execution of filterEvents method inside the compute body is try-catch guarded and defer the execution to an instance of AbstractPipelineExt.ConditionalEvaluationListener to handle such error. In this particular case the error management consist in just logging the offending Event.

Why is it important/What is the impact to the user?

This PR protects the if statements against expression evaluation errors, cancel the event under processing and log it. This avoids to crash the pipeline which encounter a runtime error during event condition evaluation, permitting to debug the root cause reporting the offending event and removing from the current processing batch.

Checklist

[x] My code follows the style guidelines of this project
[x] I have commented my code, particularly in hard-to-understand areas
[x] I have made corresponding changes to the documentation
~~[ ] I have made corresponding change to the default configuration files (and/or docker env variables)~~
[x] I have added tests that prove my fix is effective or that my feature works

Author's Checklist

[x] add test case for #15091

How to test this PR locally

start with small pipeline like

input {
    stdin { codec => json_lines }
}
filter {
  if [path][to][value] > 100 {
    mutate { add_tag => "hit" }
  }
}
output {
  stdout { 
    codec => rubydebug
  }
}

and use the data samples from #16007 2. tinker with ifs also in the output, something like:

input {
    stdin { codec => json_lines }
}

filter {
  if [path][to][value] > 100 {
    mutate { add_tag => "hit" }
  } else {
    mutate { add_tag => "miss" }
  }
  mutate { add_tag => "after"}
}

output {
   if [path][to][value] > 100 {
        stdout {
            codec => rubydebug
        }
   }
}

then verify with batches containing ok and ko data. Add the following input for example:

file {
    path => "/tmp/pipeline_conditional_test_fixture.json"
    sincedb_path => "/tmp/logstash_andsel/sincedb"
    mode => "read"
    file_completed_action => "log"
    file_completed_log_path => "/tmp/processed.log"

    codec => json
}

Using a json file like:

{"path":{"to":{"value":101}}}
{"path":{"to":{"value":102}}}
{"path":{"to":{"value":"101"}}}
{"path":{"to":{"value":103}}}

whatever other test comes to your mind :-)

Related issues

Relates #16007
Closes #15091

Use cases

Screenshots

Logs

Jul 12 '24 09:07 andsel

I believe we're in a good state in regards to catching the error situations but I'd like to improve the wording and content of the errors presented to the user, so there's less "noise". Currently with this PR we show:

[2024-08-14T17:10:47,532][WARN ][org.logstash.execution.AbstractPipelineExt][main] Error in condition evaluation with error org.logstash.config.ir.compiler.EventCondition$Compiler$UnexpectedTypeException: Unexpected input type combination left <no-class>:<null-value>, right class org.jruby.RubyFixnum:100

But if we do:

diff --git a/logstash-core/src/main/java/org/logstash/config/ir/compiler/EventCondition.java b/logstash-core/src/main/java/org/logstash/config/ir/compiler/EventCondition.java
index ab3c867f4..8d5493c9f 100644
--- a/logstash-core/src/main/java/org/logstash/config/ir/compiler/EventCondition.java
+++ b/logstash-core/src/main/java/org/logstash/config/ir/compiler/EventCondition.java
@@ -685,19 +685,19 @@ public interface EventCondition {
             UnexpectedTypeException(final Expression left, final Expression right) {
                 super(
                         String.format(
-                                "Unexpected input types left: %s, right: %s", getUnexpectedTypeDetails(left), getUnexpectedTypeDetails(right)
+                                "Unexpected conditional input combination of \'%s\' (left) and \'%s\' (right)", getUnexpectedTypeDetails(left), getUnexpectedTypeDetails(right)
                         )
                 );
             }
 
             UnexpectedTypeException(final Object inner) {
-                super(String.format("Unexpected input type %s", getUnexpectedTypeDetails(inner)));
+                super(String.format("Unexpected conditional input type \'%s\'", getUnexpectedTypeDetails(inner)));
             }
 
             UnexpectedTypeException(final Object left, final Object right) {
                 super(
                         String.format(
-                                "Unexpected input type combination left %s, right %s", getUnexpectedTypeDetails(left), getUnexpectedTypeDetails(right)
+                                "Unexpected conditional input combination of \'%s\' (left) and \'%s\' (right)", getUnexpectedTypeDetails(left), getUnexpectedTypeDetails(right)
                         )
                 );
             }
diff --git a/logstash-core/src/main/java/org/logstash/execution/AbstractPipelineExt.java b/logstash-core/src/main/java/org/logstash/execution/AbstractPipelineExt.java
index 07c324a3b..0ac584f15 100644
--- a/logstash-core/src/main/java/org/logstash/execution/AbstractPipelineExt.java
+++ b/logstash-core/src/main/java/org/logstash/execution/AbstractPipelineExt.java
@@ -179,8 +179,8 @@ public class AbstractPipelineExt extends RubyBasicObject {
     public final class LogErrorEvaluationListener implements ConditionalEvaluationListener {
         @Override
         public void notify(ConditionalEvaluationError err) {
-            lastErrorEvaluationReceived = err.getMessage();
-            LOGGER.warn("Error in condition evaluation with error {}", lastErrorEvaluationReceived);
+            lastErrorEvaluationReceived = err.getCause().getMessage();
+            LOGGER.warn("{}. Event was dropped, enable debug logging to see the event's payload.", lastErrorEvaluationReceived);
             LOGGER.debug("Event generating the fault: {}", err.failedEvent().toMap().toString());
 
             // logs the exception at debug level

Then we get:

[2024-08-14T17:06:44,651][WARN ][org.logstash.execution.AbstractPipelineExt][main] Unexpected conditional input combination of '<no-class>:<null-value>' (left) and 'class org.jruby.RubyFixnum:100' (right). Event was dropped, enable debug logging to see the event's payload.

I'm not sure if this is an over optimization for this particular kind of exception that impacts others, but I think we should aim at something similar to this.

Aug 14 '24 16:08 jsvd

Finally the biggest elephant in the room is not being able to point to right conditional had the issue. Did you investigate on the effort required to add that? It's not needed for this PR but should be a follow up issue.

Aug 14 '24 16:08 jsvd

Thanks @jsvd for picking up the 🐘 , follow a description of how we can do it, renouncing to little performance (I don't have any data about it, should we observe it?) in compilation.

Short explanation

The IfVertex instance which is used to compile the EventCondition contains the source's metadata that could be used by the filterEvent once the event condition fails to evaluate, but EventCondition-s are cached respect to their Ruby string representation.

Code details

EventCondition compilation is done starting from IfVertex: https://github.com/elastic/logstash/blob/d4519711a692f290c0d9e87401fb5d679f9385ff/logstash-core/src/main/java/org/logstash/config/ir/CompiledPipeline.java#L546

IfVertex exposes source metadata: https://github.com/elastic/logstash/blob/d4519711a692f290c0d9e87401fb5d679f9385ff/logstash-core/src/main/java/org/logstash/config/ir/graph/Vertex.java#L242 which contains the line https://github.com/elastic/logstash/blob/d4519711a692f290c0d9e87401fb5d679f9385ff/logstash-core/src/main/java/org/logstash/common/SourceWithMetadata.java#L52 and file source.

However when an EventCondition is compiled, the compiler uses a cache for precomputed equal conditions. https://github.com/elastic/logstash/blob/d4519711a692f290c0d9e87401fb5d679f9385ff/logstash-core/src/main/java/org/logstash/config/ir/compiler/EventCondition.java#L113

The has a form as (event.getField('[path][to][value]')>'100'), so if same pipeline uses same condition in different locations we can't link the condition with source reference (line, column, file).

If we accept to be little bit slower in compilation, renouncing to the cache, the code reference can be then inserted into the EventCondition, and when the condition eventually fail to evaluate in https://github.com/elastic/logstash/blob/d4519711a692f290c0d9e87401fb5d679f9385ff/logstash-core/src/main/java/org/logstash/config/ir/compiler/Utils.java#L47

Aug 19 '24 10:08 andsel