ldclient-rb nearly burnt my Mac due to CPU throttling

[dzirtusss]

Is this a support request?
No.

Describe the bug
hi, I have nearly burnt (physically) my mac because of launch-darkly. How it happened:

1. normally I just close lid or otherwise go to sleep mode (and I don’t care closing rails threads surely)
2. my provider has internet switch off somewhere in the middle of night - whatever tech issues
3. LaunchDarkly because he can’t resolve DNS have gone into never-ending throttle with all cores burning 100%
4. when I came to my mac it was sounding like a bee and was hot as hell

Lucky it didn’t happen inside the case…..

To reproduce
Guess switch off internet totally (or block DNS) but keep wifi connected.

Expected behavior
Don't burn CPU

Logs

Connecting to event stream at https://stream.launchdarkly.com/all
Unexpected error from event source: #<Socketry::Resolver::Error: getaddrinfo: nodename nor servname provided, or not known>
Exception trace: ["/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/resolver/system.rb:26:in `getaddress'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/resolver/system.rb:26:in `block in resolve'", "/Users/sergey/.rvm/rubies/ruby-2.6.3/lib/ruby/2.6.0/timeout.rb:93:in `block in timeout'", "/Users/sergey/.rvm/rubies/ruby-2.6.3/lib/ruby/2.6.0/timeout.rb:33:in `block in catch'", "/Users/sergey/.rvm/rubies/ruby-2.6.3/lib/ruby/2.6.0/timeout.rb:33:in `catch'", "/Users/sergey/.rvm/rubies/ruby-2.6.3/lib/ruby/2.6.0/timeout.rb:33:in `catch'", "/Users/sergey/.rvm/rubies/ruby-2.6.3/lib/ruby/2.6.0/timeout.rb:108:in `timeout'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/resolver/system.rb:26:in `resolve'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/tcp/socket.rb:86:in `connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/ssl/socket.rb:62:in `connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/socketry-0.5.1/lib/socketry/tcp/socket.rb:21:in `connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/impl/streaming_http.rb:105:in `open_socket'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/impl/streaming_http.rb:81:in `connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/impl/streaming_http.rb:26:in `initialize'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:218:in `new'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:218:in `block in connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:208:in `loop'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:208:in `connect'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:184:in `run_stream'", "/Users/sergey/.rvm/gems/ruby-2.6.3/gems/ld-eventsource-1.0.1/lib/ld-eventsource/client.rb:120:in `block in initialize'"]

SDK version
ldclient-rb (5.5.6)

OS/platform
Mac Catalina

[eli-darkly]

Do I understand correctly that it was repeating those connection attempts with no delays in between? Like, do you have a larger sample of the log with timestamps? The SDK is not supposed to retry failed connections immediately, and we haven't seen it behave in this way. I also can't think of any reason that the specific type of network failure (DNS query failing, vs. network not being available at all even though wifi is active) would make any difference to its behavior; those are both just I/O exceptions as far as it's concerned.

(By the way, 5.5.6 is not the latest version of the SDK; it is just the last version that was released under the gem name ldclient-rb. The new gem is launchdarkly-server-sdk as you'll see in the 5.5.6 release notes; the latest version is 5.6.2. But I'm not aware of any changes in between 5.5.6 and 5.6.2 involving the stream reconnection behavior.)

[eli-darkly]

I would also be curious to know whether you've been able to reproduce this behavior after the initial incident.

[dzirtusss]

I guess I don't have that log. It was looking a following way - rails console was opened and log was scrolling like crazy with that same error 🤷‍♂ From processes it was ruby only throttling, other were ok.

Overall I guess surely it is not very common, but just keep an eye on this, maybe add some non-linear safeguards somewhere, e.g. like sidekiq do 1, 2, 5, 15, 30 etc.

[eli-darkly]

maybe add some non-linear safeguards somewhere, e.g. like sidekiq do 1, 2, 5, 15, 30 etc.

Well, that's why I'm having some trouble understanding how this could happen: we do explicitly use exponential backoff logic. So if there is some way to make it skip that logic, I don't know what it is (which is why I was asking if you've been able to reproduce the problem).

[eli-darkly]

We did find a bug that could cause the delay to be skipped, and it was fixed in the 5.7.1 release. At that time we forgot to check against open issues so I did not flag it as a fix for this issue, but I'm fairly sure that it's the same problem you ran into. The reason I didn't manage to reproduce it earlier, I think, was that it would not happen if you interrupted the connection too soon after starting the SDK— only if the app had bee running for a little while.

So I'm going to close this issue, but please feel free to reopen it if you think that the fix did not address your situation.

[jacobbeasley]

We've been having similar issues in a client environment since rolling out Launch Darkly. It caused our apps to run 5 CPU x 60 instances of our app (whereas it used to run about 20 instances at 0.3 CPU each). Usually it is proceeded by some kind of network error. We are using version 6.4.0. Rebooting all our apps fixes it temporarily.

I see this was supposed to have been fixed, but I'm curious what the ultimate root cause was and which commit in particular fixed this, and whether a similar issue might exist in version 6.4.0.