Logstash: 6.4.2 and Java Execution

[simmel]

• Version: 6.4.2
• Operating System: Debian stretch
• Java version:

java version "1.8.0_152"
Java(TM) SE Runtime Environment (build 1.8.0_152-b16)
Java HotSpot(TM) 64-Bit Server VM (build 25.152-b16, mixed mode)

I also tried:

java version "1.8.0_191"
Java(TM) SE Runtime Environment (build 1.8.0_191-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.191-b12, mixed mode)

• Config File (if you have sensitive info, please remove it):

input {
  generator {
    count => 1
  }
}

filter {
  mutate {
    add_field => {
      "program" => "first"
    }
  }

  mutate {
    add_field => {
      "program" => "second"
    }
  }

  if [program] == "sshd" {
    mutate {
      add_tag => ["doesnotmatter"]
    }
  }
}

output {
  stdout {}
}

• Sample Data: See config file generator input
• Steps to Reproduce:
  I can't reproduce this on my OS X with Java 1.8.0_181.

Disabling Java Execution (well rather, not enabling it) works.

But enabling Java execution I get this exception:

$ ~/scm/sua-syslog-event/logstash-6.4.2/bin/logstash -f '~/test/10071.conf' --experimental-java-execution
Sending Logstash logs to /Users/simlu/scm/sua-syslog-event/logstash-6.4.2/logs which is now configured via log4j2.properties
[2018-10-25T15:04:46,811][WARN ][logstash.config.source.multilocal] Ignoring the 'pipelines.yml' file because modules or command line options are specified
[2018-10-25T15:04:47,560][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"6.4.2"}
[2018-10-25T15:04:51,638][INFO ][logstash.javapipeline    ] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50, "pipeline.max_inflight"=>500, :thread=>"#<Thread:0x76c15f run>"}
[2018-10-25T15:04:51,709][INFO ][logstash.javapipeline    ] Pipeline started {"pipeline.id"=>"main"}
[2018-10-25T15:04:51,834][INFO ][logstash.agent           ] Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>[]}
[2018-10-25T15:04:52,355][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
[2018-10-25T15:04:54,291][ERROR][org.logstash.execution.WorkerLoop] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash.
java.lang.ClassCastException: org.logstash.ConvertedList cannot be cast to org.jruby.runtime.builtin.IRubyObject
        at org.logstash.config.ir.compiler.EventCondition$Compiler.lambda$rubyFieldEquals$12(EventCondition.java:436) ~[logstash-core.jar:?]
        at org.logstash.generated.CompiledDataset2.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset3.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset4.compute(Unknown Source) ~[?:?]
        at org.logstash.execution.WorkerLoop.run(WorkerLoop.java:64) [logstash-core.jar:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_181]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_181]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_181]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_181]
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:423) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:290) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:28) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:90) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:145) [jruby-complete-9.1.13.0.jar:?]
        at Users.simlu.scm.sua_minus_syslog_minus_event.logstash_minus_6_dot_4_dot_2.logstash_minus_core.lib.logstash.java_pipeline.RUBY$block$start_workers$2(/Users/simlu/scm/sua-syslog-event/logstash-6.4.2/logstash-core/lib/logstash/java_pipeline.rb:219) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:145) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:71) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.runtime.Block.call(Block.java:124) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.RubyProc.call(RubyProc.java:289) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.RubyProc.call(RubyProc.java:246) [jruby-complete-9.1.13.0.jar:?]
        at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:104) [jruby-complete-9.1.13.0.jar:?]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181]
Exception in thread "Ruby-0-Thread-4: :1" java.lang.IllegalStateException: java.lang.ClassCastException: org.logstash.ConvertedList cannot be cast to org.jruby.runtime.builtin.IRubyObject
        at org.logstash.execution.WorkerLoop.run(org/logstash/execution/WorkerLoop.java:85)
        at java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:498)
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:423)
        at org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:290)
        at Users.simlu.scm.sua_minus_syslog_minus_event.logstash_minus_6_dot_4_dot_2.logstash_minus_core.lib.logstash.java_pipeline.block in start_workers(/Users/simlu/scm/sua-syslog-event/logstash-6.4.2/logstash-core/lib/logstash/java_pipeline.rb:219)
        at org.jruby.RubyProc.call(org/jruby/RubyProc.java:289)
        at org.jruby.RubyProc.call(org/jruby/RubyProc.java:246)
        at java.lang.Thread.run(java/lang/Thread.java:748)
Caused by: java.lang.ClassCastException: org.logstash.ConvertedList cannot be cast to org.jruby.runtime.builtin.IRubyObject
        at org.logstash.config.ir.compiler.EventCondition$Compiler.lambda$rubyFieldEquals$12(EventCondition.java:436)
        at org.logstash.generated.CompiledDataset2.compute(Unknown Source)
        at org.logstash.generated.CompiledDataset3.compute(Unknown Source)
        at org.logstash.generated.CompiledDataset4.compute(Unknown Source)
        at org.logstash.execution.WorkerLoop.run(WorkerLoop.java:64)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:423)
        at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:290)
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:28)
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:90)
        at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:145)
        at Users.simlu.scm.sua_minus_syslog_minus_event.logstash_minus_6_dot_4_dot_2.logstash_minus_core.lib.logstash.java_pipeline.RUBY$block$start_workers$2(/Users/simlu/scm/sua-syslog-event/logstash-6.4.2/logstash-core/lib/logstash/java_pipeline.rb:219)
        at org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:145)
        at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:71)
        at org.jruby.runtime.Block.call(Block.java:124)
        at org.jruby.RubyProc.call(RubyProc.java:289)
        at org.jruby.RubyProc.call(RubyProc.java:246)
        at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:104)
        at java.lang.Thread.run(Thread.java:748)
[2018-10-25T15:04:55,131][INFO ][logstash.javapipeline    ] Pipeline terminated {"pipeline.id"=>"main"}

I'm tagging #9226

[simmel]

I'm trying to narrow it down to some specific config and/or a specific log event right now.

[simmel]

Finally I've narrowed it down!

Looks like Java exec conditionals doesn't handle arrays anymore. In my config above program is an array and has two values: first and second.

[danhermann]

@simmel, thanks for your detailed bug report. I've got a PR out to fix this one.

[simmel]

Thanks for the quick fix @danhermann ! Makes my 5h debugging, reducing our ~1.8k LoC ruleset and 225M lines of log down to those 30 LoC feel a lot better = ) Have a great weekend!