ConcurrencyError: interrupted waiting for mutex: null in Logstash 2.3.1

Elastic Stack Logstash
1

Sometimes I have the following issue:

{:timestamp=>"2016-04-16T04:35:38.758000+0000", :message=>"Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash.", "exception"=>#<ConcurrencyError: interrupted waiting for mutex: null>, "backtrace"=>["org/jruby/ext/thread/Mutex.java:94:in lock'", "org/jruby/ext/thread/Mutex.java:147:in synchronize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/resolv.rb:190:in lazy_initialize'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/resolv.rb:268:in each_name'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/resolv.rb:151:in each_name'", "org/jruby/RubyArray.java:1613:in each'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/resolv.rb:150:in each_name'", "/opt/logstash/vendor/jruby/lib/ruby/1.9/resolv.rb:132:in getname'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:244:in getname'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:231:in retriable_getname'", "org/jruby/RubyProc.java:281:in call'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:216:in retriable_request'", "org/jruby/ext/timeout/Timeout.java:115:in timeout'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:215:in retriable_request'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:230:in retriable_getname'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:178:in reverse'", "org/jruby/RubyArray.java:1613:in each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:156:in reverse'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-dns-2.1.3/lib/logstash/filters/dns.rb:95:in filter'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/filters/base.rb:151:in multi_filter'", "org/jruby/RubyArray.java:1613:in each'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/filters/base.rb:148:in multi_filter'", "(eval):10863:in cond_func_401'", "org/jruby/RubyArray.java:1613:in each'", "(eval):10851:in cond_func_401'", "(eval):2035:in filter_func'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/pipeline.rb:267:in filter_batch'", "org/jruby/RubyArray.java:1613:in each'", "org/jruby/RubyEnumerable.java:852:in inject'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/pipeline.rb:265:in filter_batch'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/pipeline.rb:223:in worker_loop'", "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.3.1-java/lib/logstash/pipeline.rb:201:in start_workers'"], :level=>:error}

After that logstash died.

2

Hi Fedele, sorry for the really late response here. I'm working on a solution for this problem and I'm wondering if you can share a bit more hints about your environment?

Thanks a lot,

  • purbon
3

Hi,

don't worry.

OS is:

Description:    Ubuntu 14.04.5 LTS
Release:        14.04
Codename:       trusty

Java version is:

openjdk version "1.8.0_91"
OpenJDK Runtime Environment (build 1.8.0_91-8u91-b14-0ubuntu4~14.04-b14)
OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode)

I tryed some 2.3.x versions, but I had the same issue. Issue that I don't have with version logstash 2.2.4.

Maybe it's the new pipeline.

Thanks a lot for support

4

I already identified the situation, is due to a concurrency situation inside the jruby code. I will be releasing a fix in the next days, but in the meanwhile I'm curious for two things:

  • Do you use config management? if yes, is this config management rewriting somehow the host file?
  • Do you have an uncommon host file? can you share it might be?

Thanks a lot,

  • purbon
5

Sorry, What do you mean with "config management"? Host file == /etc/hosts?

My ELK configuration is:

  • 3 nodes (1 client and 2 master) on same ESXi.
  • On master nodes I have 2 redis servers e 2 logststash indexer

I use this configuration to be online/running when I do the updates.

All documents go into these redis servers and 2 logstash indexer (with same configuration) take from redis servers and put in elasticsearch with client node. A snippet:

input { 
    redis {
        host => "server1"
        data_type => "list"
        key => "key1"
    }
    redis {
        host => "server2"
        data_type => "list"
        key => "key1"
    }
}

filter {....}

output {
    if [tag] == "key1" {
        elasticsearch {
            hosts => ["client_node"]
            index => "key1-%{+YYYY.MM.dd}"
        }   
    }       
}

The issue is on logstash indexer.

6

Hi,
thanks for your quick answer, I mean things like puppet, chef, ansible, etc. The actual source of the problem is related with the /etc/hosts file, so I'm wondering if this could be caused by external system like one of this.

7

Ok, no /etc/hosts does never change. I can confirm this because I use etckeeper and this file does not change.

8

interesting, thanks for this information is very valuable.

9

Couple of questions out of my head:

  • Is LS able to read the /etc/hosts file?
  • Does this file contain some uncommon lines? can you share it might be I would really like to debug more the situation.
10

I created https://github.com/logstash-plugins/logstash-filter-dns/issues/26 to track the fix.

11

I created https://github.com/logstash-plugins/logstash-filter-dns/pull/27 as a fix, it would be awesome if you can test the change in your environment and tell me your experience.

Thanks for your feedback and help.

12

LS could read this file, but I think that use DNS because I use dns names in configuration that aren't in /etc/hosts

My file host is:

127.0.0.1       localhost
172.x.x.x       hostname.mydomain.local       hostname

# The following lines are desirable for IPv6 capable hosts
::1     localhost ip6-localhost ip6-loopback
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
13

So the issue is in dns plugin?

In actual configuration I don't have dns plugin. But I checked in old version and I used it.

If you want I can update logstash for my indexers (that now don't have dns plugin) and I can test your change in a shipper (with dns plugin).

How can I update plugin with this fix?

14

It would be really nice to validate that the fix is properly working for everyone, having this reproduced in LS alone is being tricky. I will do proper explanation of what you can do tomorrow morning, thanks a lot!

15

On server with dns plugin, logstash reads /var/cache/nscd/hosts that is a DNS caching.
But with lsof I can't see access to /etc/hosts

16

Hi @purbon. I upgraded to logstash 2.3.4 where there isn't dns plugin, and I didn't have issues.
If you have a path, I can test it on my system. I have about 10 milions of logs for day that use this plugin, so if there is a problem I can see it very quickly.