Global Log handler cleanup - Logs SDK #2184

lalitb · 2024-10-08T19:25:12Z

Fixes #
Design discussion issue (if applicable) #

Changes

Please provide a brief description of the changes here.

Merge requirement checklist

CONTRIBUTING guidelines followed
Unit tests added/updated (if applicable)
Appropriate CHANGELOG.md files updated for non-trivial, user-facing changes
Changes in public API reviewed (if applicable)

opentelemetry/src/global/internal_logging.rs

codecov · 2024-10-08T19:29:12Z

Codecov Report

Attention: Patch coverage is 33.33333% with 22 lines in your changes missing coverage. Please review.

Project coverage is 79.0%. Comparing base (3f5c230) to head (8d88392).
Report is 1 commits behind head on main.

Files with missing lines	Patch %	Lines
opentelemetry-sdk/src/logs/log_processor.rs	25.0%	15 Missing ⚠️
opentelemetry-sdk/src/logs/log_emitter.rs	46.1%	7 Missing ⚠️

Additional details and impacted files

@@          Coverage Diff          @@
##            main   #2184   +/-   ##
=====================================
  Coverage   79.0%   79.0%           
=====================================
  Files        122     122           
  Lines      21059   21042   -17     
=====================================
- Hits       16651   16643    -8     
+ Misses      4408    4399    -9

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

opentelemetry-sdk/src/logs/log_emitter.rs

cijothomas · 2024-10-08T19:42:52Z

opentelemetry-sdk/src/logs/log_emitter.rs

@@ -146,7 +148,10 @@ impl Drop for LoggerProviderInner {
    fn drop(&mut self) {
        for processor in &mut self.processors {
            if let Err(err) = processor.shutdown() {
-                global::handle_error(err);
+                otel_warn!(
+                    name: "LoggerProvider.Drop.AlreadyShutdown",


not sure how we assume that the error is due to "AlreadyShutdown".

Yes good catch I have changed it to LoggerProvider.Drop.ShutdownError. Have kept it as warning, as the error is during shutdown of LoggerProvider, and should be less destructive ( I think)

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

opentelemetry/src/global/internal_logging.rs

opentelemetry-sdk/src/logs/log_processor.rs

opentelemetry/src/global/internal_logging.rs

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

cijothomas · 2024-10-09T16:34:42Z

opentelemetry-sdk/src/logs/log_emitter.rs

            otel_warn!(
-                name: "logger_provider_already_shutdown"
+                name: "LoggerProvider.Shutdown.AlreadyShutdown",


this looks redundant, as returned Result already contains this information. If we need to keep this, then maybe keep it at debug/info level.

So if the error is returned as Result to the user, we decide not to log it even if this could be actionable ?

not to log or log at a very low severity.

Do you see any reason why this should be logged, given Result already carries this information? "Internal logging" is more for things that are otherwise hard to figure out, right?

I prefer logging at a lower severity (debug?) for internal debugging. When we request logs from the customer at the debug level, they should include everything necessary for troubleshooting, even if the customer disregards the shutdown result.

That is a good point! Agree with debug! here. It won't cause noise in normal operations, but when we ask users to report bug/issues, we can ask to collect all logs, including debug, so we'll have enough to investigate.

Changed this to debug now.

cijothomas · 2024-10-09T16:35:30Z

opentelemetry-sdk/src/logs/log_emitter.rs

-                    otel_warn!(
-                        name: "logger_provider_shutdown_error",
-                        error = format!("{:?}", err)
+                    otel_error!(


Same as https://github.com/open-telemetry/opentelemetry-rust/pull/2184/files#r1793832380, this feels redundant, given Result will carry this info already.

#2184 (comment)

Changed this to debug now.

cijothomas · 2024-10-09T16:42:22Z

opentelemetry-sdk/src/logs/log_emitter.rs

@@ -146,7 +146,10 @@ impl Drop for LoggerProviderInner {
    fn drop(&mut self) {
        for processor in &mut self.processors {
            if let Err(err) = processor.shutdown() {
-                global::handle_error(err);
+                otel_warn!(


i think we should do more changes to this part - this is the automatically invoked shutdown upon drop right? I believe we should first check if user has already called shutdown, and if yes, return without any logs (maybe a debug level log?)

if user has not called shutdown, then we need to call shutdown ourselves. Even here - should we log for each processor? or just log once saying shutdownfailed. The detailed failure reason should be part of the individual processor's own log.

i think we should do more changes to this part - this is the automatically invoked shutdown upon drop right? I believe we should first check if user has already called shutdown, and if yes, return without any logs (maybe a debug level log?)

Modified it accordingly, and add debug log for already shutdown.

if user has not called shutdown, then we need to call shutdown ourselves. Even here - should we log for each processor? or just log once saying shutdownfailed. The detailed failure reason should be part of the individual processor's own log.

The Processor::shutdown() returns the error, and we are now logging each to debug (instead of warn).

cijothomas · 2024-10-09T16:44:43Z

opentelemetry-sdk/src/logs/log_processor.rs

@@ -100,7 +99,8 @@ impl LogProcessor for SimpleLogProcessor {
        // noop after shutdown
        if self.is_shutdown.load(std::sync::atomic::Ordering::Relaxed) {
            otel_warn!(
-                name: "simple_log_processor_emit_after_shutdown"
+                name: "SimpleLogProcessor.Export.AfterShutdown",
+                error = LogError::Other("Attempted to export a log after processor shutdown".into())


is there any advantage of wrapping this into LogError?

I find it useful - it adds convenience on top of std::error::Error, by declaring various error types as enum and mapping it to actual error string. We don't need to add the error string while returning the error.

cijothomas · 2024-10-09T16:49:43Z

opentelemetry-sdk/src/logs/log_processor.rs

@@ -115,10 +115,9 @@ impl LogProcessor for SimpleLogProcessor {
            });
        if let Err(err) = result {
            otel_error!(
-                name: "simple_log_processor_emit_error",
-                error = format!("{:?}", err)
+                name: "SimpleLogProcessor.Export.Error",


its not easy to tell if this is useful or not.. The failure could be due to

Mutex poisoning

Exporter facing issues like network etc.

Futures-Executor can fail itself too.

I don't have a good solution in mind, so probably okay to just replace current global error handler with otel_error! for now until we can find a better alternative.

Have modified it to differentiate between MutexPoisoning and Exporter failure - I think we can further extend it in future.

cijothomas · 2024-10-09T16:52:06Z

opentelemetry-sdk/src/logs/log_processor.rs

@@ -172,10 +168,9 @@ impl<R: RuntimeChannel> LogProcessor for BatchLogProcessor<R> {

        if let Err(err) = result {
            otel_error!(
-                name: "batch_log_processor_emit_error",
-                error = format!("{:?}", err)
+                name: "BatchLogProcessor.Export.Error",


will this be triggered when channel is full? If yes, we need to rethink this, as this can spam the log output.

Yes, this error only triggers when channel is full or closed. We need to add some throttling or logic to prevent flooding - have added the TODO for now, as we need common strategy for such flooding.

Agree we need a common strategy, but lets remove the error log from here. It'll flood as-is when buffer is full.

should we remove altogether, or make it otel_debug for now - with comment to change it to otel_error once throttling is ready.

either of them are fine with me, though I slightly prefer removing altogether, as I don't know if we can ship a throttling solution for next release.

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

opentelemetry/src/logs/mod.rs

cijothomas · 2024-10-10T23:54:31Z

opentelemetry-sdk/src/logs/log_emitter.rs

-        for processor in &mut self.processors {
-            if let Err(err) = processor.shutdown() {
-                global::handle_error(err);
+        if self


I agree with this change, but please make it own separate PR, so we can keep this PR strictly for replacing global error handler with internal logger.

This was done in response to the comment - #2184 (comment). Should we keep it in this PR with separate changelog entry?

I always prefer short, very focused PRs!
One can easily review them and continuously make progress by merging short PRs quickly. Slow and steady!

cijothomas · 2024-10-10T23:56:00Z

opentelemetry/src/global/internal_logging.rs

@@ -50,11 +50,30 @@ macro_rules! otel_warn {
        {
            tracing::warn!(name: $name, target: env!("CARGO_PKG_NAME"), "");
        }
+        #[cfg(not(feature = "internal-logs"))]


Agree with this change, but for future - please make them into own separate PR to make it easier to review.

cijothomas

LGTM.
Please keep this change separate with own changelog entry:
https://github.com/open-telemetry/opentelemetry-rust/pull/2184/files#r1796235052

lalitb · 2024-10-14T04:41:57Z

internal-log and shutdown related changes are now merged separately in #2195 and #2196. Just incase if there needs another look, else will go with merge.

lalitb · 2024-10-14T21:29:03Z

internal-log and shutdown related changes are now merged separately in #2195 and #2196. Just incase if there needs another look, else will go with merge.

Merging it to make the cleanup faster, please comment if any changes required will incorporate in separate PR.

initial commit

d7fc754

lalitb requested a review from a team as a code owner October 8, 2024 19:25

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

f6e5cb9

lalitb commented Oct 8, 2024

View reviewed changes

opentelemetry/src/global/internal_logging.rs Outdated Show resolved Hide resolved

cijothomas reviewed Oct 8, 2024

View reviewed changes

opentelemetry-sdk/src/logs/log_emitter.rs Outdated Show resolved Hide resolved

cijothomas reviewed Oct 8, 2024

View reviewed changes

lalitb added 2 commits October 8, 2024 13:32

comments

76bafef

Merge branch 'global-error-handler-cleanup-logs-sdk' of github.com:la…

3006c16

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

lalitb commented Oct 8, 2024

View reviewed changes

opentelemetry/src/global/internal_logging.rs Outdated Show resolved Hide resolved

cijothomas added the integration tests Run integration tests label Oct 8, 2024

lalitb mentioned this pull request Oct 8, 2024

Global error handler cleanup - Metrics SDK #2185

Closed

4 tasks

cijothomas reviewed Oct 9, 2024

View reviewed changes

opentelemetry-sdk/src/logs/log_processor.rs Show resolved Hide resolved

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

d63957d

cijothomas reviewed Oct 9, 2024

View reviewed changes

opentelemetry/src/global/internal_logging.rs Outdated Show resolved Hide resolved

lalitb and others added 5 commits October 8, 2024 17:35

make SendResultError as warning

96e652a

Merge branch 'global-error-handler-cleanup-logs-sdk' of github.com:la…

a4a812f

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

simplify internal logs formatting

886a583

change non-actionable error to debug

0d5bf14

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

a8d772e

cijothomas reviewed Oct 9, 2024

View reviewed changes

lalitb added 4 commits October 9, 2024 12:55

review comments

c25923d

Merge branch 'global-error-handler-cleanup-logs-sdk' of github.com:la…

b8819c4

…litb/opentelemetry-rust into global-error-handler-cleanup-logs-sdk

cont..

0bd341b

lint

4979249

lalitb added 2 commits October 9, 2024 13:21

handle loggerprovider_drop

f1182ff

add todo to prevert flooding

40f7a5c

cijothomas reviewed Oct 10, 2024

View reviewed changes

opentelemetry/src/logs/mod.rs Show resolved Hide resolved

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

f695605

cijothomas reviewed Oct 10, 2024

View reviewed changes

cijothomas approved these changes Oct 10, 2024

View reviewed changes

lalitb mentioned this pull request Oct 12, 2024

Avoid redundant shutdown in LoggerProvider::drop when already shut down #2195

Merged

4 tasks

lalitb and others added 3 commits October 13, 2024 00:35

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

e99195b

Merge branch 'main' into global-error-handler-cleanup-logs-sdk

a566aac

fix merge errors

8d88392

lalitb merged commit 16c0e10 into open-telemetry:main Oct 14, 2024
24 of 25 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Global Log handler cleanup - Logs SDK #2184

Global Log handler cleanup - Logs SDK #2184

lalitb commented Oct 8, 2024

codecov bot commented Oct 8, 2024 •

edited

Loading

cijothomas Oct 8, 2024

lalitb Oct 8, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024 •

edited

Loading

cijothomas Oct 9, 2024

lalitb Oct 9, 2024 •

edited

Loading

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 9, 2024

lalitb Oct 9, 2024

cijothomas Oct 10, 2024

lalitb Oct 10, 2024

cijothomas Oct 11, 2024

cijothomas Oct 10, 2024

lalitb Oct 11, 2024

cijothomas Oct 11, 2024

cijothomas Oct 10, 2024

cijothomas left a comment

lalitb commented Oct 14, 2024

lalitb commented Oct 14, 2024

Global Log handler cleanup - Logs SDK #2184

Global Log handler cleanup - Logs SDK #2184

Conversation

lalitb commented Oct 8, 2024

Changes

Merge requirement checklist

codecov bot commented Oct 8, 2024 • edited Loading

Codecov Report

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Oct 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lalitb Oct 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cijothomas left a comment

Choose a reason for hiding this comment

lalitb commented Oct 14, 2024

lalitb commented Oct 14, 2024

codecov bot commented Oct 8, 2024 •

edited

Loading

lalitb Oct 9, 2024 •

edited

Loading

lalitb Oct 9, 2024 •

edited

Loading