rescue in io': Connection lost (ECONNRESET)

[gnuhub]

redis_subscribe_client=Redis.new(:host => "127.0.0.1", :port => 6379)
redis_subscribe_client.subscribe("md") do |on|
  on.message do |channel, msg|

    Thread.new {
      tick = JSON.parse(msg)
      if channel.eql?("md")
        save_tick(tick)
      end
    }
  end
end

/var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:244:in `rescue in io': Connection lost (ECONNRESET) (Redis::ConnectionError)
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:237:in `io'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:248:in `read'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:129:in `block (3 levels) in call_loop'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:128:in `loop'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:128:in `block (2 levels) in call_loop'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:218:in `block (2 levels) in process'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:354:in `ensure_connected'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:208:in `block in process'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:293:in `logging'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:207:in `process'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:127:in `block in call_loop'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:267:in `with_socket_timeout'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:274:in `without_socket_timeout'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/client.rb:126:in `call_loop'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/subscribe.rb:35:in `subscription'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis/subscribe.rb:12:in `subscribe'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis.rb:2718:in `_subscription'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis.rb:2098:in `block in subscribe'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis.rb:57:in `block in synchronize'
    from /usr/lib/ruby/2.1.0/monitor.rb:211:in `mon_synchronize'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis.rb:57:in `synchronize'
    from /var/lib/gems/2.1.0/gems/redis-3.2.2/lib/redis.rb:2097:in `subscribe'
    from ./ticks_save.rb:40:in `<main>'

what is the problem?

[badboy]

For some reason the connection to Redis breaks. Maybe because of timeouts or because your network has hiccups. Unlikely that it's the code's fault

[ssotos]

Hey, did you ever found out what was it? I see you had this running as localhost.

[wpp]

Hi,

I think I might experience the same issue within a Rails/ActionCable project. I'm initialising the client connection with ssl_params in addition to host and port params provided by @gnuhub. I get a pretty similar stack trace:

listen loop error: Connection lost (ECONNRESET) (Redis::ConnectionError)
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:257:in `rescue in io'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:250:in `io'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:261:in `read'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:136:in `block (3 levels) in call_loop'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:135:in `loop'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:135:in `block (2 levels) in call_loop'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:231:in `block (2 levels) in process'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:367:in `ensure_connected'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:221:in `block in process'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:306:in `logging'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:220:in `process'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:134:in `block in call_loop'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:280:in `with_socket_timeout'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/client.rb:133:in `call_loop'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/subscribe.rb:43:in `subscription'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis/subscribe.rb:12:in `subscribe'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis.rb:2765:in `_subscription'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis.rb:2143:in `block in subscribe'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis.rb:58:in `block in synchronize'
ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis.rb:58:in `synchronize'
ruby/gems/2.3.0/gems/redis-3.3.2/lib/redis.rb:2142:in `subscribe'
ruby/gems/2.3.0/gems/actioncable-5.0.1/lib/action_cable/subscription_adapter/redis.rb:75:in `block in listen'

Which occurs rather sporadically.

Since @badboy mentioned "...timeouts or because your network has hiccups." I'd be curious how you might have solved this problem (if you can recall). It happens rather sporadically and might speed up my debugging process.

[wpp]

Quick follow up: In my case it was in fact down to network hiccups!

Since these hiccups can occur every now and then I was hoping the lib supported some kind of reconnection mechanism. reconnect_attempts looked promising but I was rather surprised at the way reconnect_attempts is implemented atm. The reconnection attempts are working rather aggressively, without any kind of delay and therefore you'd have to initialise the client with a rather high number for reconnect_attempts.

Digging through the code base I found: https://github.com/redis/redis-rb/pull/347 and @pietern mentioning "a back-off algorithm when somebody needs it and it comes up as an issue".

I'm wondering if you'd still be open to discuss something like that? I would maybe open a different issue since this is no longer related to the original issue.

Cheers and thanks for the library!

[wpp]

Here is a quick recording demonstrating the current reconnection behaviour (stopping and starting docker container) and a really simple back off solution with an upper bound for the wait time.

[roooodcastro]

Hi @wpp, is there any way to fix this while they don't merge the PR, without monkey-patching Redis?

[wpp]

Hm. You could specify my fork (or for extra safety your own) and branch in your Gemfile. Maybe that's an option for you?

gem 'redis', github: 'wpp/redis-rb', branch: 'back-off-reconnection'

[roooodcastro]

I used your fork but kept having the same problem. I monkey-patched the Client class to test a few stuff and found out that the backoff algorithm is working correctly, but it's still not working.

I found out that ActionCable is using Redis's subscribe feature, and after some time the connection ends with a timeout (don't know why). The reconnect algorithm kicks in, but every time it reconnects, a ["subscribe", "_action_cable_internal", 1] command is sent to the server, and for some reason the method _read_from_socket inside redis/connection/ruby is returning an EOF signal, triggering another reconnect and starting this endless cycle that culminates with the shutdown of the process after the max amount of tries.

I think the issue I'm having is not related to this, so I'll open a new issue for it. Have you encountered something like this?

[wpp]

It's been a while since I've worked with AC. But this does not sound familiar to me, sorry.

[github0013]

Can this be a reason? https://redis.io/topics/clients#output-buffers-limits

[byroot]

This looks like the server closing the connection for whatever reason. Not actionable.