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

The report_rescued_exceptions option is not honoured in a Rails production environment #1840

Closed
matthieuprat opened this issue Jul 6, 2022 · 6 comments · Fixed by #1847
Closed
Assignees
Milestone

Comments

@matthieuprat
Copy link

matthieuprat commented Jul 6, 2022

Issue Description

Setting the report_rescued_exceptions option to false doesn't seem to be effective in a Rails production environment: exceptions rescued by the ActionDispatch::ShowExceptions middleware are reported, but as per the documentation, they shouldn't.

I originally thought this bug was introduced in 7a3a86b but on closer look, I'm actually not sure this is the case. Before this commit, the CaptureExceptions middleware was wrapping the ShowExceptions middleware, so one would be tempted to think that if exceptions were swallowed by the latter, the former wouldn't report them. However, the ShowExceptions middleware sets the exception it swallows in the action_dispatch.exception header and the CaptureExceptions middleware reads this value back to report the exception (regardless of report_rescued_exceptions).

In short, I'm not sure whether this is an actual bug or whether the documentation is wrong.

Reproduction Steps

Add this spec to sentry-rails/spec/sentry/rails_spec.rb:

context "with report_rescued_exceptions = false" do
  before do
    make_basic_app do |config, app|
      app.config.consider_all_requests_local = false
      config.rails.report_rescued_exceptions = false
    end
  end

  it "doesn't report rescued exceptions" do
    get "/exception"

    expect(transport.events.count).to eq(0)
  end
end

Expected Behavior

The spec should pass.

Actual Behavior

The spec fails with the following message:

Failures:

  1) Sentry::Rails with production config with report_rescued_exceptions = false doesn't report rescued exceptions
     Failure/Error: expect(transport.events.count).to eq(0)
     
       expected: 0
            got: 1
     
       (compared using ==)
     # ./spec/sentry/rails_spec.rb:209:in `block (4 levels) in <top (required)>'

Ruby Version

3.0.2

SDK Version

5.3.0

Integration and Its Version

Rails v6.1.4.4

Sentry Config

Sentry.init do |config|
  config.rails.report_rescued_exceptions = false
end
@st0012
Copy link
Collaborator

st0012 commented Jul 10, 2022

@matthieuprat I checked your test case and it does fail. However, I don't think it's captured through the request env.

I used ruby/debug's tracer to see how the exception flows

# the first 2 command checks I'm with the right settings
# the last tells the debugger to trace exception raised with the RuntimeError pattern
debugger(do: "Rails.application.config.consider_all_requests_local ;; Sentry.configuration.rails.report_rescued_exceptions ;; trace exception /RuntimeError/")

get "/exception"

And here's the result:

(rdbg:binding.break) Rails.application.config.consider_all_requests_local
false
(rdbg:binding.break) Sentry.configuration.rails.report_rescued_exceptions
false
(rdbg:binding.break) trace exception /RuntimeError/
Enable ExceptionTracer (enabled) with pattern /RuntimeError/
DEBUGGER (trace/exception) #th:1 #depth:133 #<RuntimeError: An unhandled exception!> at /Users/st0012/projects/sentry-ruby/sentry-rails/spec/dummy/test_rails_app/apps/7-0.rb:76
DEBUGGER (trace/exception) #th:1 #depth:127 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_controller/metal/rescue.rb:25
DEBUGGER (trace/exception) #th:1 #depth:126 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_controller/metal/instrumentation.rb:73
DEBUGGER (trace/exception) #th:1 #depth:124 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/activesupport-7.0.3/lib/active_support/notifications/instrumenter.rb:28
DEBUGGER (trace/exception) #th:1 #depth:97 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/callbacks.rb:30
DEBUGGER (trace/exception) #th:1 #depth:97 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/executor.rb:18
DEBUGGER (trace/exception) #th:1 #depth:96 #<RuntimeError: An unhandled exception!> at /Users/st0012/projects/sentry-ruby/sentry-rails/lib/sentry/rails/rescued_exception_interceptor.rb:15
DEBUGGER (trace/exception) #th:1 #depth:96 #<RuntimeError: An unhandled exception!> at /Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/debug_exceptions.rb:72
DEBUGGER (trace/exception) #th:1 #depth:94 #<RuntimeError: An unhandled exception!> at /Users/st0012/projects/sentry-ruby/sentry-ruby/lib/sentry/rack/capture_exceptions.rb:33
      doesn't report rescued exceptions (FAILED - 1)

If you check the last few traces, you can see it's actually reported via raise/rescue:

/Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/executor.rb:18
/Users/st0012/projects/sentry-ruby/sentry-rails/lib/sentry/rails/rescued_exception_interceptor.rb:15
/Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/debug_exceptions.rb:72
/Users/st0012/projects/sentry-ruby/sentry-ruby/lib/sentry/rack/capture_exceptions.rb:33

But perhaps the RescuedExceptionInterceptor middleware raised it incorrectly? Let's see what happens if we disabled it:

/Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/executor.rb:18
/Users/st0012/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/actionpack-7.0.3/lib/action_dispatch/middleware/debug_exceptions.rb:72
/Users/st0012/projects/sentry-ruby/sentry-ruby/lib/sentry/rack/capture_exceptions.rb:33

The exception raising flow still presents.

So in this case (consider_all_requests_local == false), the exception is always rescued and re-raised. Therefore, the report_rescued_exceptions doesn't apply to it.

@matthieuprat
Copy link
Author

Yes, I think you're right; since 7a3a86b, the exception is no longer captured via the request env. It just bubbles up to the CaptureExceptions middleware that reports it and re-throws it.

Before 7a3a86b, the ShowExceptions middleware would swallow the exception before it would reach the CaptureExceptions middleware. However, the middleware would still report the exception by retrieving it from the request env. (I think.)

My point being that the issue doesn't seem to be new. And fixing it might actually be a breaking change for some people. Hence why I was wondering whether it would make sense to update the docs instead.

@st0012
Copy link
Collaborator

st0012 commented Jul 11, 2022

I don't understand why should we update the doc. In the case, the exception was re-raised by the Rails itself, therefore it's not actually rescued (or swallowed to be precise). So the SDK doesn't report a rescued exception, it's a raised exception.

@matthieuprat
Copy link
Author

matthieuprat commented Jul 11, 2022

Hm, I don't think this is the case. In a production environment (more precisely, when action_dispatch.show_exceptions is true), exceptions are swallowed by the ShowExceptions middleware.

To clarify, the flow is the following:

  1. The exception reaches the RescuedExceptionInterceptor middleware which re-raises it
  2. Then, it reaches the DebugExceptions middleware which also re-raises it
  3. Then, it reaches the CaptureExceptions middleware which reports it and re-raises it
  4. Lastly, it reaches the ShowExceptions middleware which swallows it and renders an error page

In essence, the exception is swallowed by the ShowExceptions middleware but the SDK still reports it (regardless of the value of report_rescued_exceptions).

@st0012
Copy link
Collaborator

st0012 commented Jul 16, 2022

Yes you're correct. Sorry that I was scoped by the cause you mentioned at the beginning.

I think this is a bug and I'll find a way to fix it. Thanks for detailed report 👍

st0012 added a commit that referenced this issue Jul 16, 2022
When an exception is going to be swallowed by ShowExceptions middleware,
we should check the report_rescued_exceptions config before reporting
it.

See #1840 for more details
@st0012 st0012 added this to the 5.4.0 milestone Jul 16, 2022
@matthieuprat
Copy link
Author

No worries, thank you for the quick follow-up!

st0012 added a commit that referenced this issue Jul 18, 2022
* Respect report_rescued_exceptions config

When an exception is going to be swallowed by ShowExceptions middleware,
we should check the report_rescued_exceptions config before reporting
it.

See #1840 for more details

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

Successfully merging a pull request may close this issue.

3 participants