StackLevelTooDeep with version 2 and twilio-ruby gem

[rdunlop]

On my project, I have twilio-ruby 5.31.6 (the latest version), and when I upgraded rack-mini-profiler to 2.0.0, now I get:

SystemStackError: stack level too deep
from /gems/gems/rack-mini-profiler-2.0.0/lib/patches/net_patches.rb:6:in `request'

whenever I try to send an sms message with the twilio api.

If I use version 1.1.6 of rack-mini-profiler, it does not fail.

I don't know what else is a contributing factor in this situation. Any ideas?

[SamSaffron]

Hmm I guess net patches are fighting, is there a simple repro? @OsamaSayegh maybe change it so we prepend the net patches that way it will not fight with another monkey patch, net can afford the marginal slowdown of the prepend.

[rdunlop]

I haven't had time to see if there's a minimal reproduction scenario. I may be able to confirm this soon, but I wanted to open the ticket in case anyone else has issues.

[OsamaSayegh]

The net patches were switched to use module prepend in 2.0.0, see PR https://github.com/MiniProfiler/rack-mini-profiler/pull/429.

@rdunlop I think you already have something that patches Net::HTTP#request using alias_method, which conflicts with the module prepend that mini profiler has and causes the infinite loop you see (see this ruby issue). One way to confirm this is to run Net::HTTP.allocate.methods.select { |m| m =~ /request/ } and look for weird looking methods.

[rdunlop]

@OsamaSayegh thanks for the input, I thought the same thing, but I'm having difficulty figuring out how to determine what else might patch Net:HTTP#request.

> Net::HTTP.allocate.methods.select { |m| m =~ /request/ }
=> [:request, :send_request, :request_without_sk, :request_get, :request_head, :request_post, :request_put]

Ah, I see, thanks! I've found it: With rack-mini-profiler installed, I get:

Net::HTTP.allocate.method(:request).source_location
> /gems/gems/rack-mini-profiler-2.0.0/lib/patches/net_patches.rb

With rack-mini-profiler NOT installed, I get:

Net::HTTP.allocate.method(:request).source_location
> /gems/gems/skylight-core-4.2.3/lib/skylight/core/probes/net_http.rb

which a quick search yields https://github.com/skylightio/skylight-ruby/blob/master/skylight-core/lib/skylight/core/probes/net_http.rb#L24.

So, yes, you're right, there was another gem (skylight) interacting poorly here.

Thanks for the assist in tracking this down.

[OsamaSayegh]

I see 2 ways forward here:

1) Revert https://github.com/MiniProfiler/rack-mini-profiler/pull/429 2) Maybe you could send a PR to skylight that changes their Net::HTTP#request patch so that it uses module prepend?

1 would be problematic for the person who sent the PR because they had the same problem as this one, and 2 I don't know if Skylight would be OK with changing the patch to use module prepend.

[SamSaffron]

Lets open a bug on skylight and ask them what they think? At a minimum we should not be at war here both gems are popular enough.

[jean-francois-labbe]

I have the same with ScoutApm

rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:7:in `block in request'
rack-mini-profiler (2.0.0) lib/mini_profiler/profiling_methods.rb:39:in `step'
rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:6:in `request'
scout_apm (2.6.3) lib/scout_apm/instruments/net_http.rb:30:in `block in request_with_scout_instruments'
scout_apm (2.6.3) lib/scout_apm/tracer.rb:34:in `instrument'
scout_apm (2.6.3) lib/scout_apm/tracer.rb:44:in `instrument'
scout_apm (2.6.3) lib/scout_apm/instruments/net_http.rb:29:in `request_with_scout_instruments'
rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:7:in `block in request'
rack-mini-profiler (2.0.0) lib/mini_profiler/profiling_methods.rb:39:in `step'
rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:6:in `request'

[fabioxgn]

This happens with the new_relic_rpm gem too: https://github.com/newrelic/rpm

SystemStackError (stack level too deep):

addressable (2.7.0) lib/addressable/idna/pure.rb:305:in `hash'
addressable (2.7.0) lib/addressable/idna/pure.rb:305:in `lookup_unicode_composition'
addressable (2.7.0) lib/addressable/idna/pure.rb:215:in `unicode_compose_pair'
addressable (2.7.0) lib/addressable/idna/pure.rb:153:in `block in unicode_compose'
activesupport (6.0.2.1) lib/active_support/core_ext/range/each.rb:9:in `each'
activesupport (6.0.2.1) lib/active_support/core_ext/range/each.rb:9:in `each'
addressable (2.7.0) lib/addressable/idna/pure.rb:149:in `unicode_compose'
addressable (2.7.0) lib/addressable/idna/pure.rb:121:in `unicode_normalize_kc'
addressable (2.7.0) lib/addressable/uri.rb:566:in `normalize_component'
addressable (2.7.0) lib/addressable/uri.rb:1126:in `normalized_host'
addressable (2.7.0) lib/addressable/uri.rb:1246:in `normalized_authority'
addressable (2.7.0) lib/addressable/uri.rb:2170:in `normalize'
addressable (2.7.0) lib/addressable/uri.rb:2184:in `normalize!'
newrelic_rpm (6.9.0.363) lib/new_relic/agent/http_clients/uri_util.rb:34:in `parse_and_normalize_url'
newrelic_rpm (6.9.0.363) lib/new_relic/agent/http_clients/net_http_wrappers.rb:53:in `uri'
newrelic_rpm (6.9.0.363) lib/new_relic/agent/instrumentation/net.rb:25:in `request_with_newrelic_trace'
rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:7:in `block in request'
rack-mini-profiler (2.0.0) lib/mini_profiler/profiling_methods.rb:39:in `step'
rack-mini-profiler (2.0.0) lib/patches/net_patches.rb:6:in `request'

[SamSaffron]

oh my ... we can not conflict with both, I say we revert the prepend for now @OsamaSayegh ... I guess there is not clear way of winning here.

[OsamaSayegh]

Ok, I've reverted the prepend commit.

[nateberkopec]

A few reports of this as well from the CGRP Slack. Thanks for the revert 👍

[SamSaffron]

A new gem release is in the oven!

On Tue, Mar 17, 2020 at 11:00 AM Nate Berkopec notifications@github.com wrote:

A few reports of this as well from the CGRP Slack. Thanks for the revert 👍

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/MiniProfiler/rack-mini-profiler/issues/437#issuecomment-599810882, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAABIXLO3VD7JYAWN3W23ITRH24QDANCNFSM4LGV46NA .

[enthusiasmus]

Hi guys! We are using the newest release (2.0.1) and still receive the stack level too deep error, because we are using datadog, which also patches the net class. But I thought the revert and so the 2.0.1 release is all it takes to make the error disappear? Any advice?

{"method":"GET","path":"/action","format":"html","controller":"RandomController","action":"actiona","status":200,"duration":13.1,"view":0.26,"db":1.31,"time":401239.64226398,"http_user_agent":"Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Firefox/68.0","dd":{"trace_id":5970647214373537213,"span_id":5609394670000953193},"ddsource":["ruby"],"current_user_id":null,"remote_ip":"77.2.39.155","@timestamp":"2020-04-21T13:03:08.992Z","@version":"1","message":"[200] GET /async_cart_data (Spree::OrdersController#async_cart_data)"}
#<Thread:0x000056289cc81f98@/usr/local/bundle/gems/airbrake-ruby-4.8.0/lib/airbrake-ruby/thread_pool.rb:120 run> terminated with exception (report_on_exception is true):
/usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/context.rb:281:in `local': stack level too deep (SystemStackError)
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/provider.rb:18:in `context'
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/tracer.rb:103:in `call_context'
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/tracer.rb:356:in `active_span'
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/contrib/http/circuit_breaker.rb:12:in `should_skip_tracing?'
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/contrib/http/instrumentation.rb:35:in `request'
    from /usr/local/bundle/gems/rack-mini-profiler-2.0.1/lib/patches/net_patches.rb:9:in `block in request_with_mini_profiler'
    from /usr/local/bundle/gems/rack-mini-profiler-2.0.1/lib/mini_profiler/profiling_methods.rb:39:in `step'
    from /usr/local/bundle/gems/rack-mini-profiler-2.0.1/lib/patches/net_patches.rb:8:in `request_with_mini_profiler'
     ... 9694 levels...
    from /usr/local/bundle/gems/ddtrace-0.29.1/lib/ddtrace/contrib/http/instrumentation.rb:39:in `request'
    from /usr/local/bundle/gems/airbrake-ruby-4.8.0/lib/airbrake-ruby/sync_sender.rb:37:in `send'
    from /usr/local/bundle/gems/airbrake-ruby-4.8.0/lib/airbrake-ruby/async_sender.rb:57:in `block in thread_pool'
    from /usr/local/bundle/gems/airbrake-ruby-4.8.0/lib/airbrake-ruby/thread_pool.rb:123:in `block in spawn_worker'

Best regards, Lukas

[OsamaSayegh]

@enthusiasmus I looked at datadog source code and I can see they prepend their patch to the Net::HTTP class. In 2.0.1 we reverted to applying our patch using methods aliasing which unfortunately means it'll clash with patches applied using prepend (in your case that's datadog's patch). Version 2.0.0 shouldn't clash with datadog though, were you on version 2.0.0 and it also clashed?

[enthusiasmus]

@OsamaSayegh I installed the 2.0.0 and there are no problems for us! :confetti_ball:

[kjeldahl]

Appsignal also just changed (version 2.10.4) to use prepend which leads to errors when combined with miniprofiler versions other than 2.0.0.

Could it be possible to use the same approach as with the rails patches so it is configurable whether to use prepend or method aliasing?

[OsamaSayegh]

@kjeldahl thanks for the suggestion! As of https://github.com/MiniProfiler/rack-mini-profiler/commit/d7e30177859a43fd0fba0cc54ad04bb4fe37e6a4, we now have a way to configure how the patch is applied 🎉

For people with the same issue coming here from google, see the repo's readme for instructions on how to fix this.