Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Empty field references cause ArrayIndexOutOfBoundsException #8823

Closed
jakelandis opened this issue Dec 11, 2017 · 5 comments

Comments

Projects
None yet
4 participants
@jakelandis
Copy link
Contributor

commented Dec 11, 2017

Calling FieldReference.from("") will result in :

java.lang.ArrayIndexOutOfBoundsException: -1

	at java.util.ArrayList.elementData(ArrayList.java:418)
	at java.util.ArrayList.remove(ArrayList.java:495)
	at org.logstash.FieldReference.parse(FieldReference.java:165)
	at org.logstash.FieldReference.parseToCache(FieldReference.java:152)
	at org.logstash.FieldReference.from(FieldReference.java:84)
	at org.logstash.FieldReferenceTest.testParseEmptyString(FieldReferenceTest.java:46)
	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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
	at com.intellij.rt.execution.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:47)
	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:242)
	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:70)

This can happen if used with the JSON filter and the JSON has an empty string for a value.

For example

input {
	stdin {
	}
}

filter {
    json {
         source => "message"
    }
} 
output {
	stdout { codec => rubydebug }
}

With input (which is valid JSON):

{"Production number":"12345678","":""}

Results in

Exception in thread "Ruby-0-Thread-14@[main]>worker6: /Users/jake/workspace/logstash/logstash-core/lib/logstash/pipeline.rb:392" java.lang.ArrayIndexOutOfBoundsException: -1
	at java.util.ArrayList.elementData(ArrayList.java:418)
	at java.util.ArrayList.remove(ArrayList.java:495)
	at org.logstash.FieldReference.parse(FieldReference.java:165)
	at org.logstash.FieldReference.parseToCache(FieldReference.java:152)
	at org.logstash.FieldReference.from(FieldReference.java:84)
	at org.logstash.ext.JrubyEventExtLibrary$RubyEvent.ruby_set_field(JrubyEventExtLibrary.java:88)
	at org.logstash.ext.JrubyEventExtLibrary$RubyEvent$INVOKER$i$2$0$ruby_set_field.call(JrubyEventExtLibrary$RubyEvent$INVOKER$i$2$0$ruby_set_field.gen)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:323)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
	at org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
	at org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:186)
	at org.jruby.runtime.BlockBody.yield(BlockBody.java:116)
	at org.jruby.runtime.Block.yield(Block.java:165)
	at org.jruby.RubyHash$12.visit(RubyHash.java:1362)
	at org.jruby.RubyHash$12.visit(RubyHash.java:1359)
	at org.jruby.RubyHash.visitLimited(RubyHash.java:662)
	at org.jruby.RubyHash.visitAll(RubyHash.java:647)
	at org.jruby.RubyHash.iteratorVisitAll(RubyHash.java:1319)
	at org.jruby.RubyHash.each_pairCommon(RubyHash.java:1354)
	at org.jruby.RubyHash.each(RubyHash.java:1343)
	at org.jruby.RubyHash$INVOKER$i$0$0$each.call(RubyHash$INVOKER$i$0$0$each.gen)
	at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:498)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:298)
	at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:428)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:355)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:83)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:348)
	at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:173)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:332)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:83)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:348)
	at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:173)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:332)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
	at org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
	at org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:186)
	at org.jruby.runtime.BlockBody.yield(BlockBody.java:116)
	at org.jruby.runtime.Block.yield(Block.java:165)
	at org.jruby.RubyArray.each(RubyArray.java:1734)
	at org.jruby.RubyArray$INVOKER$i$0$0$each.call(RubyArray$INVOKER$i$0$0$each.gen)
	at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:498)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:298)
	at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:79)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:428)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:355)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:83)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:338)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:314)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:83)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:338)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:314)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
	at org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
	at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:73)
	at org.jruby.runtime.Block.call(Block.java:124)
	at org.jruby.RubyProc.call(RubyProc.java:289)
	at org.jruby.internal.runtime.methods.ProcMethod.call(ProcMethod.java:63)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:204)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:338)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:314)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:83)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:179)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:165)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:338)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:163)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:314)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:89)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:214)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:200)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:208)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:323)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:73)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:132)
	at org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:148)
	at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:73)
	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)

@colinsurprenant

This comment has been minimized.

Copy link
Contributor

commented Dec 11, 2017

testing with stdin+json_lines produces a json parse error:

$ bin/logstash -e 'input { stdin { codec => json_lines } } output { stdout { codec => rubydebug } }'
...
{"Production number":"12345678","":""}

[2017-12-11T11:53:49,376][WARN ][logstash.codecs.jsonlines] JSON parse error, original data now in message field {:error=>#<LogStash::Json::ParserError: -1>, :data=>"{\"Production number\":\"12345678\",\"\":\"\"}"}
{
       "message" => "{\"Production number\":\"12345678\",\"\":\"\"}",
      "@version" => "1",
          "host" => "mbp15r",
          "tags" => [
        [0] "_jsonparsefailure"
    ],
    "@timestamp" => 2017-12-11T16:53:49.378Z
}
@colinsurprenant

This comment has been minimized.

Copy link
Contributor

commented Dec 11, 2017

but all json validators do report {"Production number":"12345678","":""} as valid json in fact.

@jakelandis

This comment has been minimized.

Copy link
Contributor Author

commented Dec 11, 2017

@colinsurprenant - Agreed. I logged an issue to the json codec: logstash-plugins/logstash-codec-json#35

This issue only applies to the ArrayIndexOutOfBoundsException, and one (of possibly many) way to get there is via the JSON filter with an empty string key.

@jordansissel

This comment has been minimized.

Copy link
Contributor

commented Dec 28, 2017

I'm not sure this is fixed? Maybe not related --

#8824 was merged into 6.1 and landed in v6.1.1 (per git tags)

but:

% bin/logstash -e 'input { stdin { codec => json } }'
{ "": "test" }
[2017-12-23T11:19:29,059][WARN ][logstash.codecs.jsonlines] JSON parse error, original data now in message field {:error=>#<LogStash::Json::ParserError: -1>, :data=>"{ \"\": \"test\" }"}
...

and

% bin/logstash -e 'input { stdin { } } filter { json { source => "message" } }'
{ "": "hello" }
[2017-12-23T11:23:51,062][ERROR][logstash.pipeline        ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {:pipeline_id=>"main", "exception"=>"-1", "backtrace"=>["java.util.ArrayList.elementData(ArrayList.java:422)", "java.util.ArrayList.remove(ArrayList.java:499)", "org.logstash.FieldReference.parse(FieldReference.java:159)", "org.logstash.FieldReference.parseToCache(FieldReference.java:146)", "org.logstash.FieldReference.from(FieldReference.java:78)", {{remainder omitted for brevity}}
java.lang.ArrayIndexOutOfBoundsException: -1
        at java.util.ArrayList.elementData(ArrayList.java:422)
        at java.util.ArrayList.remove(ArrayList.java:499)
        at org.logstash.FieldReference.parse(FieldReference.java:159)
        at org.logstash.FieldReference.parseToCache(FieldReference.java:146)
        at org.logstash.FieldReference.from(FieldReference.java:78)
{{truncated for brevity}}
@jsvd

This comment has been minimized.

Copy link
Member

commented Dec 28, 2017

@jordansissel it seems the v6.1.1 tag was placed incorrectly:

% curl localhost:9600?pretty
{
  "host" : "Joaos-MacBook-Pro-5.local",
  "version" : "6.1.1",
  "http_address" : "127.0.0.1:9600",
  "id" : "9f1dd434-bab2-49bf-af96-43655907f220",
  "name" : "Joaos-MacBook-Pro-5.local",
  "build_date" : "2017-12-17T21:51:17+00:00",
  "build_sha" : "d46ca0de31662d29b8c5c94d4162e4c760d3f8fb",
  "build_snapshot" : false
}

This seems indeed fixed for 6.1.2-snapshot:

/tmp/logstash-6.1.2-SNAPSHOT % echo '{ "": "test" }' | bin/logstash -e 'input { stdin { codec => json } }'
[2017-12-28T09:48:41,747][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"6.1.2"}
[2017-12-28T09:48:42,499][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
[2017-12-28T09:48:46,469][INFO ][logstash.pipeline        ] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>500, :thread=>"#<Thread:0x392baaef run>"}
[2017-12-28T09:48:46,544][INFO ][logstash.inputs.stdin    ] Automatically switching from json to json_lines codec {:plugin=>"stdin"}
[2017-12-28T09:48:46,577][INFO ][logstash.pipeline        ] Pipeline started {"pipeline.id"=>"main"}
[2017-12-28T09:48:46,866][INFO ][logstash.agent           ] Pipelines running {:count=>1, :pipelines=>["main"]}
{
    "@timestamp" => 2017-12-28T09:48:46.843Z,
          "host" => "Joaos-MacBook-Pro-5.local",
              "" => "test",
      "@version" => "1"
}

insukcho added a commit to insukcho/logstash that referenced this issue Feb 1, 2018

yaauie added a commit to yaauie/logstash that referenced this issue Aug 8, 2018

yaauie added a commit that referenced this issue Aug 9, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.