Errno::EINVAL: Invalid argument instead of Redis::CannotConnectError

[printercu]

Sometimes this code fails (on different iteration) with Errno::EINVAL: Invalid argument when redis server is down.

redis = Redis.new(driver: :hiredis)
10000.times do |i|
  puts(i.to_s)
  begin
    redis.get(1)
  rescue Redis::CannotConnectError
  end
end
# oneliner:
# redis = Redis.new(driver: :hiredis); 10000.times { |i| puts(i.to_s); begin; redis.get(1); rescue Redis::CannotConnectError; end }

:ruby driver is ok.

[pietern]

Can you provide some more information?

For example, can you run strace while reproducing this issue, configured to only capture networking related system calls? I'd be interested in seeing an excerpt that shows EINVAL being returned by either connect(2) or some other call.

Without such information, I can't help you out.

[printercu]

I'll try. Does'n this oneliner reproduce the issue for you?

[dplummer]

@printercu I'm unable to reproduce this issue on my local system using ruby 2.1.1, redis 2.8.8, redis gem 3.0.7, and hiredis-rb 0.5.2. I suspect @pietern cannot reproduce it locally either.

[printercu]

@dplummer have you turned your redis server down? You can just provide port: 6380 (or other one that is not listened by redis) in my oneliner.

[dplummer]

Nope, no failures on either a Macbook Pro, Archlinux desktop or Ubuntu 14.04 EC2 VM.

[printercu]

Sorry, i think i can get you wrong. Do you mean 'nope, no failures when server is down' or 'nope, did not turned server down'? I just tried with same configuration (but redis 2.8.5) and got error on mac os.

Sometimes this code fails (on different iteration) with Errno::EINVAL: Invalid argument when redis server is down.

[dplummer]

I'm unable to reproduce your issue. I am not getting a Errno::EINVAL exception.

[pietern]

I'm not able to reproduce either.

If you can post back more information about your environment and more details that would allow us to reproduce your issue locally, we can re-open the issue.

[masterkain]

got the same error, here's a trace if it does help.

~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/connection/hiredis.rb:16:in `connect': Invalid argument (Errno::EINVAL)
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/connection/hiredis.rb:16:in `connect'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:285:in `establish_connection'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:79:in `block in connect'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:257:in `with_reconnect'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:78:in `connect'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:304:in `ensure_connected'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:191:in `block in process'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:270:in `logging'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:190:in `process'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis/client.rb:96:in `call'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis.rb:784:in `block in get'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis.rb:37:in `block in synchronize'
  from ~/.rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/monitor.rb:211:in `mon_synchronize'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis.rb:37:in `synchronize'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-3.0.7/lib/redis.rb:783:in `get'
  from ~/.rvm/gems/ruby-2.1.2/gems/redis-namespace-1.4.1/lib/redis/namespace.rb:352:in `method_missing'
  from ~/.rvm/gems/ruby-2.1.2/bundler/gems/sidetiq-b1021d8cf18b/lib/sidetiq/schedulable.rb:65:in `get_schedulable_key'
  from ~/.rvm/gems/ruby-2.1.2/bundler/gems/sidetiq-b1021d8cf18b/lib/sidetiq/schedulable.rb:45:in `recurrence'
  from ~/Sites/myapp2/rails/app/workers/scheduled_iap_cleaner.rb:16:in `<class:ScheduledIapCleaner>'
  from ~/Sites/myapp2/rails/app/workers/scheduled_iap_cleaner.rb:12:in `<top (required)>'
  from ~/.rvm/gems/ruby-2.1.2/gems/polyglot-0.3.5/lib/polyglot.rb:65:in `require'
  from ~/.rvm/gems/ruby-2.1.2/gems/polyglot-0.3.5/lib/polyglot.rb:65:in `require'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:247:in `block in require'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:232:in `load_dependency'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:247:in `require'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:348:in `require_or_load'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:480:in `load_missing_constant'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:180:in `const_missing'
  from ~/Sites/myapp2/rails/spec/workers/scheduled_iap_cleaner_spec.rb:13:in `<top (required)>'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:241:in `load'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:241:in `block in load'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:232:in `load_dependency'
  from ~/.rvm/gems/ruby-2.1.2/gems/activesupport-4.1.1/lib/active_support/dependencies.rb:241:in `load'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/configuration.rb:1051:in `block in load_spec_files'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/configuration.rb:1051:in `each'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/configuration.rb:1051:in `load_spec_files'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/runner.rb:97:in `setup'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/runner.rb:85:in `run'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/runner.rb:70:in `run'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/lib/rspec/core/runner.rb:38:in `invoke'
  from ~/.rvm/gems/ruby-2.1.2/gems/rspec-core-3.0.0/exe/rspec:4:in `<top (required)>'
  from ~/.rvm/gems/ruby-2.1.2/bin/rspec:23:in `load'
  from ~/.rvm/gems/ruby-2.1.2/bin/rspec:23:in `<main>'
  from ~/.rvm/gems/ruby-2.1.2/bin/ruby_executable_hooks:15:in `eval'
  from ~/.rvm/gems/ruby-2.1.2/bin/ruby_executable_hooks:15:in `<main>'

[printercu]

@pietern, @dplummer here is my backtrace (here I tried in new environment):

$ irb
2.1.1 :003 > require 'redis'
 => true 
2.1.1 :004 > require 'hiredis'
 => true 
2.1.1 :005 > Hiredis::VERSION
 => "0.5.2" 
2.1.1 :006 > Redis::VERSION
 => "3.0.7" 
2.1.1 :007 > redis = Redis.new(driver: :hiredis, port: 1111)
 => #<Redis client v3.0.7 for redis://127.0.0.1:1111/0> 
2.1.1 :008 > 10000.times do |i|
2.1.1 :009 >       puts(i.to_s)
2.1.1 :010?>     begin
2.1.1 :011 >           redis.get(1)
2.1.1 :012?>       rescue Redis::CannotConnectError
2.1.1 :013?>       end
2.1.1 :014?>   end
0
1
....
589
590
Errno::EINVAL: Invalid argument
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/connection/hiredis.rb:16:in `connect'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/connection/hiredis.rb:16:in `connect'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:285:in `establish_connection'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:79:in `block in connect'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:257:in `with_reconnect'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:78:in `connect'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:304:in `ensure_connected'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:191:in `block in process'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:270:in `logging'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:190:in `process'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis/client.rb:96:in `call'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis.rb:784:in `block in get'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis.rb:37:in `block in synchronize'
    from /Users/max/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/monitor.rb:211:in `mon_synchronize'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis.rb:37:in `synchronize'
    from /Users/max/.rvm/gems/ruby-2.1.1/gems/redis-3.0.7/lib/redis.rb:783:in `get'
    from (irb):11:in `block in irb_binding'
    from (irb):8:in `times'
    from (irb):8
    from /Users/max/.rvm/rubies/ruby-2.1.1/bin/irb:11:in `<main>'2.1.1 :015 > 

Please, make sure you are trying to connect to port which is not listened by redis instance, if you try to reproduce.

[pietern]

I tried to reproduce again with the script you listed and see an Errno::EINVAL happen after a variable number of iterations. Hiredis creates a new socket every time it tries to reconnect, so the process can easily run out of the number of file descriptors it is allowed to use (check this with ulimit -n). I ran the reproduce script with an allowance of 10k file descriptors and it didn't show the issue. By default, processes on OSX get 256 file descriptors.

Hiredis can't do anything about the process running out of file descriptors. It can raise a more descriptive error, but that's about it. I'll reopen the ticket, because we'd need to figure out which system call the Errno::EINVAL comes from, so that we can decorate the error and transform it into a CannotConnectError so that the redis gem can retry (out of file descriptors can be transient).

[printercu]

Thanks for the explanation! I've noticed that Rails.cache adapter for redis rescues only from Errno::ECONNREFUSED, Redis::CannotConnectError. So it will fail when cache server is down.

[mickey]

A few of our gems, rescue from Redis::BaseError to handle failure (readthis, flipper,...) so with Errno::EINVAL in case of failure/failover it fails when it should not.

Here's my patch:

class Hiredis::Connection
  def connect_with_decorate_errno_einval(host, port, timeout)
    begin
      connect_without_decorate_errno_einval(host, port, timeout)
    rescue Errno::EINVAL => e
      raise Redis::CannotConnectError, e.message
    end
  end
  alias_method_chain :connect, :decorate_errno_einval
end

[ashiksp]

Any update on this issue ?

[mandaputtra]

Hi, got this message too any recomendation on solving it? LinuxMint 19.01

events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: Redis connection to 6379:6379 failed - connect EINVAL 0.0.24.235:6379 - Local (0.0.0.0:0)
    at internalConnect (net.js:881:16)
    at defaultTriggerAsyncIdScope (internal/async_hooks.js:294:19)
    at GetAddrInfoReqWrap.emitLookup [as callback] (net.js:1028:9)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:59:10)
Emitted 'error' event at:
    at RedisClient.onError (/home/maxsol/Works/yanmar-nodejs/node_modules/socket.io-redis/index.js:118:12)
    at RedisClient.emit (events.js:198:13)
    at RedisClient.on_error (/home/maxsol/Works/yanmar-nodejs/node_modules/redis/index.js:406:14)
    at Socket.<anonymous> (/home/maxsol/Works/yanmar-nodejs/node_modules/redis/index.js:279:14)
    at Socket.emit (events.js:198:13)
    at emitErrorNT (internal/streams/destroy.js:91:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)