[Sidekiq 6.5.1] SSL_read: unexpected eof while reading #5402
Comments
jeremiemv
changed the title
|
SSL issues are lower level than Sidekiq. Check the redis gem or driver for
issues.
…On Fri, Jun 24, 2022 at 19:34 Jérémie Meyer de Ville < ***@***.***> wrote:
Ruby version: 3.1.2
Rails version: 7.0.3
Sidekiq: 6.5.1
redis gem: 4.6.0
Running on Heroku
Happening in
- staging, common runtime, heroku-22
- production, shield private space, heroku-20
Heroku Redis: 6.2.3
After upgrading to 6.5.1 from 6.4.0, we are having intermittent redis
connection issues, in both staging and production
*OpenSSL::SSL::SSLError: SSL_read: unexpected eof while reading*
/app/vendor/ruby-3.1.2/lib/ruby/3.1.0/openssl/buffering.rb line 214 in sysread_nonblock
/app/vendor/ruby-3.1.2/lib/ruby/3.1.0/openssl/buffering.rb line 214 in read_nonblock
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/connection/ruby.rb line 55 in block in _read_from_socket
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/connection/ruby.rb line 54 in loop
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/connection/ruby.rb line 54 in _read_from_socket
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/connection/ruby.rb line 47 in gets
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/connection/ruby.rb line 382 in read
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 311 in block in read
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 299 in io
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 310 in read
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 161 in block in call
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 279 in block (2 levels) in process
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 420 in ensure_connected
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 269 in block in process
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 356 in logging
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 268 in process
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/client.rb line 161 in call
/app/vendor/bundle/ruby/3.1.0/gems/scout_apm-5.2.0/lib/scout_apm/instruments/redis.rb line 32 in block in call_with_scout_instruments
/app/vendor/bundle/ruby/3.1.0/gems/scout_apm-5.2.0/lib/scout_apm/tracer.rb line 34 in instrument
/app/vendor/bundle/ruby/3.1.0/gems/scout_apm-5.2.0/lib/scout_apm/tracer.rb line 44 in instrument
/app/vendor/bundle/ruby/3.1.0/gems/scout_apm-5.2.0/lib/scout_apm/instruments/redis.rb line 31 in call_with_scout_instruments
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis.rb line 263 in block in send_command
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis.rb line 262 in synchronize
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis.rb line 262 in send_command
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/commands/scripting.rb line 110 in _eval
/app/vendor/bundle/ruby/3.1.0/gems/redis-4.6.0/lib/redis/commands/scripting.rb line 97 in evalsha
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 55 in zpopbyscore
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 35 in block (2 levels) in enqueue_jobs
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 30 in each
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 30 in block in enqueue_jobs
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq.rb line 156 in block in redis
/app/vendor/bundle/ruby/3.1.0/gems/connection_pool-2.2.5/lib/connection_pool.rb line 63 in block (2 levels) in with
/app/vendor/bundle/ruby/3.1.0/gems/connection_pool-2.2.5/lib/connection_pool.rb line 62 in handle_interrupt
/app/vendor/bundle/ruby/3.1.0/gems/connection_pool-2.2.5/lib/connection_pool.rb line 62 in block in with
/app/vendor/bundle/ruby/3.1.0/gems/connection_pool-2.2.5/lib/connection_pool.rb line 59 in handle_interrupt
/app/vendor/bundle/ruby/3.1.0/gems/connection_pool-2.2.5/lib/connection_pool.rb line 59 in with
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq.rb line 153 in redis
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 29 in enqueue_jobs
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 109 in enqueue
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/scheduled.rb line 101 in block in start
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/component.rb line 8 in watchdog
/app/vendor/bundle/ruby/3.1.0/gems/sidekiq-6.5.1/lib/sidekiq/component.rb line 17 in block in safe_thread
*initializer*
require "sidekiq/web"
Sidekiq.configure_server do |config|
config.redis = {
url: ENV["SIDEKIQ_REDIS_URL"] || ENV["REDIS_URL"] || "redis://localhost:6379/1",
ssl_params: { verify_mode: OpenSSL::SSL::VERIFY_NONE }
}
end
Sidekiq.configure_client do |config|
config.redis = {
url: ENV["SIDEKIQ_REDIS_URL"] || ENV["REDIS_URL"] || "redis://localhost:6379/1",
ssl_params: { verify_mode: OpenSSL::SSL::VERIFY_NONE }
}
end
*sidekiq.yml*
# Sample configuration file for Sidekiq.
# Options here can still be overridden by cmd line args.
# Place this file at config/sidekiq.yml and Sidekiq will
# pick it up automatically.
---
:verbose: false
:concurrency: 5
:timeout: 25
:max_retries: 14
# Sidekiq will run this file through ERB when reading it so you can
# even put in dynamic logic, like a host-specific queue.
# http://www.mikeperham.com/2013/11/13/advanced-sidekiq-host-specific-queues/
:queues:
- critical
- default
- mailers
- low
# you can override concurrency based on environment
production:
:concurrency: <%= ENV.fetch("SIDEKIQ_CONCURRENCY") { 5 } %>
development:
:max_retries: 0
—
Reply to this email directly, view it on GitHub
<#5402>, or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AAAAWX2SR7MEGRWGE62YDYTVQXWRJANCNFSM5ZYQLD7Q>
.
You are receiving this because you are subscribed to this thread.Message
ID: ***@***.***>
|
|
@mperham we haven't touched the redis gem |
|
And no recent openssl updates. |
|
I don’t see any issues either nor am I aware of any issues. https://github.com/redis/redis-rb/blob/master/CHANGELOG.md#470 6.5.0 added support for the new redis-client gem but I don’t see how that could have broken low-level SSL socket operations in the existing redis gem. @casperisfine ? |
|
Yeah I don't see it either. @jeremiemv a couple questions to hopefully have a few theories to explore:
|
|
We changed: conn.evalsha(@lua_zpopbyscore_sha, keys: keys, argv: argv)for conn.evalsha(@lua_zpopbyscore_sha, keys, argv)But that should make any difference: https://github.com/redis/redis-rb/blob/70dab9c149e739b450fa0c6ad660646f58e23170/lib/redis/commands/scripting.rb#L75-L96 |
|
Also since it happens on staging, I assume you can test more various things.
NB: I'm just giving ideas to hopefully get a bit more info on what the problem is. |
Yes. And same in staging and prod.
Only logs I see are the regular metrics samples. No warning or error. I found another application log. Not sure if this is helpful additional info.
Will give it a try.
Will give it a try.
Not sure it is possible with Redis 6 on Heroku. Thank you for looking into this BTW! |
Oh wow, color me intrigued. Something in the |
|
No SSL and SSL: hiredis-client: Going to see if I can make |
|
Ah. It just happened in staging with My apologies, the timing really coincided with the No idea what the root cause is yet :/ |
|
Is there something bad about the Lua that causes Redis to reset the connection? Perhaps using a command or option that is not supported in the version you're running? |
Note that
Ah that makes more sense now :) I'm still willing to help debug this any way I can. Once you manage to get more information feel free to open an issue on |
|
I came to this issue by googling for My app connects to Redis (6.2.3, heroku-redis, hobby-dev plan) using SSL/TLS (i.e. using a Because downgrading from heroku-22 to heroku-20 resolved these issues for me for now, I don't have a pressing issue. I'm sharing my experience/info in the hopes that it will be useful in understanding/diagnosing the cause of the problem, and in the hope that, once it is resolved I will again be able to upgrade to the heroku-22 stack, this time without errors. |
|
I know it's not Sidekiq's issue, but since this is the only result when searching online, I figured I'd share more info along with @davidrunger. Heroku-22 now uses OpenSSL 3 and has no support for OpenSSL 1. Thinking that may be the issue. I hit the same errors above when I upgraded to heroku-22 and have since reverted until I can spend more time on it. There's gotta be an incompatibility or outdated dependency somewhere in my app's Redis stack. |
|
Thank you everyone. Reverted to Will open a ticket with Heroku so they are aware of the issue. And probably open a |
|
Hey, just hit the same issue after upgrading to heroku-22. Thank you all for investigation. |
|
Please contact Heroku support and point them to this issue. They are welcome to add any context or link to better resources. |
|
From my Heroku support ticket: (they agreed for me to copy/paste this) We've seen a few reports of this, and while we continue investigating to see how we can improve this from our end, I think we have a pretty good idea of the current situation - let me share: These "unexpected EOF while reading" SSL errors can be reproduced consistently as soon as the connection is killed from the Redis end. The two more direct ways here would be to open a OpenSSL 3 has a much more strict behavior about unexpected EOF. Most Redis clients for other languages use their own TLS implementation, and some clients like PHP and Python's have enabled the SSL_OP_IGNORE_UNEXPECTED_EOF setting to make OpenSSL 3 behave as it did in previous versions. However, for Ruby specifically, we can see that when redis-rb is running with OpenSSL 3 and it gets one of these EOF, it is not gracefully reconnecting as it does for the behavior it saw with older OpenSSL versions. From our investigation so far we believe that the final fix will probably need to come from Ruby's OpenSSL and/or redis-rb. To get back into what I believe might be the source of the EOFs, which is Redis terminating client connections, it is important to remember that all Heroku Redis instances will close idle connections after 5 minutes: https://devcenter.heroku.com/articles/managing-heroku-redis-using-cli#redis-timeout. I consider this feature useful to avoid that any connection leaks to Redis could end up in your app hitting the maximum number of clients, but this is something you can fully configure on your own. I have been working with some of our customers that have tried setting the idle timeout to a larger value, around 25 hours, so that the dyno cycling periods are covered. This is, by making the timeout over 25 hours, no connections made by your dynos during their lifespan would be affected by this timeout. Heroku Redis is configured with a Alternatively, and especially seeing that this is behavior coming from OpenSSL that could potentially affect other connections, you might want to build EOF resiliency/retries from within your code directly. To confirm, this behavior does not happen in previous stacks like Would you like to test the idle timeout changes and let us know how it goes? As I mentioned, this is something we're actively investigating and working on, and it's possible this situation results in changes to the default timeout and keepalive settings in Heroku as I mentioned. We're still investigating further to see if these EOFs due to the incorrectly closed connections from the Redis server side is due to the default Redis behavior or if there might be something specific with how Heroku Redis runs that could be causing it. However, and keeping this in mind, if you want to use that info around OpenSSL, feel free to do so. For context, this is what other languages/clients did: python/cpython#25309 As I mentioned, we'll continue looking into this to see if we can make Heroku Redis compliant with the expected behavior from our end. I've linked this ticket to the internal work item where we're tracking this so I can keep you posted if we have news in the short term. |
|
@jeremiemv thanks, that makes a lot of sense. Someone should open an issue in redis-rb to discuss this OpenSSL 3 quirk. |
|
Yep, we can probably handle it more cleanly. |
|
Awesome @byroot 🥇 Want me to open an issue? |
|
Sure. I'll look at it tomorrow. Probably isn't too big a deal. #famouslastwords. |
|
Fix is here: redis/redis-rb#1107, I'd appreciate if some people could test it in staging/production just to be sure my local testing was good (unfortunately |
|
Redis Server issue filed here: redis/redis#10915 |
Hey David! I also did the same. Hope you're well. And thanks to the team here for finding the issue! 🙏 |
|
Did anyone in the last weeks give |
|
@Mariusio This has been fixed for some time. The fix is not in Heroku-22 (since it was not the issue, other than it happening to ship with OpenSSL 3 since it's based on Ubuntu 22.04), but instead in |
|
@edmorley Thanks so much for the update and the explanation, very helpful. |
|
Hey y'all, was running into the same issue: intermittent "SSL_read: unexpected eof while reading" errors while initializing Sidekiq jobs. Am pretty sure it began after upgrading from Alpine Linux 3.16 (where the openssl version is 1.1.1t) to 3.17 (where it's 3.0.8). Also happen to be running redis-rb 4.6.0. Strongly expect upgrading to redis >= 4.7.1 will do the trick; will update this comment whenever we have the chance to go live with that. Chiming in since most users encountering this seem to be on Heroku, which we are not, and it's widely known that information is power. Edit: Haven't seen the issue recur yet in our logs, so calling this a success. |
Ruby version: 3.1.2
Rails version: 7.0.3
Sidekiq: 6.5.1
redis gem: 4.6.0
Running on Heroku
Happening in
Heroku Redis: 6.2.3, premium-0
We have dedicated redis instances for sidekiq.
After upgrading to 6.5.1 from 6.4.2, we are having intermittent redis connection issues, in both staging and production.
OpenSSL::SSL::SSLError: SSL_read: unexpected eof while reading
initializer
sidekiq.yml
The text was updated successfully, but these errors were encountered: