feat(logs): make logger shutdown &self #1643

TommyCpp · 2024-03-26T05:56:50Z

This PR aim to address the issue brought up in #1625 (comment)

In summary we need to:

Ensure logger provider shut down will block creating new (functional) logger.
Ensure no log can be emitted from logger once the logger provider shutdown.

We discussed the solution of keeping Weak reference from LoggerProvider to Loggers but as I implemented this solution it seems to complicated. I revisited why we need mutable reference during LoggerProvider and found that LogProcessor shutdown doesn't have to take a mutable reference.

Changes

make LogProcessor shutdown taking &self instead of &mut self.
- This decouple the shutdown from drop. If one LogProcessor is shared across multiple thread, any thread can call shutdown to stop the LogProcessor from emitting more logs. But this doesn't mean the LogProcessor will drop.
- However, drop will call shutdown
- This implementation stops the log emitting after shutdown in BatchLogProcessor. Emitting new logs after shutdown will result in a LogError saying the receiver on the worker task has already closed.
- for SimpleLogProcessor we need a field to mark if the processor has been shutdown we also need to check it everytime before emitting the logs.
Add a field in LoggerProvider to mark if the logger provider has shutdown. If it has, return a noop logger

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)

codecov · 2024-03-26T06:01:06Z

Codecov Report

Attention: Patch coverage is 85.96491% with 24 lines in your changes are missing coverage. Please review.

Project coverage is 70.0%. Comparing base (f203b03) to head (4e2eacc).
Report is 15 commits behind head on main.

❗ Current head 4e2eacc differs from pull request most recent head 5bb6471. Consider uploading reports for the commit 5bb6471 to get more accurate results

Files	Patch %	Lines
opentelemetry-sdk/src/logs/log_emitter.rs	80.2%	16 Missing ⚠️
opentelemetry/src/logs/record.rs	0.0%	5 Missing ⚠️
opentelemetry/src/logs/noop.rs	0.0%	3 Missing ⚠️

Additional details and impacted files

@@           Coverage Diff           @@
##            main   #1643     +/-   ##
=======================================
+ Coverage   69.3%   70.0%   +0.7%     
=======================================
  Files        136     136             
  Lines      19637   20029    +392     
=======================================
+ Hits       13610   14028    +418     
+ Misses      6027    6001     -26

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

lalitb · 2024-03-27T17:22:39Z

This seems like a much more streamlined approach. In particular, the LoggerProvider (and so the LogProcessors) can be shut down without needing to wait for all loggers to be dropped.

[TODO] for SimpleLogProcessor we need a field to mark if the processor has been shutdown we also need to check it everytime before emitting the logs.

I believe it should be acceptable if the check is performed atomically. This isn't related to the current PR, but just to reiterate so I don't forget, this check would also need to be added in ReentrantLogProcessor for ETW and user_events exporter.

lalitb · 2024-03-28T20:54:04Z

@TommyCpp Do you plan to make it ready for review? The changes look good to me.

TommyCpp · 2024-03-29T03:00:09Z

Sorry busy week. Will get it done this weekend

TommyCpp · 2024-03-29T03:01:04Z

this check would also need to be added in ReentrantLogProcessor for ETW and user_events exporter.

I think we should also make it clear that LogProcessor needs to make sure no new logs get processed after shutdown

lalitb · 2024-04-05T16:01:44Z

opentelemetry-sdk/src/logs/log_emitter.rs

    }

    /// Attempts to shutdown this `LoggerProvider`, succeeding only when
    /// all cloned `LoggerProvider` values have been dropped.
+    // todo: remove this


nit - If we are keeping try_shutdown() for backward compatibility, good to update the existing comments, as now it doesn't just attempt, but really shutdown the LoggerProvider.

opentelemetry-sdk/src/logs/log_processor.rs

TommyCpp · 2024-04-07T22:08:59Z

Simple log processor took some hit as expected but it's acceptable IMHO

simple-log/no-context   time:   [109.01 ns 109.09 ns 109.20 ns]
                        change: [-2.4832% -2.3350% -2.1759%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 2 outliers among 100 measurements (2.00%)
  1 (1.00%) high mild
  1 (1.00%) high severe
simple-log/with-context time:   [109.56 ns 109.62 ns 109.69 ns]
                        change: [+2.0309% +2.1353% +2.2391%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 3 outliers among 100 measurements (3.00%)
  3 (3.00%) high mild

simple-log-with-int/no-context
                        time:   [146.61 ns 146.71 ns 146.81 ns]
                        change: [-3.8572% -3.6060% -3.4182%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) low mild
simple-log-with-int/with-context
                        time:   [146.41 ns 146.55 ns 146.70 ns]
                        change: [+2.7780% +2.9471% +3.1086%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 2 outliers among 100 measurements (2.00%)
  2 (2.00%) high mild

simple-log-with-double/no-context
                        time:   [144.09 ns 144.30 ns 144.49 ns]
                        change: [-2.8585% -2.7094% -2.5562%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 3 outliers among 100 measurements (3.00%)
  1 (1.00%) low mild
  2 (2.00%) high mild
simple-log-with-double/with-context
                        time:   [143.65 ns 143.75 ns 143.85 ns]
                        change: [-0.4290% -0.2448% -0.0662%] (p = 0.01 < 0.05)
                        Change within noise threshold.
Found 3 outliers among 100 measurements (3.00%)
  2 (2.00%) low mild
  1 (1.00%) high mild

simple-log-with-string/no-context
                        time:   [138.76 ns 138.87 ns 139.00 ns]
                        change: [-7.9410% -7.7945% -7.6528%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 8 outliers among 100 measurements (8.00%)
  8 (8.00%) high mild
simple-log-with-string/with-context
                        time:   [147.51 ns 147.61 ns 147.74 ns]
                        change: [+2.4718% +2.6915% +2.8987%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high severe

simple-log-with-bool/no-context
                        time:   [144.49 ns 144.57 ns 144.64 ns]
                        change: [-1.3301% -1.2371% -1.1458%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 8 outliers among 100 measurements (8.00%)
  2 (2.00%) low severe
  2 (2.00%) low mild
  4 (4.00%) high mild
simple-log-with-bool/with-context
                        time:   [147.11 ns 147.26 ns 147.41 ns]
                        change: [+2.9351% +3.1008% +3.2648%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 3 outliers among 100 measurements (3.00%)
  3 (3.00%) high mild

simple-log-with-bytes/no-context
                        time:   [167.25 ns 167.39 ns 167.53 ns]
                        change: [+3.4868% +3.5855% +3.6920%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 2 outliers among 100 measurements (2.00%)
  1 (1.00%) high mild
  1 (1.00%) high severe
simple-log-with-bytes/with-context
                        time:   [164.25 ns 164.52 ns 164.77 ns]
                        change: [-3.4532% -3.2357% -3.0189%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 3 outliers among 100 measurements (3.00%)
  1 (1.00%) low mild
  2 (2.00%) high mild

simple-log-with-a-lot-of-bytes/no-context
                        time:   [158.78 ns 158.94 ns 159.09 ns]
                        change: [-6.1546% -5.9827% -5.7952%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 3 outliers among 100 measurements (3.00%)
  1 (1.00%) high mild
  2 (2.00%) high severe
simple-log-with-a-lot-of-bytes/with-context
                        time:   [170.54 ns 171.53 ns 173.46 ns]
                        change: [+3.6391% +4.1090% +5.1313%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high severe

simple-log-with-vec-any-value/no-context
                        time:   [203.13 ns 203.24 ns 203.36 ns]
                        change: [-6.0749% -5.9717% -5.8644%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 4 outliers among 100 measurements (4.00%)
  1 (1.00%) low mild
  3 (3.00%) high mild
simple-log-with-vec-any-value/with-context
                        time:   [211.36 ns 211.71 ns 212.08 ns]
                        change: [-1.1547% -0.9804% -0.8161%] (p = 0.00 < 0.05)
                        Change within noise threshold.

simple-log-with-inner-vec-any-value/no-context
                        time:   [276.62 ns 276.81 ns 277.00 ns]
                        change: [+0.8487% +0.9492% +1.0494%] (p = 0.00 < 0.05)
                        Change within noise threshold.
Found 5 outliers among 100 measurements (5.00%)
  1 (1.00%) low mild
  3 (3.00%) high mild
  1 (1.00%) high severe
simple-log-with-inner-vec-any-value/with-context
                        time:   [274.47 ns 274.97 ns 275.65 ns]
                        change: [-1.1943% -0.8690% -0.5281%] (p = 0.00 < 0.05)
                        Change within noise threshold.
Found 7 outliers among 100 measurements (7.00%)
  7 (7.00%) high severe

simple-log-with-map-any-value/no-context
                        time:   [233.37 ns 233.47 ns 233.59 ns]
                        change: [-2.3170% -2.1937% -2.0710%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 5 outliers among 100 measurements (5.00%)
  1 (1.00%) low mild
  3 (3.00%) high mild
  1 (1.00%) high severe
simple-log-with-map-any-value/with-context
                        time:   [233.39 ns 233.55 ns 233.71 ns]
                        change: [+0.4716% +0.7618% +1.0012%] (p = 0.00 < 0.05)
                        Change within noise threshold.
Found 6 outliers among 100 measurements (6.00%)
  3 (3.00%) high mild
  3 (3.00%) high severe

simple-log-with-inner-map-any-value/no-context
                        time:   [345.49 ns 345.65 ns 345.80 ns]
                        change: [+4.0620% +4.1413% +4.2130%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 5 outliers among 100 measurements (5.00%)
  3 (3.00%) low mild
  2 (2.00%) high mild
simple-log-with-inner-map-any-value/with-context
                        time:   [348.78 ns 349.29 ns 350.15 ns]
                        change: [+5.3044% +5.5604% +5.8275%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 6 outliers among 100 measurements (6.00%)
  1 (1.00%) low mild
  2 (2.00%) high mild
  3 (3.00%) high severe

long-log/no-context     time:   [107.13 ns 107.18 ns 107.24 ns]
                        change: [+0.4446% +0.5142% +0.5924%] (p = 0.00 < 0.05)
                        Change within noise threshold.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high mild
long-log/with-context   time:   [109.07 ns 109.29 ns 109.69 ns]
                        change: [+1.3800% +1.5142% +1.6832%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 3 outliers among 100 measurements (3.00%)
  2 (2.00%) high mild
  1 (1.00%) high severe

full-log/no-context     time:   [109.70 ns 109.79 ns 109.89 ns]
                        change: [+3.4539% +3.5922% +3.7297%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high mild
full-log/with-context   time:   [111.41 ns 111.47 ns 111.55 ns]
                        change: [+0.1869% +0.2796% +0.3707%] (p = 0.00 < 0.05)
                        Change within noise threshold.
Found 7 outliers among 100 measurements (7.00%)
  1 (1.00%) low severe
  1 (1.00%) low mild
  3 (3.00%) high mild
  2 (2.00%) high severe

full-log-with-4-attributes/no-context
                        time:   [246.83 ns 246.95 ns 247.08 ns]
                        change: [-0.3164% -0.0559% +0.1822%] (p = 0.68 > 0.05)
                        No change in performance detected.
Found 6 outliers among 100 measurements (6.00%)
  1 (1.00%) low mild
  2 (2.00%) high mild
  3 (3.00%) high severe
full-log-with-4-attributes/with-context
                        time:   [249.19 ns 249.38 ns 249.59 ns]
                        change: [-4.3881% -4.1521% -3.9539%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 7 outliers among 100 measurements (7.00%)
  1 (1.00%) low mild
  4 (4.00%) high mild
  2 (2.00%) high severe

full-log-with-9-attributes/no-context
                        time:   [442.82 ns 443.27 ns 443.83 ns]
                        change: [-3.3624% -3.0116% -2.6846%] (p = 0.00 < 0.05)
                        Performance has improved.
full-log-with-9-attributes/with-context
                        time:   [454.05 ns 454.27 ns 454.51 ns]
                        change: [-1.8147% -1.7175% -1.6242%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 7 outliers among 100 measurements (7.00%)
  5 (5.00%) high mild
  2 (2.00%) high severe

full-log-with-attributes/no-context
                        time:   [282.22 ns 282.36 ns 282.52 ns]
                        change: [-5.0554% -4.1746% -3.4991%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 4 outliers among 100 measurements (4.00%)
  2 (2.00%) low mild
  1 (1.00%) high mild
  1 (1.00%) high severe
full-log-with-attributes/with-context
                        time:   [292.55 ns 292.78 ns 293.09 ns]
                        change: [-2.2768% -1.9404% -1.6585%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 5 outliers among 100 measurements (5.00%)
  1 (1.00%) low mild
  2 (2.00%) high mild
  2 (2.00%) high severe

lalitb

Thanks.

opentelemetry-sdk/src/logs/log_emitter.rs

opentelemetry/src/global/logs.rs

TommyCpp · 2024-04-24T16:12:21Z

@open-telemetry/rust-approvers can I get another review?

opentelemetry/src/logs/record.rs

opentelemetry-sdk/src/logs/log_emitter.rs

opentelemetry-sdk/CHANGELOG.md

opentelemetry-sdk/src/logs/log_processor.rs

opentelemetry-sdk/src/testing/logs/in_memory_exporter.rs

opentelemetry/src/global/logs.rs

cijothomas

This is probably not required for logging signal...
See https://github.com/open-telemetry/opentelemetry-rust/pull/1643/files#r1579840322

cijothomas · 2024-04-26T15:08:13Z

opentelemetry-sdk/CHANGELOG.md

@@ -13,6 +13,7 @@
  `ProcessResourceDetector` resource detectors, use the
  [`opentelemetry-resource-detector`](https://crates.io/crates/opentelemetry-resource-detectors) instead.
 - Baggage propagation error will be reported to global error handler [#1640](https://github.com/open-telemetry/opentelemetry-rust/pull/1640)
+- Make `shutdown` method in `LoggerProvider` and `LogProcessor` taking immutable reference [#1643](https://github.com/open-telemetry/opentelemetry-rust/pull/1643)


Lets describe all the changes this PR is making:

Loggers obtained after shutdown is now no-ops.

Shutdown requires immutable ref for provider/processor.

Simple and batch processors will ignore new logrecord after shutdown.

cijothomas

Thanks! I have a suggestion to make changelog better to reflect the actuals.
Also please update the PR description to reflect the current state, for easy paper-trail in the future.

lalitb

Thanks.

TommyCpp marked this pull request as ready for review April 1, 2024 00:46

TommyCpp requested a review from a team as a code owner April 1, 2024 00:46

lalitb reviewed Apr 5, 2024

View reviewed changes

TommyCpp force-pushed the shutdown_channel branch 2 times, most recently from 1b45663 to 52757f0 Compare April 7, 2024 21:27

TommyCpp requested review from hdost, lalitb and cijothomas April 15, 2024 00:17

lalitb approved these changes Apr 16, 2024

View reviewed changes

lalitb mentioned this pull request Apr 17, 2024

Refactor SdkMeterProvider with Inner Structure for Better Lifecycle Control #1663

Merged

4 tasks

shaun-cox reviewed Apr 19, 2024

View reviewed changes

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

TommyCpp force-pushed the shutdown_channel branch from 5631a88 to a0c0dbf Compare April 23, 2024 06:04

lalitb reviewed Apr 23, 2024

View reviewed changes

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

lalitb reviewed Apr 23, 2024

View reviewed changes

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

lalitb mentioned this pull request Apr 23, 2024

Revisit shutdown_signal_provider methods at API level #1679

Closed

cijothomas reviewed Apr 24, 2024

View reviewed changes

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

cijothomas reviewed Apr 24, 2024

View reviewed changes

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

lalitb approved these changes Apr 24, 2024

View reviewed changes

cijothomas reviewed Apr 25, 2024

View reviewed changes

opentelemetry-sdk/CHANGELOG.md Outdated Show resolved Hide resolved

cijothomas reviewed Apr 25, 2024

View reviewed changes

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

cijothomas reviewed Apr 25, 2024

View reviewed changes

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

cijothomas reviewed Apr 25, 2024

View reviewed changes

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

cijothomas requested changes Apr 25, 2024

View reviewed changes

TommyCpp added 9 commits April 25, 2024 20:17

feat(logs): make logger shutdown &self

5c57bb8

add unit tests

25f28e8

fix main

cde300d

add shutdown in global logger provider

185c094

revise tests

1f351aa

address comments

90c5e1c

CHANGELOG

4daa2af

address comments

79c0b05

CHANGELOG

0fcd167

TommyCpp force-pushed the shutdown_channel branch from fc907ff to 0fcd167 Compare April 26, 2024 03:34

unit test

5bd59e7

TommyCpp requested a review from cijothomas April 26, 2024 05:36

cijothomas reviewed Apr 26, 2024

View reviewed changes

cijothomas approved these changes Apr 26, 2024

View reviewed changes

cijothomas requested a review from lalitb April 26, 2024 15:09

lalitb approved these changes Apr 26, 2024

View reviewed changes

Update CHANGELOG.md

5bb6471

cijothomas merged commit 0ba4cbd into open-telemetry:main Apr 29, 2024
15 checks passed

lalitb mentioned this pull request Apr 30, 2024

[Logs API] Remove global provider for Logs #1691

Merged

4 tasks

Expyron mentioned this pull request May 30, 2024

Remove unused dependency #1847

Merged

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(logs): make logger shutdown &self #1643

feat(logs): make logger shutdown &self #1643

TommyCpp commented Mar 26, 2024 •

edited

codecov bot commented Mar 26, 2024 •

edited

lalitb commented Mar 27, 2024

lalitb commented Mar 28, 2024

TommyCpp commented Mar 29, 2024

TommyCpp commented Mar 29, 2024

lalitb Apr 5, 2024

TommyCpp commented Apr 7, 2024

lalitb left a comment

TommyCpp commented Apr 24, 2024

cijothomas left a comment

cijothomas Apr 26, 2024

cijothomas left a comment

lalitb left a comment

feat(logs): make logger shutdown &self #1643

feat(logs): make logger shutdown &self #1643

Conversation

TommyCpp commented Mar 26, 2024 • edited

Changes

Merge requirement checklist

codecov bot commented Mar 26, 2024 • edited

Codecov Report

lalitb commented Mar 27, 2024

lalitb commented Mar 28, 2024

TommyCpp commented Mar 29, 2024

TommyCpp commented Mar 29, 2024

lalitb Apr 5, 2024

Choose a reason for hiding this comment

TommyCpp commented Apr 7, 2024

lalitb left a comment

Choose a reason for hiding this comment

TommyCpp commented Apr 24, 2024

cijothomas left a comment

Choose a reason for hiding this comment

cijothomas Apr 26, 2024

Choose a reason for hiding this comment

cijothomas left a comment

Choose a reason for hiding this comment

lalitb left a comment

Choose a reason for hiding this comment

TommyCpp commented Mar 26, 2024 •

edited

codecov bot commented Mar 26, 2024 •

edited