malformed JSON causes codec looping "unrecoverable error"

Description

Hi,

While I was trying the new fantasy logstash-1.2, i found a little weird behavior. I'm not sure if it's expect result.

I just test a simple input & output:
```
input {stdin {codec => "json"}}
output { stdout { debug => true }}
```
After start logstash the agent, I just type "ENTER" without any other words.
I will get the error message as below continually.

```
A plugin had an unrecoverable error. Will restart this plugin.
Plugin: <LogStash::Inputs::Stdin type=>"stdin-type">
Error: closed stream {:level=>:error}
```

It seems the same issue at INPUT:file with JSON codec.
I think it might cause logstash agent stop shipping log if there is any "NEWLINE" or corrupted JSON in log file.

Any idea?

[UPDATE]
Not only ENTER but also all malformed JSON will cause the issue.
Follow error was reproduced by my randomly keyboard input.

```
A plugin had an unrecoverable error. Will restart this plugin.
Plugin: <LogStash::Inputs::Stdin type=>"stdin-type">
Error: unexpected token at ' sdf
'
Exception: JSON:arserError
Stack: json/ext/Parser.java:251:in `parse'
jar:file:/root/test-logstash/logstash.jar!/META-INF/jruby.home/lib/ruby/1.9/json/common.rb:155:in `parse'
file:/root/test-logstash/logstash.jar!/logstash/codecs/json.rb:12:in `decode'
file:/root/test-logstash/logstash.jar!/logstash/inputs/stdin.rb:26:in `run'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:151:in `inputworker'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:145:in `start_input' {:level=>:error, :file=>"/root/test-logstash/logstash.jar!/logstash/pipeline.rb", :line=>"156", :method=>"inputworker"}
json/ext/Parser.java:251:in `parse'
jar:file:/root/test-logstash/logstash.jar!/META-INF/jruby.home/lib/ruby/1.9/json/common.rb:155:in `parse'
file:/root/test-logstash/logstash.jar!/logstash/codecs/json.rb:12:in `decode'
file:/root/test-logstash/logstash.jar!/logstash/inputs/stdin.rb:26:in `run'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:151:in `inputworker'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:145:in `start_input'
stdin shutting down. {:level=>:debug, :file=>"/root/test-logstash/logstash.jar!/logstash/inputs/stdin.rb", :line=>"41", :method=>"teardown"}
Plugin is finished {lugin=><LogStash::Inputs::Stdin type=>"stdin-type">, :level=>:info, :file=>"/root/test-logstash/logstash.jar!/logstash/plugin.rb", :line=>"58", :method=>"finished"}
A plugin had an unrecoverable error. Will restart this plugin.
Plugin: <LogStash::Inputs::Stdin type=>"stdin-type">
Error: closed stream
Exception: IOError
Stack: org/jruby/RubyIO.java:2797:in `sysread'
file:/root/test-logstash/logstash.jar!/logstash/inputs/stdin.rb:25:in `run'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:151:in `inputworker'
file:/root/test-logstash/logstash.jar!/logstash/pipeline.rb:145:in `start_input' {:level=>:error, :file=>"/root/test-logstash/logstash.jar!/logstash/pipeline.rb", :line=>"156", :method=>"inputworker"}
```

Thanks!

Activity

Show:
Jonathan Tron
September 6, 2013, 8:30 AM

I see that there's no error handling in "JSON codec" nor "stdin input" when decoding a given message.

I'm wondering where this error handling should be done:

  • in "stdin input", it would probably be better to introduce something like a "codec decode exception" so that inputs can rescue this one independently from the code used.

  • in "json codec", should we raise an exception or create an event using the given data as "message" key and adding a specific tag "_codec_failed" (like the "_grok_parsefailure" one)

Jordan Sissel
September 7, 2013, 12:32 AM

I've restored the original behavior of older 'format => json' in the new json codecs.

Invalid json will nwo simply become an event with the 'message' as the raw-invalid-json text. Example:

Jordan Sissel
September 7, 2013, 12:34 AM

commit 621d61e8 fixes this

Ryan DeShone
October 26, 2013, 11:04 PM

Has this also been applied to the oldlogstashjson codec?

I am shipping json formatted apache logs using lumberjack. Every once in a while, for a reason we haven't been able to track down, lumberjack will truncate a log line, causing malformed json input to be processed by logstash. The process promptly crashes with an error akin to the following:

Exception in thread "LogStash::Runner" org.jruby.exceptions.RaiseException: (ParserError) unexpected token at '{ "@timestamp": "2013-10-26T18:32:16-0400", "@fields": { "http_client": "1.2.3.4", "http_duration_usec": 4802, "http_status": "200", "http_request": "/some/request", "http_request_host": "127.0.0.1", "http_method": "POST", "http_referrer": "-", "http_user-agent": "libwww-perl/5.833", "http_vhost": "some.vhost.com", "http_content-length": "34", "http_X-Forwarded-For": "1.2.3.4", "http_remote_u'
at json.ext.Parser.parse(json/ext/Parser.java:251)
at JSON.parse(jar:file:/opt/logstash/logstash-1.2.2-flatjar.jar!/META-INF/jruby.home/lib/ruby/1.9/json/common.rb:155)
at LogStash::Codecs::OldLogStashJSON.decode(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/logstash/codecs/oldlogstashjson.rb:9)
at RUBY.run(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/logstash/inputs/lumberjack.rb:45)
at org.jruby.RubyProc.call(org/jruby/RubyProc.java:271)
at Lumberjack::Connection.data(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:241)
at RUBY.run(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:223)
at Lumberjack:arser.data_field_value(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:182)
at Lumberjack:arser.feed(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:93)
at RUBY.compressed_payload(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:198)
at Lumberjack:arser.feed(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:93)
at RUBY.run(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:220)
at RUBY.run(file:/opt/logstash/logstash-1.2.2-flatjar.jar!/lumberjack/server.rb:59)

Fixed

Assignee

Piotr Popieluch

Reporter

Zz Chen

Labels

None

Fix versions

Affects versions

Configure