gelf listener died (bis)

[jlecour]

Hi, I've asked on the forum about this :
https://discuss.elastic.co/t/gelf-listener-died/61580
No one has replied over there yet in 2 weeks, so I'm trying here.

It's not exactly the same as #21 since the error is different.

• Version: 2.4.0
• Operating System: Debian 8.6 (up-to-date)
• Config File :

input {
  beats {
    port => 5044
  }
  gelf {
    port => 12201
    type => "gelf"
  }
}
output {
  elasticsearch {
    hosts => "localhost:9200"
    index => "logs-%{type}-%{+YYYY.MM.dd}"
    manage_template => false
  }
}

Error in log file :

{:timestamp=>"2016-10-11T11:58:29.704000+0200", :message=>"gelf listener died (0.0.0.0:12201)", :exception=>#<SocketError: bind: name or service not known>, :backtrace=>["org/jruby/ext/socket/RubyUDPSocket.java:160:in `bind'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:98:in `udp_listener'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:77:in `run'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:342:in `inputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:336:in `start_input'"], :level=>:warn}

NB: The error message is customized to show the host:port that fails.

[jlecour]

I've noticed that sometimes i also get this error :

{:timestamp=>"2016-10-12T15:47:37.520000+0200", :message=>"gelf listener died (0.0.0.0:12201)", :exception=>#<NoMethodError: undefined method `[]=' for nil:NilClass>, :backtrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:130:in `new_event'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:113:in `udp_listener'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:77:in `run'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:342:in `inputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:336:in `start_input'"], :level=>:warn}

and immediately after, I get the "listener died" error every 5 seconds.

If it is not a coincidence, it seems strange that a bad GELF message is able to crash the listener.

[jlecour]

With this command I can reproduce the crash :

echo '' | gzip | nc -u -w 1 127.0.0.1 12201

You can see that the message is empty, then gziped (as it should be) and sent via UDP to the Logstash GELF port.

[jlecour]

I confirm that I reproduce the crash.

In a terminal I send a sample tracable message to Logstash every 1 sec.
In another terminal i tail the log (ans see nothing unusual).

Then, from a third terminal, I send the empty message. Immediately I see the parse error in the log :

{:timestamp=>"2016-10-12T16:49:00.557000+0200", :message=>"gelf listener died", :exception=>#<NoMethodError: undefined method `[]=' for nil:NilClass>, :backtrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:130:in `new_event'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:113:in `udp_listener'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:77:in `run'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:342:in `inputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:336:in `start_input'"], :level=>:warn}

Then, exactly every 5 seconds I get the gelf listener died error :

{:timestamp=>"2016-10-12T16:49:05.725000+0200", :message=>"gelf listener died", :exception=>#<SocketError: bind: name or service not known>, :backtrace=>["org/jruby/ext/socket/RubyUDPSocket.java:160:in `bind'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:98:in `udp_listener'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-gelf-2.0.7/lib/logstash/inputs/gelf.rb:77:in `run'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:342:in `inputworker'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:336:in `start_input'"], :level=>:warn}

[Cactusbone]

PR #51 for the recurring SocketError: bind: name or service not known
Thanks for the bug, it enabled me to understand why I was getting this log (original error was lost in logs)