DEBUG-3210 DI: change logging to be appropriate for customer inspection #4230
Conversation
Failure to enable DI is now a warning (since enabling it must have been requested by the customer). Remaining logging calls are now emitted at debug level by default, making those entries not visible in customer logs. An internal DI setting is added to reinstate logging of internal issues at warn level, for developing/debugging DI.
|
👋 Hey @p-datadog, please fill "Change log entry" section in the pull request description. If changes need to be present in CHANGELOG.md you can state it this way **Change log entry**
Yes. A brief summary to be placed into the CHANGELOG.md(possible answers Yes/Yep/Yeah) Or you can opt out like that **Change log entry**
None.(possible answers No/Nope/None) Visited at: 2024-12-16 20:55:24 UTC |
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## master #4230 +/- ##
=======================================
Coverage 97.75% 97.76%
=======================================
Files 1355 1356 +1
Lines 82165 82180 +15
Branches 4207 4211 +4
=======================================
+ Hits 80321 80341 +20
+ Misses 1844 1839 -5 ☔ View full report in Codecov by Sentry. |
| # Logs an internal informational message. | ||
| # When verbose logging is enabled, the logging happens at info level. | ||
| # When verbose logging is disabled, nothing is logged. | ||
| def log_info_internal(msg) | ||
| if settings.dynamic_instrumentation.internal.verbose_logging | ||
| logger.info(msg) | ||
| end | ||
| end |
There was a problem hiding this comment.
Minor: This is a bit unexpected to me; why not log it at debug level as well? E.g. it seems weird that if I enable debug logging with DD_TRACE_DEBUG=true, there's still some logging that won't show up?
| @@ -53,12 +57,12 @@ def environment_supported?(settings) | |||
| # TODO add tests? | |||
| unless settings.dynamic_instrumentation.internal.development | |||
| if Datadog::Core::Environment::Execution.development? | |||
| Datadog.logger.debug("Not enabling dynamic instrumentation because we are in development environment") | |||
| Datadog.logger.warn("Not enabling dynamic instrumentation because we are in development environment") | |||
There was a problem hiding this comment.
Minor: Since this is a customer-visible string, I'd suggest not using the "we" since it's a bit confusing. Here's a potential alternative
| Datadog.logger.warn("Not enabling dynamic instrumentation because we are in development environment") | |
| Datadog.logger.warn("Development environment detected; not enabling dynamic instrumentation") |
| return false | ||
| end | ||
| end | ||
| if RUBY_ENGINE != 'ruby' || RUBY_VERSION < '2.6' | ||
| Datadog.logger.debug("Not enabling dynamic instrumentation because of unsupported Ruby version") | ||
| Datadog.logger.warn("Not enabling dynamic instrumentation because of unsupported Ruby version") |
There was a problem hiding this comment.
For this one, I suggest being a bit more actionable, e.g.
| Datadog.logger.warn("Not enabling dynamic instrumentation because of unsupported Ruby version") | |
| Datadog.logger.warn("Cannot enable dynamic instrumentation: Ruby 2.6+ is required") |
| raise if settings.dynamic_instrumentation.internal.propagate_all_exceptions | ||
| logger.warn("Unhandled exception in line trace point: #{exc.class}: #{exc}") | ||
| log_warn_internal("Unhandled exception in line trace point: #{exc.class}: #{exc}") | ||
| telemetry&.report(exc, description: "Unhandled exception in line trace point") | ||
| # TODO test this path | ||
| end | ||
| rescue => exc | ||
| raise if settings.dynamic_instrumentation.internal.propagate_all_exceptions | ||
| logger.warn("Unhandled exception in line trace point: #{exc.class}: #{exc}") | ||
| log_warn_internal("Unhandled exception in line trace point: #{exc.class}: #{exc}") | ||
| telemetry&.report(exc, description: "Unhandled exception in line trace point") |
There was a problem hiding this comment.
You may want to expose a block-based version of these methods. E.g. right now the whole string is built, even if the logger is going to throw it away.
In other parts of the codebase we often do Datadog.logger.debug do ... end or similar, and that version tends to be cheaper since debug logging is often off so it nopes out without building the string. (This is a common trick for logging libraries)
| module Datadog | ||
| module DI | ||
| # Logging for DI | ||
| module Logging |
There was a problem hiding this comment.
Minor: Since every class that uses Logging ends up needing to get passed a logger object anyway, I wonder if it would make sense to turn this module into an actual class that would have a logger as an instance variable, and then you'd always call methods on this class instead of the logger directly.
This would also solve the potential (small) sharp edge of "oops I included Logging but this class doesn't already have a logger" -- since you know that if you have the object, then you have all that you need.
What does this PR do?
Failure to enable DI is now a warning (since enabling it must have been requested by the customer).
Remaining logging calls are now emitted at debug level by default, making those entries not visible in customer logs.
An internal DI setting is added to reinstate logging of internal issues at warn level, for developing/debugging DI.
Motivation:
DI currently uses the logger for reporting its internal issues. However, the logger normally logs to customer logs, and as such the default logging should be customer-centric, meaning log entries should only be created for matters that the customers understand and can fix.
Change log entry
Dynamic instrumentation: logging of internal conditions is now done on debug level, and these log entries will not be visible by default in customer applications.
Additional Notes:
How to test the change?
Due to the introduction of an additional layer of abstraction for DI logging, end-to-end tests will need to have additional assertions added for log entries being visible (or not). This will be done as part of DEBUG-3210 but is not part of this PR.