Pipeline stops processing events because of exception in filterworker "#<NoMethodError: undefined method `encode' for nil:NilClass>"

[mezzatto]

I'm getting the following error in the logstash log, and when it happens the pipeline stops processing events:

{:timestamp=>"2014-11-29T15:44:34.069000-0200", :message=>"Exception in filterworker", "exception"=>#<NoMethodError: undefined method `encode' for nil:NilClass>, "backtrace"=>["(ruby filter code):1:in `register'", "org/jruby/RubyProc.java:271:in `call'", "/usr/local/logstash/lib/logstash/filters/ruby.rb:38:in `filter'", "(eval):32:in `initialize'", "org/jruby/RubyProc.java:271:in `call'", "/usr/local/logstash/lib/logstash/pipeline.rb:262:in `filter'", "/usr/local/logstash/lib/logstash/pipeline.rb:203:in `filterworker'", "/usr/local/logstash/lib/logstash/pipeline.rb:143:in `start_filters'"], :level=>:error}

The error does not seems to be related to some specific input. Sometimes the log is generated but the pipeline processing continues.

Some info about the environment:

# java -version
java version "1.7.0_60"
Java(TM) SE Runtime Environment (build 1.7.0_60-b19)
Java HotSpot(TM) 64-Bit Server VM (build 24.60-b09, mixed mode)

Command line:

/usr/bin/java -Xmx500m -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -Djava.awt.headless=true -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -jar /usr/local/logstash/vendor/jar/jruby-complete-1.7.11.jar -I/usr/local/logstash/lib /usr/local/logstash/lib/logstash/runner.rb agent -f /etc/logstash/log_indexer.conf -w 4 -l /var/log/logstash/log_indexer.log

My config:

input {
  redis {
    host => "127.0.0.1"
    port => 43210
    data_type => "list"
    key => "proc_log"
    batch_count => 100
    codec => json
    threads => 4
  }
}

filter {
  ruby {
    code => "event['message'] = event['message'][0].encode('iso-8859-1', 'utf-8', :invalid => :replace, :undef => :replace, :replace => '')"
  }
}

output {
  file {
    codec => line { charset => "ISO-8859-1" }
    message_format => '%{message}'
    flush_interval => 1
    path => "%{path}"
  }
  elasticsearch {
    index => "ck-%{+YYYY.MM.dd.HH}"
    protocol => "http"
    cluster => "elasticsearch_procura_access"
    flush_size => 100
    workers => 4
  }
}

[bluescapepaul]

👍 the worker should drop the event and log the message when it gets this sort of exception. Simply refusing to process any more events seems like a poor design,

[antgel]

Any clues as to a workaround for this, or how to debug it further? It's causing us problems in production.

[jordansissel]

@antgel your ruby code is incorrect. It is calling the .encode method on an object which is nil.

event['message'][0].encode(...)

This event['message'][0] is a nil value when you get this exception. Knowing why this happens will require knowing more about your event's structure.

[jordansissel]

the worker should drop the event

No. Dropping data because of a resolvable problem is not a good default behavior. :)

In the future, we are adding a way to stash these kinds of problematic events in a way that will be recoverable later and will not block further processing of events. You can read more about the dead letter queue feature, here

[jsvd]

closing this as the problem itself related to an error in the configuration. since then the ruby filter has wrapped the code execution in a begin rescue that prints an error message and tags the event with a _rubyexception tag.

more about this in https://github.com/logstash-plugins/logstash-filter-ruby/blob/master/lib/logstash/filters/ruby.rb#L37-L43