Open scouttyg opened 1 year ago
Hi @scouttyg , thanks for submitting the issue. Skylight's normalizers are basically just subscribers to (typically) existing events fired by ActiveSupport::Notifications, and wouldn't affect the stack trace. I'm afraid I don't understand what is garbled about the stacktrace in your screenshot; this is more or less what I expect to see in the middleware stack with or without Skylight.
Are you able to post the stacktrace in plain text, and explain how it differs from what you expect to see?
@zvkemp It's hard to paste everything here, but consider the cases below:
Here, above OAuth::Unauthorized, we get only one frame, in the file that the error occurred, but not the parent class, or anything higher level than that. We also get about 300 frames of looping around lines like the following:
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
System
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
System
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
System
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
System
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
System
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
System
This is not what we want, as the file we want loses all it's context (e.g. parent classes, etc), and there's a bunch of unrelated stack tracing that isn't really telling us anything:
After removing skylight, above OAuth::Unauthorized, we get the frame of the file that caused the error, along with the parent class, that parent's class, etc. We also only get about 4-5 frames around the OAuth::Unauthorized section, which is much more clean.
This is much more what we want, as it tells us only the relevant files to the trace at hand:
I believe what you are seeing is a result of the ActionDispatch::MiddlewareStack::InstrumentationProxy
firing the process_middleware.action_dispatch
event. Note that ActiveSupport::Notifications will short-circuit to a different code path if a particular key has no subscribers, so it seems that Skylight is the only thing in your app that listens to that particular event.
@zvkemp
I believe what you are seeing is a result of the ActionDispatch::MiddlewareStack::InstrumentationProxy firing the process_middleware.action_dispatch event. Note that ActiveSupport::Notifications will short-circuit to a different code path if a particular key has no subscribers, so it seems that Skylight is the only thing in your app that listens to that particular event.
Could you expand on this more, and how the conflict between sentry-ruby
, sentry-rails
, and skylight
would cause this long stack trace?
We're wanting more what #2 in my comment above is showing (e.g. a much shorter trace), but I'm unsure how Skylight hooking into the process_middleware.action_dispatch
event would affect our Sentry traces as described here -- except potentially that once Skylight subscribes to the process_middleware.action_dispatch
event, any other things listening for events start listening for them as well (e.g. potentially via https://github.com/getsentry/sentry-ruby/blob/a2d6bbede020fb5b1039a79cdbac135a345a54a0/sentry-rails/lib/sentry/rails/breadcrumb/active_support_logger.rb#L29)
I also know sentry-rails
patches a bit of ActiveSupport::Notifications
(see: https://github.com/getsentry/sentry-ruby/blob/master/sentry-rails/lib/sentry/rails/tracing.rb#LL42C16-L42C50), so maybe there's some sort of circular logic going on here as well, but in general, trying to get more insight into the path forward here to make these two services work well together.
It's not a conflict per-se. You can probably experiment with any notification subscriber to get the same stacktrace (the InstrumentationProxy was a relatively recent addition to Rails, so it's likely not as many things consume it), e.g.
# config/initializers/subscriber_example.rb
ActiveSupport::Notifications.subscribe("process_middleware.action_dispatch") do |*args|
# contents of block not particularly important
end
The repeated frames in the trace are just from calling the same instrumentation methods from all of your middlewares. A brand new rails app has 29 things in the middleware stack, and by default they are all wrapped in InstrumentationProxy, so as long as anything subscribes to that event, the stack will have calls to instrumenter#instrument. Note that this is the ActiveSupport::Notifications instrumenter, (which is a general purpose event fanout) not Skylight's (which sends event data into a Skylight trace).
I believe the question you should ask is what Sentry is doing to filter the stacktraces (in your second gif they are very aggressively limiting the information they show you by default), and why that filter doesn't seem to recognize the pattern in your more verbose example. As I previously said, this was a relatively recent addition for Rails (version 6 I believe?) so it's entirely possible they just don't expect this pattern yet.
@zvkemp
I believe the question you should ask is what Sentry is doing to filter the stacktraces (in your second gif they are very aggressively limiting the information they show you by default), and why that filter doesn't seem to recognize the pattern in your more verbose example. As I previously said, this was a relatively recent addition for Rails (version 6 I believe?) so it's entirely possible they just don't expect this pattern yet.
Hmm, potentially, but at the error line in question there's differences where things were filtered out vs kept in with the combination of the two that would imply other things at play. Here's a few other screenshots:
In the below case, we have the line where the error happened, but then only one more frame through the ..action_dispatch/middleware/stack.rb
:
Here, we not only have the line where the error happened, but the parent class, etc up all the way to the controller level.
In case 1, it looks like the parent of the error at hand goes straight to action_dispatch
, vs the parent class stack, whereas in case 2 it bubbles up correctly. Would this still be the case of how sentry potentially filters the trace, or some sort of hijack mechanism causing the stack trace to move over to action_dispatch
?
As far as I am aware, there's no way to 'hijack' a callstack. Are you viewing the 'raw' stacktraces in their UI, or do you have the 'app only' selector active?
@zvkemp There is indeed a way to view a "Full Stack Trace" vs a minimal one, but even with the full stack trace there is no reference to the parent classes that should have been there:
The full stack trace of the sentry + skylight can't be seen in this picture, but here's a rough copy of it below:
app/services/external_auths/twitter_consumer.rb in rescue in obtain_oauth_access_token at line 77
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack-attack (6.6.1) lib/rack/attack.rb in call at line 127
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rails-settings-cached (2.9.2) lib/rails-settings/middleware.rb in call at line 9
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
warden (1.2.9) lib/warden/manager.rb in block in call at line 36
warden (1.2.9) lib/warden/manager.rb in catch at line 34
warden (1.2.9) lib/warden/manager.rb in call at line 34
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/tempfile_reaper.rb in call at line 15
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/etag.rb in call at line 27
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/conditional_get.rb in call at line 40
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/head.rb in call at line 12
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/http/permissions_policy.rb in call at line 38
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/http/content_security_policy.rb in call at line 36
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/session/abstract/id.rb in context at line 266
rack (2.2.7) lib/rack/session/abstract/id.rb in call at line 260
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/cookies.rb in call at line 704
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/callbacks.rb in block in call at line 27
activesupport (7.0.5) lib/active_support/callbacks.rb in run_callbacks at line 99
actionpack (7.0.5) lib/action_dispatch/middleware/callbacks.rb in call at line 26
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
sentry-rails (5.9.0) lib/sentry/rails/rescued_exception_interceptor.rb in call at line 12
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
ddtrace (1.12.0) lib/datadog/tracing/contrib/rails/middlewares.rb in call at line 19
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/debug_exceptions.rb in call at line 28
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in block (2 levels) in call at line 28
sentry-ruby (5.9.0) lib/sentry/hub.rb in with_session_tracking at line 223
sentry-ruby (5.9.0) lib/sentry-ruby.rb in with_session_tracking at line 385
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in block in call at line 19
sentry-ruby (5.9.0) lib/sentry/hub.rb in with_scope at line 59
sentry-ruby (5.9.0) lib/sentry-ruby.rb in with_scope at line 365
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in call at line 18
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/show_exceptions.rb in call at line 26
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
lograge (0.12.0) lib/lograge/rails_ext/rack/logger.rb in call_app at line 18
railties (7.0.5) lib/rails/rack/logger.rb in block in call at line 25
activesupport (7.0.5) lib/active_support/tagged_logging.rb in block in tagged at line 99
activesupport (7.0.5) lib/active_support/tagged_logging.rb in tagged at line 37
activesupport (7.0.5) lib/active_support/tagged_logging.rb in tagged at line 99
railties (7.0.5) lib/rails/rack/logger.rb in call at line 25
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/remote_ip.rb in call at line 93
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
request_store (1.5.1) lib/request_store/middleware.rb in call at line 19
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/request_id.rb in call at line 26
skylight (5.3.4) lib/skylight/probes/action_dispatch/request_id.rb in call at line 8
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/method_override.rb in call at line 24
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/runtime.rb in call at line 22
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
activesupport (7.0.5) lib/active_support/cache/strategy/local_cache_middleware.rb in call at line 29
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/executor.rb in call at line 14
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/static.rb in call at line 23
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack (2.2.7) lib/rack/sendfile.rb in call at line 110
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
actionpack (7.0.5) lib/action_dispatch/middleware/host_authorization.rb in call at line 131
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
skylight (5.3.4) lib/skylight/middleware.rb in call at line 99
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
rack-cors (2.0.1) lib/rack/cors.rb in call at line 102
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
ddtrace (1.12.0) lib/datadog/tracing/contrib/rack/middlewares.rb in call at line 98
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in block in call at line 61
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_dispatch/middleware/stack.rb in call at line 60
railties (7.0.5) lib/rails/engine.rb in call at line 530
puma (6.3.0) lib/puma/configuration.rb in call at line 270
puma (6.3.0) lib/puma/request.rb in block in handle_request at line 100
puma (6.3.0) lib/puma/thread_pool.rb in with_force_shutdown at line 344
puma (6.3.0) lib/puma/request.rb in handle_request at line 99
puma (6.3.0) lib/puma/server.rb in process_client at line 443
puma (6.3.0) lib/puma/server.rb in block in run at line 245
puma (6.3.0) lib/puma/thread_pool.rb in block in spawn_thread at line 151
This is the similar "full stack trace" provided when only sentry is installed (which reduces down correctly)
app/services/external_auths/twitter_consumer.rb in rescue in obtain_oauth_access_token at line 77
app/services/external_auths/twitter_consumer.rb in obtain_oauth_access_token at line 66
app/services/external_auths/twitter_consumer.rb in external_auth_by_request_token! at line 17
app/controllers/oauth/twitter_controller.rb in verify at line 18
actionpack (7.0.5) lib/action_controller/metal/basic_implicit_render.rb in send_action at line 6
actionpack (7.0.5) lib/abstract_controller/base.rb in process_action at line 215
ddtrace (1.12.0) lib/datadog/tracing/contrib/action_pack/action_controller/instrumentation.rb in process_action at line 105
actionpack (7.0.5) lib/action_controller/metal/rendering.rb in process_action at line 165
actionpack (7.0.5) lib/abstract_controller/callbacks.rb in block in process_action at line 234
activesupport (7.0.5) lib/active_support/callbacks.rb in block in run_callbacks at line 118
sentry-rails (5.9.0) lib/sentry/rails/controller_transaction.rb in block in sentry_around_action at line 17
sentry-ruby (5.9.0) lib/sentry/hub.rb in block in with_child_span at line 109
sentry-ruby (5.9.0) lib/sentry/span.rb in with_child_span at line 169
sentry-ruby (5.9.0) lib/sentry/hub.rb in with_child_span at line 107
sentry-ruby (5.9.0) lib/sentry-ruby.rb in with_child_span at line 456
sentry-rails (5.9.0) lib/sentry/rails/controller_transaction.rb in sentry_around_action at line 14
activesupport (7.0.5) lib/active_support/callbacks.rb in block in run_callbacks at line 127
activesupport (7.0.5) lib/active_support/callbacks.rb in run_callbacks at line 138
actionpack (7.0.5) lib/abstract_controller/callbacks.rb in process_action at line 233
actionpack (7.0.5) lib/action_controller/metal/rescue.rb in process_action at line 22
actionpack (7.0.5) lib/action_controller/metal/instrumentation.rb in block in process_action at line 67
activesupport (7.0.5) lib/active_support/notifications.rb in block in instrument at line 206
activesupport (7.0.5) lib/active_support/notifications/instrumenter.rb in instrument at line 24
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
activesupport (7.0.5) lib/active_support/notifications.rb in instrument at line 206
actionpack (7.0.5) lib/action_controller/metal/instrumentation.rb in process_action at line 66
actionpack (7.0.5) lib/action_controller/metal/params_wrapper.rb in process_action at line 259
activerecord (7.0.5) lib/active_record/railties/controller_runtime.rb in process_action at line 27
actionpack (7.0.5) lib/abstract_controller/base.rb in process at line 151
actionpack (7.0.5) lib/action_controller/metal.rb in dispatch at line 188
actionpack (7.0.5) lib/action_controller/metal.rb in dispatch at line 251
actionpack (7.0.5) lib/action_dispatch/routing/route_set.rb in dispatch at line 49
actionpack (7.0.5) lib/action_dispatch/routing/route_set.rb in serve at line 32
actionpack (7.0.5) lib/action_dispatch/journey/router.rb in block in serve at line 50
actionpack (7.0.5) lib/action_dispatch/journey/router.rb in each at line 32
actionpack (7.0.5) lib/action_dispatch/journey/router.rb in serve at line 32
actionpack (7.0.5) lib/action_dispatch/routing/route_set.rb in call at line 852
flipper (0.28.0) lib/flipper/middleware/memoizer.rb in memoized_call at line 72
flipper (0.28.0) lib/flipper/middleware/memoizer.rb in call at line 37
omniauth (2.1.1) lib/omniauth/strategy.rb in call! at line 202
omniauth (2.1.1) lib/omniauth/strategy.rb in call at line 169
omniauth (2.1.1) lib/omniauth/builder.rb in call at line 44
rack-attack (6.6.1) lib/rack/attack.rb in call at line 127
rails-settings-cached (2.9.2) lib/rails-settings/middleware.rb in call at line 9
warden (1.2.9) lib/warden/manager.rb in block in call at line 36
warden (1.2.9) lib/warden/manager.rb in catch at line 34
warden (1.2.9) lib/warden/manager.rb in call at line 34
rack (2.2.7) lib/rack/tempfile_reaper.rb in call at line 15
rack (2.2.7) lib/rack/etag.rb in call at line 27
rack (2.2.7) lib/rack/conditional_get.rb in call at line 40
rack (2.2.7) lib/rack/head.rb in call at line 12
actionpack (7.0.5) lib/action_dispatch/http/permissions_policy.rb in call at line 38
actionpack (7.0.5) lib/action_dispatch/http/content_security_policy.rb in call at line 36
rack (2.2.7) lib/rack/session/abstract/id.rb in context at line 266
rack (2.2.7) lib/rack/session/abstract/id.rb in call at line 260
actionpack (7.0.5) lib/action_dispatch/middleware/cookies.rb in call at line 704
actionpack (7.0.5) lib/action_dispatch/middleware/callbacks.rb in block in call at line 27
activesupport (7.0.5) lib/active_support/callbacks.rb in run_callbacks at line 99
actionpack (7.0.5) lib/action_dispatch/middleware/callbacks.rb in call at line 26
sentry-rails (5.9.0) lib/sentry/rails/rescued_exception_interceptor.rb in call at line 12
ddtrace (1.12.0) lib/datadog/tracing/contrib/rails/middlewares.rb in call at line 19
actionpack (7.0.5) lib/action_dispatch/middleware/debug_exceptions.rb in call at line 28
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in block (2 levels) in call at line 28
sentry-ruby (5.9.0) lib/sentry/hub.rb in with_session_tracking at line 223
sentry-ruby (5.9.0) lib/sentry-ruby.rb in with_session_tracking at line 385
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in block in call at line 19
sentry-ruby (5.9.0) lib/sentry/hub.rb in with_scope at line 59
sentry-ruby (5.9.0) lib/sentry-ruby.rb in with_scope at line 365
sentry-ruby (5.9.0) lib/sentry/rack/capture_exceptions.rb in call at line 18
actionpack (7.0.5) lib/action_dispatch/middleware/show_exceptions.rb in call at line 26
lograge (0.12.0) lib/lograge/rails_ext/rack/logger.rb in call_app at line 18
railties (7.0.5) lib/rails/rack/logger.rb in block in call at line 25
activesupport (7.0.5) lib/active_support/tagged_logging.rb in block in tagged at line 99
activesupport (7.0.5) lib/active_support/tagged_logging.rb in tagged at line 37
activesupport (7.0.5) lib/active_support/tagged_logging.rb in tagged at line 99
railties (7.0.5) lib/rails/rack/logger.rb in call at line 25
actionpack (7.0.5) lib/action_dispatch/middleware/remote_ip.rb in call at line 93
request_store (1.5.1) lib/request_store/middleware.rb in call at line 19
actionpack (7.0.5) lib/action_dispatch/middleware/request_id.rb in call at line 26
rack (2.2.7) lib/rack/method_override.rb in call at line 24
rack (2.2.7) lib/rack/runtime.rb in call at line 22
activesupport (7.0.5) lib/active_support/cache/strategy/local_cache_middleware.rb in call at line 29
actionpack (7.0.5) lib/action_dispatch/middleware/executor.rb in call at line 14
actionpack (7.0.5) lib/action_dispatch/middleware/static.rb in call at line 23
rack (2.2.7) lib/rack/sendfile.rb in call at line 110
actionpack (7.0.5) lib/action_dispatch/middleware/host_authorization.rb in call at line 131
rack-cors (2.0.1) lib/rack/cors.rb in call at line 102
ddtrace (1.12.0) lib/datadog/tracing/contrib/rack/middlewares.rb in call at line 98
railties (7.0.5) lib/rails/engine.rb in call at line 530
puma (6.3.0) lib/puma/configuration.rb in call at line 270
puma (6.3.0) lib/puma/request.rb in block in handle_request at line 100
puma (6.3.0) lib/puma/thread_pool.rb in with_force_shutdown at line 344
puma (6.3.0) lib/puma/request.rb in handle_request at line 99
puma (6.3.0) lib/puma/server.rb in process_client at line 443
puma (6.3.0) lib/puma/server.rb in block in run at line 245
puma (6.3.0) lib/puma/thread_pool.rb in block in spawn_thread at line 151
@zvkemp Interesting to note, the first mentioned "bad" trace above is 250 lines long, which makes me wonder if the STACKTRACE_FRAME_LIMIT_ON_OVERSIZED_PAYLOAD
plays a role here, because even though it is set to 500, 250 frames is supposedly taken from both sides (e.g. see comment here: https://github.com/getsentry/sentry-ruby/issues/2018#issuecomment-1458516216) which makes me wonder if this is where the trimming is occuring in some way.
If true, it could be discarding additional frames, which could be causing the issue at hand. Let me look more into this avenue as well, and thank you for your patience.
I had similar issues with Sentry returning big backtraces with a lot of irrelevant traces, I've solved it by adding a backtrace_cleanup_callback to the Sentry config.
Give it a try in your config/initializers/sentry.rb
Sentry.init do |config|
# Add silencers for irrelevant notifications and sentry backtraces
config.backtrace_cleanup_callback = ->(backtrace) do
cleaner = ActiveSupport::BacktraceCleaner.new
cleaner.remove_silencers!
cleaner.add_silencer do |line|
line =~ %r{active_support/notifications|sentry/rails/tracing|action_dispatch/middleware/stack}
end
cleaner.clean(backtrace)
end
end
We use the following tech stack:
rails (7.0.5)
skylight (5.3.4)
sentry-rails (5.9.0)
sentry-ruby (5.9.0)
And unfortunately, we've been having some trouble with stack traces on Sentry getting super garbled. You can see the report on the sentry-ruby Github here: https://github.com/getsentry/sentry-ruby/issues/1863
I explained a bit of what we were seeing in this comment here: https://github.com/getsentry/sentry-ruby/issues/1863#issuecomment-1582842442, but in a nutshell, stack traces look like the following:
Basically one good frame, and then a bunch of seemingly looping frames.
The lines I see regarding skylight and sentry in the garbled stack are:
skylight (5.3.4) lib/skylight/middleware.rb in call at line 99
sentry-rails (5.9.0) lib/sentry/rails/tracing.rb in instrument at line 54
skylight (5.3.4) lib/skylight/probes/action_dispatch/request_id.rb in call at line 8
When I disable Skylight's
process_middleware.action_dispatch
Normalizer (e.g. https://github.com/skylightio/skylight-ruby/blob/master/lib/skylight/normalizers/action_dispatch/process_middleware.rb) it looks like the logs calm down, but I couldn't trace any further than that. Something with what the instrumenter is doing.Just figured I'd submit this issue here as well, in case there was any insights that could be gleamed, although the issue seems to be the interaction of these two different libraries together.