Elasticsearch-rails: Faraday::ConnectionFailed - threads problem

[inska]

Hi,

I am using elasticsearch-rails and elasticsearch-model gem with Rails 4.2.2, and Puma. Gem works very well normally, but when getting request much, Rails returns 500 error with below message:

Faraday::ConnectionFailed: easy handle already used in multi handle

To solve this problem, I investigated what was point, and I got something. When set puma threads to static as 1, that problem not occur. Does elasticsearch-rails and elasticsearch-model have threads problem?

Tried to move below code from initializer to controller, but repeats 500 error:
Elasticsearch::Model.client = Elasticsearch::Client.new host: 'localhost'

I am considering just fix threads count as 1 and using workers but it could be heavy rails application for server instance.. when removing elasticsearch related gems and code out, rails application works very very well.

Please let me know how can I fix it.

Best Regards,
Inska

[jogaco]

I am using Rails 4.2 and Puma as well. Only I do not have many requests, so I have not found this problem yet.

[marcomorain]

I'm hitting a similar problem with Faraday (not using Elasticsearch Rails). Running a set of get commands in parallel fails.

/Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:879:in `initialize': [!] getaddrinfo: nodename nor servname provided, or not known (Faraday::ConnectionFailed)
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:879:in `open'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:879:in `block in connect'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/timeout.rb:74:in `timeout'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:878:in `connect'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:863:in `do_start'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:852:in `start'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:1375:in `request'
    from /Users/travis/.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/http.rb:1133:in `get'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:80:in `perform_request'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:40:in `block in call'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:87:in `with_net_http_connection'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:32:in `call'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/request/url_encoded.rb:15:in `call'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:139:in `build_response'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/connection.rb:377:in `run_request'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday/connection.rb:140:in `get'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/faraday-0.9.2/lib/faraday.rb:99:in `method_missing'
    from /Users/travis/build/flipdish/ios/fastlane/actions/whitelabel_config.rb:47:in `block in download_assets'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:408:in `call'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:408:in `call_with_index'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:288:in `block (2 levels) in work_in_threads'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:419:in `with_instrumentation'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:287:in `block in work_in_threads'
    from /Users/travis/build/flipdish/ios/vendor/bundle/ruby/2.2.0/gems/parallel-1.6.2/lib/parallel.rb:183:in `block (2 levels) in in_threads'

[jogaco]

I do not know if it is related, but occasionally, once per day or less, I get this:

[Faraday::ConnectionFailed] connection refused: localhost:9200

This is not very nice, as users get a 500 error.

[karmi]

Hi @inska, apologies for the delay with a reply on this issue. Thanks for the report, I think the suspicion that some parts of the code are not threadsafe and it manifests itself in Puma is warranted. I was never able to reliably replicate that, but I think something is there.

Now, @andrewvc is working in on improving the thread safety situation in #284, and it's possible this will translate into better stability within Puma.

Just to make the situation more clear, all of you guys are running the client with only host, or multiple hosts? I'm asking because it would allow us to narrow down the issue -- my suspicion is that the problematic code will be in the the connection selection parts. But when the hosts is set to one, there is no selection, so the problem will be on a more basic level.

[jogaco]

I'm personally working with single host, with ES in same host as rails app, and not much load at all: around 1000 pages per day, and as said, I occasionally get a Faraday connection failed.

[karmi]

@jogaco, interesting, thanks... It can be also a legitimate connection refused by Elasticsearch, when it would be overloaded, but I guess it's not very probable in the case you describe. I'll try to setup some environment with Puma and then pound it with ab, httperr or similar and see how it behaves.

[liamwhite]

Confirming this with Phusion Passenger Enterprise 5.0.26 when we switched threads on in the application. Almost every single request errored as such:

Faraday::ConnectionFailed: easy handle already used in multi handle 

…dle/ruby/2.3.0/gems/patron-0.5.0/lib/patron/session.rb:  216:in `handle_request'
…dle/ruby/2.3.0/gems/patron-0.5.0/lib/patron/session.rb:  216:in `request'
…2.3.0/gems/faraday-0.9.2/lib/faraday/adapter/patron.rb:   33:in `call'
…y/2.3.0/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:  139:in `build_response'
…uby/2.3.0/gems/faraday-0.9.2/lib/faraday/connection.rb:  377:in `run_request'
…/lib/elasticsearch/transport/transport/http/faraday.rb:   21:in `block in perform_request'
…t-1.0.15/lib/elasticsearch/transport/transport/base.rb:  201:in `perform_request'
…/lib/elasticsearch/transport/transport/http/faraday.rb:   20:in `perform_request'
…transport-1.0.15/lib/elasticsearch/transport/client.rb:  125:in `perform_request'
…rch-api-1.0.15/lib/elasticsearch/api/actions/search.rb:  167:in `search'
…earch-model-0.1.8/lib/elasticsearch/model/searching.rb:   51:in `execute!'

Turning threaded mode back off caused the errors to cease immediately.

[liamwhite]

@karmi when running ab against a test app with puma as the appserver, any concurrency level higher than one crashes ruby with a segfault. This is only reproducible with the Patron gem in the Gemfile (see attached for an example app)
esrails_threads.tar.gz

It would be well worth noting that Patron does not really support concurrency

[karmi]

Yes, it just happened to me the other day with Sidekiq, and I had to switch some workers to net_http. Thanks for concrete confirmations on this and for the pointer to the Patron documentation. We have to solve this one way or other.

The one problem I see with the obvious solution, using the connection_pool gem, is that it's no longer maintained. But it should be fairly easy to implement something like that which would play nicely in threaded environments.

I am keeping this on my mind, just wasn't able to find a quiet day or two to focus on it without distractions.

[tozz]

Ran into this problem too (not with Rails, just a Rack app). Solved it temporarily by wrapping elasticsearch-ruby and storing an instance of the client in Thread.local.
There's a lot of politics around using Thread.local for things like these, but I've found that it works quite well for simple things :)

[liamwhite]

@tozz can you share the code you used to accomplish this?

[tozz]

@liamwhite You can solve it in a lot of ways, I currently use something like https://gist.github.com/tozz/c8fc54f77d3108146b6b5278d4540589
Remember that each thread will do a new connection to ES, this is why some kind of pooling needs to either be compatible with connection_pool or introduced into the elasticsearch-transport gem.

[liamwhite]

I was able to use this in an initializer to fix my threads issue, and have now been running threaded for a bit less than a month:

Elasticsearch::Model.client = ConnectionPool::Wrapper.new(size: 5, timeout: 3) { Elasticsearch::Client.new }

However, I still periodically get the issue mentioned in the OP.

[bkazez]

I have applied this fix and am still frequently getting "Faraday::ConnectionFailed: easy handle already used in multi handle". Are there any new recommendations? I'm unfortunately new to Rails and don't know how to help debug this.

[bkazez]

Never mind, turns out I wasn't calling Elasticsearch::Client.new from within the block passed to ConnectionPool::Wrapper.new, so it was always using the same client.

[dathuonruby]

I'm using elasticsearch_persistance-5.0.1 and elasticsearch_model-5.0.1 with rails 4.0.9 on puma server & Elastic search 5.3.0.

Getting below issue with 500 code. I can't use less number of thread count on puma where my application running with very heavy traffic. Can anyone explain what exactly the reason for below issue( It's occurring 3 to 5 times in a day on total load)

Faraday::ConnectionFailed (Failed to open TCP connection to es_server:9200 (getaddrinfo: Temporary failure in name resolution)):
app/models/concerns/searchable.rb:53:in block in search_for' app/models/concerns/searchable.rb:51:insearch_for'
app/models/my_model.rb:54:in search_for' app/controllers/my_controller.rb:41:inblock (2 levels) in search'
app/controllers/my_controller.rb:31:in `search'

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[addisonmartin]

I am still encountering this issue using Ruby 2.7.2, Ruby on Rails 6.0, Elasticsearch OSS 7.9.2, Elasticsearch Gem 7.9.0, Elasticsearch Model Gem 7.1.1, and Elasticsearch Rails Gem 7.1.1.

Essentially I was trying to setup my Rails application to use Elasticsearch all using docker compose. I was following the readme to add indexing as a background job with Sidekiq, and had to change the following line:

Client = Elasticsearch::Client.new host: ENV['ELASTICSEARCH_HOST'], logger: Logger

to the fix mentioned above:

Client = Elasticsearch::Model.client = ConnectionPool::Wrapper.new(size: 5, timeout: 3) { Elasticsearch::Client.new host: ENV['ELASTICSEARCH_HOST'], logger: Logger }