Rails active support log subscribers #2690
Conversation
solnic
force-pushed
the
2605-rails-active-support-log-subscribers
branch
4 times, most recently
from
e2de725 to
10b1acd
Compare
solnic
force-pushed
the
2605-rails-active-support-log-subscribers
branch
2 times, most recently
from
e9a1bb4 to
6a8cea8
Compare
solnic
force-pushed
the
2605-rails-active-support-log-subscribers
branch
from
6a8cea8 to
be03827
Compare
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## master #2690 +/- ##
==========================================
- Coverage 97.44% 97.21% -0.23%
==========================================
Files 136 144 +8
Lines 5317 5645 +328
==========================================
+ Hits 5181 5488 +307
- Misses 136 157 +21
🚀 New features to boost your workflow:
|
There was a problem hiding this comment.
mainly left comments on
- overhead
- configuration api
some more high level feedback:
I would have much preferred this to be a simple proxy of just passing through to our logger whatever rails emits. Instead, now we have special loggers for each component. I will not block this if you are ok with maintaining all this extra code (I do not like maintaining a lot of code, my personal preference.)
Further, there is now a lot of duplication of logic between
- breadcrumbs
- logger
- tracing
To reiterate from a business point of view, Logging is mainly a high volume trace connected feed of events, whereas Tracing is a much more curated instrumentation experience and they both have their place. The way this PR is makes Logging very similar to Performance.
| @@ -2,6 +2,8 @@ | |||
|
|
|||
| module Sentry | |||
| module TestHelper | |||
| module_function | |||
There was a problem hiding this comment.
@sl0thentr0py makes it possible to call methods as class methods too, or include them as RSpec example helpers. Very handy IMO.
| @@ -63,6 +62,14 @@ def teardown_sentry_test | |||
| Sentry::Scope.global_event_processors.clear | |||
| end | |||
|
|
|||
| def clear_sentry_events | |||
| if Sentry.initialized? && Sentry.configuration.enable_logs | |||
| [Sentry.get_current_client.transport, Sentry.logger].each do |obj| | |||
There was a problem hiding this comment.
this will only clear the transport if enable_logs is on
| # File path for DebugStructuredLogger to log events to. If not set, defaults to a temporary file. | ||
| # This is useful for debugging and testing structured logging. | ||
| # @return [String, nil] | ||
| attr_accessor :sdk_debug_structured_logger_log_file |
There was a problem hiding this comment.
I do not like that we are polluting the main configuration namespace with this debug stuff, would prefer they be passed as init arguments to DebugStructuredLogger.new and instead of structured_logger_class we just have structured_logger where you can pass in your own instance.
There was a problem hiding this comment.
@sl0thentr0py are you OK with cleaning that up in a separate PR?
| EMPTY_HASH = {}.freeze | ||
|
|
||
| if ::Rails.version.to_f >= 6.0 | ||
| def self.backend |
There was a problem hiding this comment.
these do not need to be methods, just make a class variable
| @@ -3,6 +3,8 @@ | |||
| ### Feature | |||
|
|
|||
| - Propagated sampling rates as specified in [Traces](https://develop.sentry.dev/sdk/telemetry/traces/#propagated-random-value) docs ([#2671](https://github.com/getsentry/sentry-ruby/pull/2671)) | |||
| - Support for Rails ActiveSupport log subscribers ([#2690](https://github.com/getsentry/sentry-ruby/pull/2690)) | |||
There was a problem hiding this comment.
need a detailed changelog entry for how to use this stuff
|
|
||
| def initialize | ||
| @enabled = false | ||
| @subscribers = {} |
There was a problem hiding this comment.
when enabled is set to true, we should populate a set of sane subscribers by default
| end | ||
|
|
||
| if ::Rails.version.to_f >= 6.1 | ||
| def extract_db_config_from_connection(connection) |
There was a problem hiding this comment.
Logging is supposed to be extremely low overhead because the volume is very high. If any of these branches are potentially expensive or incur an extra db connection, I would err on the side of leaving this data out in those cases instead of trying to be too smart to find it.
So basically, just take it simply if it exists otherwise let it not be there.
We already have a full fledged tracing product and if people want complete instrumentation, they are supposed to use Performance and not just Logging.
![cursor[bot]](https://avatars.githubusercontent.com/in/1210556?s=60&v=4){kind=small}
| obj.clear if obj.respond_to?(:clear) | ||
| end | ||
| end | ||
| end |
There was a problem hiding this comment.
Bug: Test Pollution: Sentry Transport Not Always Cleared
The clear_sentry_events method now clears the Sentry transport only when enable_logs is true. This can lead to test pollution, as the transport stores all captured events, not just logs, and should be cleared unconditionally during test teardown for proper isolation.
| File.readlines(log_file).map do |line| | ||
| JSON.parse(line) | ||
| end | ||
| end |
There was a problem hiding this comment.
Bug: Log Initialization and Parsing Errors
The logged_events method can raise Errno::ENOENT if the log file hasn't been created yet, as initialize_log_file only makes the directory. It also risks JSON::ParserError if the log file contains invalid JSON, potentially causing crashes.
| # @param event [ActiveSupport::Notifications::Event] The controller action event | ||
| def process_action(event) | ||
| payload = event.payload | ||
| duration = event.time.round(2) |
There was a problem hiding this comment.
Bug: Incorrect Event Duration Calculation
The ActionControllerSubscriber uses event.time to calculate the event duration, but event.time is the event's start timestamp. This results in incorrect duration values being logged for process_action.action_controller events.
Adds log subscribers for common Rails components.
Screenshots
Closes #2605