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.

Sign up for GitHub

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

Jump to bottom

When something is not jsonable, the service stop #3289

Closed
athoune opened this issue May 20, 2015 · 8 comments
Closed

When something is not jsonable, the service stop #3289

athoune opened this issue May 20, 2015 · 8 comments
Assignees
@andrewvc
Labels
bug crashes v1.5.2

Comments

@athoune
Copy link

athoune commented May 20, 2015

The stacktrace doesn't show the root cause. I don't know if it's my specific plugin, or something else, but it crash. Does logstash have to panic for a JSON drama?

java.lang.ClassNotFoundException: com.fasterxml.jackson.module.afterburner.ser.BeanPropertyAccessor
    at java.lang.ClassLoader.findClass(ClassLoader.java:531)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    at java.lang.ClassLoader.defineClass1(Native Method)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:800)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:643)
    at com.fasterxml.jackson.module.afterburner.util.MyClassLoader.loadAndResolve(MyClassLoader.java:86)
    at com.fasterxml.jackson.module.afterburner.ser.PropertyAccessorCollector.generateAccessorClass(PropertyAccessorCollector.java:166)
    at com.fasterxml.jackson.module.afterburner.ser.PropertyAccessorCollector.findAccessor(PropertyAccessorCollector.java:108)
    at com.fasterxml.jackson.module.afterburner.ser.SerializerModifier.changeProperties(SerializerModifier.java:55)
    at com.fasterxml.jackson.databind.ser.BeanSerializerFactory.constructBeanSerializer(BeanSerializerFactory.java:351)
    at com.fasterxml.jackson.databind.ser.BeanSerializerFactory.findBeanSerializer(BeanSerializerFactory.java:263)
    at com.fasterxml.jackson.databind.ser.BeanSerializerFactory._createSerializer2(BeanSerializerFactory.java:222)
    at com.fasterxml.jackson.databind.ser.BeanSerializerFactory.createSerializer(BeanSerializerFactory.java:152)
    at com.fasterxml.jackson.databind.SerializerProvider._createUntypedSerializer(SerializerProvider.java:1108)
    at com.fasterxml.jackson.databind.SerializerProvider._createAndCacheUntypedSerializer(SerializerProvider.java:1068)
    at com.fasterxml.jackson.databind.SerializerProvider.findValueSerializer(SerializerProvider.java:476)
    at com.fasterxml.jackson.databind.ser.impl.PropertySerializerMap.findAndAddSecondarySerializer(PropertySerializerMap.java:95)
    at com.fasterxml.jackson.databind.ser.std.MapSerializer._findAndAddDynamic(MapSerializer.java:689)
    at com.fasterxml.jackson.databind.ser.std.MapSerializer.serializeFields(MapSerializer.java:486)
    at com.fasterxml.jackson.databind.ser.std.MapSerializer.serialize(MapSerializer.java:412)
    at com.fasterxml.jackson.databind.ser.std.MapSerializer.serialize(MapSerializer.java:27)
    at com.jrjackson.RubyAnySerializer.serialize(RubyAnySerializer.java:93)
    at com.jrjackson.RubyAnySerializer.serialize(RubyAnySerializer.java:17)
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:128)
    at com.fasterxml.jackson.databind.ObjectMapper._configAndWriteValue(ObjectMapper.java:2881)
    at com.fasterxml.jackson.databind.ObjectMapper.writeValueAsString(ObjectMapper.java:2338)
    at com.jrjackson.JrJacksonRaw.generate(JrJacksonRaw.java:144)
    at com.jrjackson.JrJacksonRaw$INVOKER$s$0$1$generate.call(JrJacksonRaw$INVOKER$s$0$1$generate.gen)
    at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:665)
    at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:206)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at rubyjit.LogStash::Json$$jruby_dump_226c5a71b7811191c0a5473f7b4bcfb08d4521801661519073.chained_0_rescue_1$RUBY$SYNTHETIC__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/json.rb:43)
    at rubyjit.LogStash::Json$$jruby_dump_226c5a71b7811191c0a5473f7b4bcfb08d4521801661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/json.rb)
    at rubyjit.LogStash::Json$$jruby_dump_226c5a71b7811191c0a5473f7b4bcfb08d4521801661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/json.rb)
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181)
    at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:206)
    at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:61)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at rubyjit.LogStash::Event$$to_json_125d586ba2f5ca945f63519da032f048960185601661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/event.rb:158)
    at rubyjit.LogStash::Event$$to_json_125d586ba2f5ca945f63519da032f048960185601661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/event.rb)
    at org.jruby.ast.executable.AbstractScript.__file__(AbstractScript.java:38)
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:141)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:134)
    at rubyjit.LogStash::Outputs::File$$format_message_ea30790b6df9be357048a9df608964613a6228d11661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb:160)
    at rubyjit.LogStash::Outputs::File$$format_message_ea30790b6df9be357048a9df608964613a6228d11661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb)
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at rubyjit.LogStash::Outputs::File$$receive_283036d0777f57f7d194371d7c5c502c1b6e6a261661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb:107)
    at rubyjit.LogStash::Outputs::File$$receive_283036d0777f57f7d194371d7c5c502c1b6e6a261661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb)
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at rubyjit.LogStash::Outputs::Base$$handle_55d11b738524f0d354ebf54aa7334e2156dbaabb1661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/outputs/base.rb:88)
    at rubyjit.LogStash::Outputs::Base$$handle_55d11b738524f0d354ebf54aa7334e2156dbaabb1661519073.__file__(/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/outputs/base.rb)
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at rubyjit.LogStash::Pipeline$$output_func_9a1270d79e9a6491cfb779c9da1866d3bb4b91ce1661519073.__file__((eval):741)
    at rubyjit.LogStash::Pipeline$$output_func_9a1270d79e9a6491cfb779c9da1866d3bb4b91ce1661519073.__file__((eval))
    at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
    at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
    at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
    at org.jruby.ast.WhileNode.interpret(WhileNode.java:131)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
    at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
    at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74)
    at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:139)
    at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:187)
    at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:306)
    at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:136)
    at org.jruby.ast.VCallNode.interpret(VCallNode.java:88)
    at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
    at org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:112)
    at org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:206)
    at org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:194)
    at org.jruby.runtime.Interpreted19Block.call(Interpreted19Block.java:125)
    at org.jruby.runtime.Block.call(Block.java:101)
    at org.jruby.RubyProc.call(RubyProc.java:290)
    at org.jruby.RubyProc.call(RubyProc.java:228)
    at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:99)
    at java.lang.Thread.run(Thread.java:745)
LogStash::Json::GeneratorError: Failed to load class 'org.jruby.RubyBasicObject$Access4JacksonSerializer': com.fasterxml.jackson.module.afterburner.ser.BeanPropertyAccessor
      jruby_dump at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/json.rb:45
      jruby_dump at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/json.rb:43
         to_json at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/event.rb:158
  format_message at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb:160
         receive at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-file-0.1.6/lib/logstash/outputs/file.rb:107
          handle at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/outputs/base.rb:88
     output_func at (eval):741
    outputworker at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:244
   start_outputs at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:166
@colinsurprenant
Copy link
Contributor

@athoune thanks for the report. Could you please share your config and possibly a sample log line which can reproduce the problem?

Clearly, logstash should not crash for a JSON drama :P Once we figure out the root cause we will fix it and also add better exception handling for this. Note that we have an open issue #2477 that we will resume work on shortly that should help with these type of errors.

@athoune
Copy link
Author

athoune commented May 26, 2015

The crash appears in jruby_dump. With a dirty hack (dumping bad value to a file) :

def jruby_dump(o)
      # test for enumerable here to work around an omission in JrJackson::Json.dump to
      # also look for Java::JavaUtil::ArrayList, see TODO submit issue
      o.is_a?(Enumerable) ? JrJackson::Raw.generate(o) : JrJackson::Json.dump(o)
    rescue => e
      target = open('/tmp/debug.txt', 'w+')
      target.write(o)
      raise LogStash::Json::GeneratorError.new(e.message)
    end

I get this debug :

{"@timestamp"=>"2015-05-26T10:28:51.000Z", "message"=>"@Historywoman Got to hand it to you Madame Jill,that's quite a collection of OO,BNP,NF and intransigent,swivel eyed disciples you have there", "user"=>"FuarachBlas", "client"=>"<a href=\"http://twitter.com\" rel=\"nofollow\">Twitter Web Client</a>", "retweeted"=>false, "source"=>"http://twitter.com/FuarachBlas/status/603145768187383808", "@version"=>"1", "in-reply-to"=><null>, "tags"=>["twitter"]}

The null value seems guilty to me.

@athoune
Copy link
Author

athoune commented May 26, 2015

This content came from the twitter input plugin. What the hell is <null> ? ruby use nil for null content.

@colinsurprenant
Copy link
Contributor

@athoune ok, this is great info. so <null> is actually the string representation of the object, so my guess here is that the Twitter plugin (using the twitter gem) generates some object which JrJackson cannot serialize. With that info we should be able to get to the bottom of this.

@suyograo suyograo added v1.5.2 and removed v1.5.1 labels Jun 17, 2015
@suyograo suyograo assigned andrewvc and unassigned untergeek Jun 17, 2015
@andrewvc
Copy link
Contributor

@colinsurprenant @athoune I'm trying to repro this unsuccessfully. It's tricky because its not clear which <null> is representing. As @colinsurprenant mentioned, it definitely is not nil.

@athoune Have you seen this lately? I've been trying to repro this with the following config:

input {
  twitter {
    consumer_key => "x"
    consumer_secret => "x"
    oauth_token => "x"
    oauth_token_secret => "x"
    keywords => ["#truedetective", "truedetective", "truedetectiveseason2", "true detective"]
    type => "truedetective"

  }
}

output {
  stdout {
    codec => "json"
}

@andrewvc
Copy link
Contributor

@colinsurprenant @athoune Well, I let it run a little longer, and I caught a null. The culprit seems to be: Twitter::NullObject.

This would seem to be an issue in the twitter plugin, which should not be passing that through directly.

I'll also look at the error handlers here. We should probably be rescuing: JrJackson::ParseError errors and logging then continuing.

@colinsurprenant
Copy link
Contributor

+1 good catch

@andrewvc andrewvc mentioned this issue Jun 22, 2015
Open
@andrewvc
Copy link
Contributor

andrewvc commented Jul 1, 2015

I'm closing this issue because a temporary fix has been released.
logstash-plugins/logstash-input-twitter#15 will remain open however, waiting the permanent fix.

@andrewvc andrewvc closed this as completed Jul 1, 2015
@juanqui juanqui mentioned this issue Oct 31, 2015
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@andrewvc andrewvc

Labels
bug crashes v1.5.2
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@colinsurprenant @athoune @andrewvc @untergeek @suyograo