Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Infinite Stack Recursion with HTTP #1999

Closed
saulshanabrook opened this issue Feb 6, 2023 · 14 comments
Closed

Infinite Stack Recursion with HTTP #1999

saulshanabrook opened this issue Feb 6, 2023 · 14 comments
Assignees

Comments

@saulshanabrook
Copy link

saulshanabrook commented Feb 6, 2023

Issue Description

Hello!

I am coming across an error trying to use the sentry ruby bindings on with a rails app, during a rake task. The task uploads the precompiled assets to an S3 server. It exits cleanly without the sentry integration, but when I add it, it enters into an infinitely recursive loop with the patched HTTP module. I am not sure how to debug this further or what to do.

Thank you!

Reproduction Steps

edited with simpler steps:

$ git clone https://github.com/saulshanabrook/discourse-hosting
$ cd discourse-hosting
$ echo 'HOSTNAME=any-domain.com' > .env
$ docker compose run --rm upload_assets

Following the steps of https://github.com/saulshanabrook/discourse-hosting#local-development-with-docker-compose the error will be raised when running docker compose run --rm upload_assets:

Expected Behavior

The command exits cleanly without an error

Actual Behavior

It raises a SystemStackError:

$ docker compose run --rm upload_assets
[+] Running 4/0
  Container discourse-hosting-db-1             Running 0.0s
  Container discourse-hosting-minio-1          Running 0.0s
  Container discourse-hosting-redis-1          Running 0.0s
  Container discourse-hosting-glitchtip-web-1  Running 0.0s
** Invoke s3:upload_assets (first_time)
** Invoke environment (first_time)
** Execute environment
** Invoke s3:ensure_cors_rules (first_time)
** Invoke environment 
** Execute s3:ensure_cors_rules
** Execute s3:upload_assets
rake aborted!
SystemStackError: stack level too deep
...
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35:in `block in request'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry-ruby.rb:446:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:32:in `request'
(eval):5:in `request'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35:in `block in request'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry-ruby.rb:446:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:32:in `request'
(eval):5:in `request'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35:in `block in request'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry-ruby.rb:446:in `with_child_span'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:32:in `request'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/connection_pool.rb:348:in `request'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/handler.rb:79:in `block in transmit'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/handler.rb:133:in `block in session'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/connection_pool.rb:104:in `session_for'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/handler.rb:128:in `session'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/handler.rb:76:in `transmit'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/handler.rb:50:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/plugins/content_length.rb:24:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/plugins/request_callback.rb:85:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/s3_signer.rb:132:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/s3_signer.rb:63:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/s3_host_id.rb:17:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/xml/error_handler.rb:10:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/transfer_encoding.rb:26:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/helpful_socket_errors.rb:12:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/s3_signer.rb:110:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/redirects.rb:20:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/retry_errors.rb:360:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/http_checksum.rb:19:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/endpoint_pattern.rb:30:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/accelerate.rb:67:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/checksum_algorithm.rb:136:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/bucket_dns.rb:35:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/dualstack.rb:41:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/expect_100_continue.rb:22:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/bucket_name_restrictions.rb:26:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/arn.rb:62:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/rest/handler.rb:10:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/recursion_detection.rb:18:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/user_agent.rb:13:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/plugins/endpoint.rb:47:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/param_validator.rb:26:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/arn.rb:88:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/sse_cpk.rb:24:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/dualstack.rb:27:in `call'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/plugins/accelerate.rb:56:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/checksum_algorithm.rb:111:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/jsonvalue_converter.rb:22:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/idempotency_token.rb:19:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/param_converter.rb:26:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/plugins/request_callback.rb:71:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/plugins/response_paging.rb:12:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/plugins/response_target.rb:24:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/request.rb:72:in `send_request'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/poller.rb:65:in `send_request'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/poller.rb:51:in `call'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:107:in `block in poll'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:104:in `loop'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:104:in `poll'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:94:in `block (2 levels) in wait'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:93:in `catch'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:93:in `block in wait'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:92:in `catch'
/usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/aws-sdk-core/waiters/waiter.rb:92:in `wait'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/waiters.rb:123:in `wait'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/bucket.rb:98:in `wait_until_exists'
/usr/local/bundle/gems/aws-sdk-s3-1.114.0/lib/aws-sdk-s3/bucket.rb:79:in `exists?'
/var/www/discourse/lib/s3_helper.rb:404:in `s3_bucket'
/var/www/discourse/lib/s3_helper.rb:240:in `list'
/var/www/discourse/lib/tasks/s3.rake:14:in `existing_assets'
/var/www/discourse/lib/tasks/s3.rake:24:in `should_skip?'
/var/www/discourse/lib/tasks/s3.rake:36:in `upload'
/var/www/discourse/lib/tasks/s3.rake:192:in `block (2 levels) in <main>'
/var/www/discourse/lib/tasks/s3.rake:192:in `each'
/var/www/discourse/lib/tasks/s3.rake:192:in `block in <main>'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
/usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/rake.rb:26:in `execute'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:160:in `invoke_task'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block (2 levels) in top_level'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `each'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block in top_level'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:125:in `run_with_threads'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:110:in `top_level'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:83:in `block in run'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
/usr/local/lib/ruby/gems/3.1.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
/usr/local/bin/rake:25:in `load'
/usr/local/bin/rake:25:in `<top (required)>'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli.rb:486:in `exec'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli.rb:31:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli.rb:25:in `start'
/usr/local/bundle/gems/bundler-2.3.22/exe/bundle:48:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.3.22/lib/bundler/friendly_errors.rb:120:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.3.22/exe/bundle:36:in `<top (required)>'
/usr/local/bundle/bin/bundle:25:in `load'
/usr/local/bundle/bin/bundle:25:in `<main>'
Tasks: TOP => s3:upload_assets

Ruby Version

3.1

SDK Version

sentry-ruby-5.8.0

Integration and Its Version

No response

Sentry Config

Sentry.init do |config|

  # this gem also provides a new breadcrumb logger that accepts instrumentations from ActiveSupport
  # it's not activated by default, but you can enable it with
  # config.breadcrumbs_logger = [:active_support_logger]

  config.dsn =  ENV['SENTRY_DSN']
end
@st0012
Copy link
Collaborator

st0012 commented Feb 6, 2023

@saulshanabrook Thanks for reporting this, but can you simplify the reproduction steps down to just a Ruby/Rails application? The amount of dependencies and manual operations required to run it seems to be quite high:

  1. Install docker
  2. Install docker compose
  3. Tweaking my /etc/hosts
  4. Find a place to configure Sentry integration

I gave up on step 3 because I don't feel comfortable changing system configs (even harmless) for reproducing an issue that doesn't require it.

@sl0thentr0py
Copy link
Member

@saulshanabrook also is this a regression introduced by 5.8.0 (since that's the version in your issue) or does it also happen on older versions?

@sl0thentr0py
Copy link
Member

ok so what is happening is this super is going back to the same patched request for some reason, still don't know why.

@saulshanabrook can you print Net::HTTP.ancestors after sticking a binding.pry/debugger in your rake task?

@saulshanabrook
Copy link
Author

@st0012 Yeah, that totally makes sense about the complicated reproduction steps.

I have tested this to reproduce the bug, which doesn't require messing with hosts, getting a sentry config, or having a domain:

$ git clone https://github.com/saulshanabrook/discourse-hosting
$ cd discourse-hosting
$ echo 'HOSTNAME=any-domain.com' > .env
$ docker compose run --rm upload_assets

Let me know if that doesn't work to reproduce it.

@saulshanabrook
Copy link
Author

@sl0thentr0py I was just starting to use sentry with this project. I tried it with 5.7.0 a few weeks ago when that was the latest, was hitting the same error, upgraded to 5.8.0 to see if it would fix it but to no avail. Do you recommend I try downgrading to an earlier version?

@saulshanabrook
Copy link
Author

@sl0thentr0py Sure, is this what you mean? I believe it's [Sentry::Net::HTTP]

$ docker compose run --rm upload_assets rdbg -c --  bundle exec rake --trace s3:upload_assets
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "SECRET_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "DSN" variable is not set. Defaulting to a blank string.
WARN[0000] The "DSN" variable is not set. Defaulting to a blank string.
WARN[0000] The "EMAIL" variable is not set. Defaulting to a blank string.
WARN[0000] The "SECRET_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "DSN" variable is not set. Defaulting to a blank string.
WARN[0000] The "DSN" variable is not set. Defaulting to a blank string.
WARN[0000] The "SECRET_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "DSN" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "SECRET_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "EMAIL" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "EMAIL" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "EMAIL" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
WARN[0000] The "EMAIL" variable is not set. Defaulting to a blank string.
WARN[0000] The "SEND_GRID_API_KEY" variable is not set. Defaulting to a blank string.
[+] Running 4/0
 ⠿ Container discourse-hosting-minio-1          Running                                                                                                                                  0.0s
 ⠿ Container discourse-hosting-redis-1          Running                                                                                                                                  0.0s
 ⠿ Container discourse-hosting-db-1             Running                                                                                                                                  0.0s
 ⠿ Container discourse-hosting-glitchtip-web-1  Running                                                                                                                                  0.0s
[4, 13] in /usr/local/bin/rake
     4| #
     5| # The application 'rake' is installed as part of a gem, and
     6| # this file is here to facilitate running it.
     7| #
     8|
=>   9| require 'rubygems'
    10|
    11| Gem.use_gemdeps
    12|
    13| version = ">= 0.a"
=>#0	<top (required)> at /usr/local/bin/rake:9
  #1	[C] Kernel.load at /usr/local/bundle/gems/bundler-2.3.22/lib/bundler/cli/exec.rb:58
  # and 14 frames (use `bt' command for all frames)
(rdbg) b /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35    # break command
#0  BP - Line (pending)  /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35
(rdbg) c    # continue command
** Invoke s3:upload_assets (first_time)
** Invoke environment (first_time)
** Execute environment
** Invoke s3:ensure_cors_rules (first_time)
** Invoke environment
** Execute s3:ensure_cors_rules
Installing CORS rules...
skipping
** Execute s3:upload_assets
[30, 39] in /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb
    30|         return super if from_sentry_sdk?
    31|
    32|         Sentry.with_child_span(op: OP_NAME, start_timestamp: Sentry.utc_now.to_f) do |sentry_span|
    33|           set_sentry_trace_header(req, sentry_span)
    34|
=>  35|           super.tap do |res|
    36|             record_sentry_breadcrumb(req, res)
    37|
    38|             if sentry_span
    39|               request_info = extract_request_info(req)
=>#0	block {|sentry_span=nil|} in request at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35
  #1	Sentry::Hub#with_child_span(instrumenter=:sentry, attributes={:op=>"http.client", :start_timestamp=>16..., block=#<Proc:0x00007f9058c78a40 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100
  # and 102 frames (use `bt' command for all frames)

Stop by #0  BP - Line  /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35 (line)
(ruby) Net::HTTP.ancestors
[Sentry::Net::HTTP]

@sl0thentr0py
Copy link
Member

no i just wanted to know if this was a regression or not. In that case downgrading won't help, we'll need to find the problem in this setup and fix it.

@saulshanabrook
Copy link
Author

saulshanabrook commented Feb 8, 2023

I am also getting the same problem in the main server, I believe in a sidekiq worker process:

[Transport] Sending envelope with items [sessions]  to Sentry
exception happened in background worker: stack level too deep

Discourse also captures some of the stacktrace:

Screenshot 2023-02-08 at 1 38 13 PM

Let me know if you have any ideas on ways to troubleshoot this!

@sl0thentr0py
Copy link
Member

sl0thentr0py commented Feb 9, 2023

ok some investigation, still not sure what the issue is.

discourse has the following in their gemfile (faraday with explicit net-http gem)
https://github.com/discourse/discourse/blob/main/Gemfile#L269-L274

and then you're adding sentry manually in the Dockerfile with bundle add
https://github.com/saulshanabrook/discourse-hosting/blob/f880f8d714fc614535e96d0114203a67c529a854/Dockerfile#L50-L52

@st0012 do you see any problems with the patching in this scenario?

Normally the ancestors should look like this

[1] pry(main)> Net::HTTP.ancestors
=> [Sentry::Net::HTTP, Net::HTTP, Net::Protocol, Object, PP::ObjectMixin, JSON::Ext::Generator::GeneratorMethods::Object, Kernel, BasicObject]

while you have just Sentry::Net::HTTP in there which is suspicious.

@saulshanabrook
Copy link
Author

@sl0thentr0py I tried adding RUN bundle remove net-http to the end of my Dockerfile, but that didn't change it FYI.

@sl0thentr0py sl0thentr0py self-assigned this Feb 10, 2023
@st0012
Copy link
Collaborator

st0012 commented Feb 12, 2023

It's because discourse injects method_profiler, which uses alias_method to patch the request method. And because sentry-ruby uses prepend in Sentry::Net::HTTP, the 2 conflicts and causes infinite loop.

We had several cases like this:

Given that more and more tools use prepend now, I'd recommend them to use prepend as well to avoid conflicts with other tools. But it could be a big change if all their patches are implemented with alias_method.


Debugging note: As a major contributor of the debug gem, I was surprised to see you use it in this report, which helped me quite a lot. Thank you 😄

I based my investigation on the command you provided:

  1. Enter the same breakpoint you set
  2. bt 10 - list closest 10 frames
=>#0	block {|sentry_span=nil|} in request at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35
  #1	Sentry::Hub#with_child_span(instrumenter=:sentry, attributes={:op=>"http.client", :start_timestamp=>16..., block=#<Proc:0x0000ffff882e94c8 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100
  #2	Sentry.with_child_span(attributes={:op=>"http.client", :start_timestamp=>16..., block=#<Proc:0x0000ffff882e9478 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry-ruby.rb:446
  #3	Sentry::Net::HTTP#request__mp_unpatched(req=#<Net::HTTP::Head HEAD>, body=nil, block=#<Proc:0x0000ffff89fac7e0 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:32
  #4	Net::HTTP#request(args=[#<Net::HTTP::Head HEAD>, nil], blk=#<Proc:0x0000ffff89fac7e0 /usr/local/bund...) at (eval):5
  #5	block {|sentry_span=nil|} in request at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:35
  #6	Sentry::Hub#with_child_span(instrumenter=:sentry, attributes={:op=>"http.client", :start_timestamp=>16..., block=#<Proc:0x0000ffff89fac718 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/hub.rb:100
  #7	Sentry.with_child_span(attributes={:op=>"http.client", :start_timestamp=>16..., block=#<Proc:0x0000ffff89fac6a0 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry-ruby.rb:446
  #8	Sentry::Net::HTTP#request(req=#<Net::HTTP::Head HEAD>, body=nil, block=#<Proc:0x0000ffff89fac7e0 /usr/local/bund...) at /usr/local/bundle/gems/sentry-ruby-5.8.0/lib/sentry/net/http.rb:32
  #9	Seahorse::Client::NetHttp::ConnectionPool::ExtendedSession#request(args=[#<Net::HTTP::Head HEAD>], block=#<Proc:0x0000ffff89fac588 /usr/local/bund...) at /usr/local/bundle/gems/aws-sdk-core-3.130.2/lib/seahorse/client/net_http/connection_pool.rb:348
  1. f 4 - because (eval):5 looks fishy and I want to see what that frame does.
  2. l - to get the surrounding code:
(rdbg) l    # list command
     1|
     2|
     3| unless defined?(request__mp_unpatched)
     4|   alias_method :request__mp_unpatched, :request
=>   5|   def request(*args, &blk)
     6|     unless prof = Thread.current[:_method_profiler]
     7|       return request__mp_unpatched(*args, &blk)
     8|     end
     9|     return request__mp_unpatched(*args, &blk) if @mp_recurse_protect_request
    10| @mp_recurse_protect_request = true
  1. Once I saw the alias_method, I knew it's the cause. So then I just googled that code piece by piece to find the source.
    • If it's not inside docker, I'd use edit . to open the file in editor right away.

@sl0thentr0py
Copy link
Member

wow great debugging @st0012 !

@sl0thentr0py
Copy link
Member

@saulshanabrook does that answer your question? You'll need to patch discourse upstream to make it work with sentry, I don't think we can do much here. If it resolves your question, please close this issue.

@saulshanabrook
Copy link
Author

Wow @st0012 that is excellent detective work! I had seen the (eval):5 as well but didn't realize that was a discourse block and not a sentry block....

Thank you for your work on the debug gem! I have actually never used ruby before trying to get Discourse up and running and the debugging experience was surprisingly pleasant :)

I posted a topic on the Discourse meta forum about this issue, so I will reply with your suggested fix (replacing use of alias_method with prepend) and use a workaround for now (probably just patching that piece to remove their method profiler).

Thank you all for helping me debug this, I really thought I would just have to give up on using Sentry for this project ❤️.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants