Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Leverage Suppression Context in Sdk #2868

Merged
merged 16 commits into from
Mar 28, 2025
Merged
Show file tree
Hide file tree
Changes from 13 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 19 additions & 1 deletion docs/design/logs.md
Original file line number Diff line number Diff line change
Expand Up @@ -345,7 +345,25 @@ only meant for OTel components itself and anyone writing extensions like custom
Exporters etc.

// TODO: Document the principles followed when selecting severity for internal
logs // TODO: Document how this can cause circular loop and plans to address it.
logs

When OpenTelemetry components generate logs that could potentially feed back
into OpenTelemetry, this can result in what is known as "telemetry-induced
telemetry." To address this, OpenTelemetry provides a mechanism to suppress such
telemetry using the `Context`. Components are expected to mark telemetry as
suppressed within a specific `Context` by invoking
`Context::enter_telemetry_suppressed_scope()`. The Logs SDK implementation
checks this flag in the current `Context` and ignores logs if suppression is
enabled.

This mechanism relies on proper in-process propagation of the `Context`.
However, external libraries like `hyper` and `tonic`, which are used by
OpenTelemetry in its OTLP Exporters, do not propagate OpenTelemetry's `Context`.
As a result, the suppression mechanism does not work out-of-the-box to suppress
logs originating from these libraries.

// TODO: Document how OTLP can solve this issue without asking external
crates to respect and propagate OTel Context.

## Summary

Expand Down
22 changes: 12 additions & 10 deletions examples/logs-basic/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -15,19 +15,21 @@ fn main() {
.with_simple_exporter(exporter)
.build();

// For the OpenTelemetry layer, add a tracing filter to filter events from
// OpenTelemetry and its dependent crates (opentelemetry-otlp uses crates
// like reqwest/tonic etc.) from being sent back to OTel itself, thus
// preventing infinite telemetry generation. The filter levels are set as
// follows:
// To prevent a telemetry-induced-telemetry loop, OpenTelemetry's own internal
// logging is properly suppressed. However, logs emitted by external components
// (such as reqwest, tonic, etc.) are not suppressed as they do not propagate
// OpenTelemetry context. Until this issue is addressed
// (https://github.com/open-telemetry/opentelemetry-rust/issues/2877),
// filtering like this is the best way to suppress such logs.
//
// The filter levels are set as follows:
// - Allow `info` level and above by default.
// - Restrict `opentelemetry`, `hyper`, `tonic`, and `reqwest` completely.
// Note: This will also drop events from crates like `tonic` etc. even when
// they are used outside the OTLP Exporter. For more details, see:
// https://github.com/open-telemetry/opentelemetry-rust/issues/761
// - Completely restrict logs from `hyper`, `tonic`, `h2`, and `reqwest`.
//
// Note: This filtering will also drop logs from these components even when
// they are used outside of the OTLP Exporter.
let filter_otel = EnvFilter::new("info")
.add_directive("hyper=off".parse().unwrap())
.add_directive("opentelemetry=off".parse().unwrap())
.add_directive("tonic=off".parse().unwrap())
.add_directive("h2=off".parse().unwrap())
.add_directive("reqwest=off".parse().unwrap());
Expand Down
21 changes: 12 additions & 9 deletions opentelemetry-appender-tracing/examples/basic.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,16 +16,19 @@ fn main() {
.with_simple_exporter(exporter)
.build();

// For the OpenTelemetry layer, add a tracing filter to filter events from
// OpenTelemetry and its dependent crates (opentelemetry-otlp uses crates
// like reqwest/tonic etc.) from being sent back to OTel itself, thus
// preventing infinite telemetry generation. The filter levels are set as
// follows:
// To prevent a telemetry-induced-telemetry loop, OpenTelemetry's own internal
// logging is properly suppressed. However, logs emitted by external components
// (such as reqwest, tonic, etc.) are not suppressed as they do not propagate
// OpenTelemetry context. Until this issue is addressed
// (https://github.com/open-telemetry/opentelemetry-rust/issues/2877),
// filtering like this is the best way to suppress such logs.
//
// The filter levels are set as follows:
// - Allow `info` level and above by default.
// - Restrict `opentelemetry`, `hyper`, `tonic`, and `reqwest` completely.
// Note: This will also drop events from crates like `tonic` etc. even when
// they are used outside the OTLP Exporter. For more details, see:
// https://github.com/open-telemetry/opentelemetry-rust/issues/761
// - Completely restrict logs from `hyper`, `tonic`, `h2`, and `reqwest`.
//
// Note: This filtering will also drop logs from these components even when
// they are used outside of the OTLP Exporter.
let filter_otel = EnvFilter::new("info")
.add_directive("hyper=off".parse().unwrap())
.add_directive("opentelemetry=off".parse().unwrap())
Expand Down
69 changes: 2 additions & 67 deletions opentelemetry-appender-tracing/src/layer.rs
Original file line number Diff line number Diff line change
Expand Up @@ -289,13 +289,11 @@ mod tests {
use opentelemetry::{logs::AnyValue, Key};
use opentelemetry_sdk::error::{OTelSdkError, OTelSdkResult};
use opentelemetry_sdk::logs::{InMemoryLogExporter, LogProcessor};
use opentelemetry_sdk::logs::{LogBatch, LogExporter};
use opentelemetry_sdk::logs::{SdkLogRecord, SdkLoggerProvider};
use opentelemetry_sdk::trace::{Sampler, SdkTracerProvider};
use tracing::{error, warn};
use tracing::error;
use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
use tracing_subscriber::{EnvFilter, Layer};
use tracing_subscriber::Layer;

pub fn attributes_contains(log_record: &SdkLogRecord, key: &Key, value: &AnyValue) -> bool {
log_record
Expand All @@ -313,69 +311,6 @@ mod tests {
}

// cargo test --features=testing

#[derive(Clone, Debug, Default)]
struct ReentrantLogExporter;

impl LogExporter for ReentrantLogExporter {
async fn export(&self, _batch: LogBatch<'_>) -> OTelSdkResult {
// This will cause a deadlock as the export itself creates a log
// while still within the lock of the SimpleLogProcessor.
warn!(name: "my-event-name", target: "reentrant", event_id = 20, user_name = "otel", user_email = "[email protected]");
Ok(())
}
}

#[test]
#[ignore = "See issue: https://github.com/open-telemetry/opentelemetry-rust/issues/1745"]
fn simple_processor_deadlock() {
let exporter: ReentrantLogExporter = ReentrantLogExporter;
let logger_provider = SdkLoggerProvider::builder()
.with_simple_exporter(exporter.clone())
.build();

let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);

// Setting subscriber as global as that is the only way to test this scenario.
tracing_subscriber::registry().with(layer).init();
warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "[email protected]");
}

#[test]
#[ignore = "While this test runs fine, this uses global subscriber and does not play well with other tests."]
fn simple_processor_no_deadlock() {
let exporter: ReentrantLogExporter = ReentrantLogExporter;
let logger_provider = SdkLoggerProvider::builder()
.with_simple_exporter(exporter.clone())
.build();

let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);

// This filter will prevent the deadlock as the reentrant log will be
// ignored.
let filter = EnvFilter::new("debug").add_directive("reentrant=error".parse().unwrap());
// Setting subscriber as global as that is the only way to test this scenario.
tracing_subscriber::registry()
.with(filter)
.with(layer)
.init();
warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "[email protected]");
}

#[tokio::test(flavor = "multi_thread", worker_threads = 1)]
#[ignore = "While this test runs fine, this uses global subscriber and does not play well with other tests."]
async fn batch_processor_no_deadlock() {
let exporter: ReentrantLogExporter = ReentrantLogExporter;
let logger_provider = SdkLoggerProvider::builder()
.with_batch_exporter(exporter.clone())
.build();

let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);

tracing_subscriber::registry().with(layer).init();
warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "[email protected]");
}

#[test]
fn tracing_appender_standalone() {
// Arrange
Expand Down
22 changes: 12 additions & 10 deletions opentelemetry-otlp/examples/basic-otlp-http/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -72,19 +72,21 @@ async fn main() -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
// Create a new OpenTelemetryTracingBridge using the above LoggerProvider.
let otel_layer = OpenTelemetryTracingBridge::new(&logger_provider);

// For the OpenTelemetry layer, add a tracing filter to filter events from
// OpenTelemetry and its dependent crates (opentelemetry-otlp uses crates
// like reqwest/tonic etc.) from being sent back to OTel itself, thus
// preventing infinite telemetry generation. The filter levels are set as
// follows:
// To prevent a telemetry-induced-telemetry loop, OpenTelemetry's own internal
// logging is properly suppressed. However, logs emitted by external components
// (such as reqwest, tonic, etc.) are not suppressed as they do not propagate
// OpenTelemetry context. Until this issue is addressed
// (https://github.com/open-telemetry/opentelemetry-rust/issues/2877),
// filtering like this is the best way to suppress such logs.
//
// The filter levels are set as follows:
// - Allow `info` level and above by default.
// - Restrict `opentelemetry`, `hyper`, `tonic`, and `reqwest` completely.
// Note: This will also drop events from crates like `tonic` etc. even when
// they are used outside the OTLP Exporter. For more details, see:
// https://github.com/open-telemetry/opentelemetry-rust/issues/761
// - Completely restrict logs from `hyper`, `tonic`, `h2`, and `reqwest`.
//
// Note: This filtering will also drop logs from these components even when
// they are used outside of the OTLP Exporter.
let filter_otel = EnvFilter::new("info")
.add_directive("hyper=off".parse().unwrap())
.add_directive("opentelemetry=off".parse().unwrap())
.add_directive("tonic=off".parse().unwrap())
.add_directive("h2=off".parse().unwrap())
.add_directive("reqwest=off".parse().unwrap());
Expand Down
22 changes: 12 additions & 10 deletions opentelemetry-otlp/examples/basic-otlp/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -66,19 +66,21 @@ async fn main() -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
// Create a new OpenTelemetryTracingBridge using the above LoggerProvider.
let otel_layer = OpenTelemetryTracingBridge::new(&logger_provider);

// For the OpenTelemetry layer, add a tracing filter to filter events from
// OpenTelemetry and its dependent crates (opentelemetry-otlp uses crates
// like reqwest/tonic etc.) from being sent back to OTel itself, thus
// preventing infinite telemetry generation. The filter levels are set as
// follows:
// To prevent a telemetry-induced-telemetry loop, OpenTelemetry's own internal
// logging is properly suppressed. However, logs emitted by external components
// (such as reqwest, tonic, etc.) are not suppressed as they do not propagate
// OpenTelemetry context. Until this issue is addressed
// (https://github.com/open-telemetry/opentelemetry-rust/issues/2877),
// filtering like this is the best way to suppress such logs.
//
// The filter levels are set as follows:
// - Allow `info` level and above by default.
// - Restrict `opentelemetry`, `hyper`, `tonic`, and `reqwest` completely.
// Note: This will also drop events from crates like `tonic` etc. even when
// they are used outside the OTLP Exporter. For more details, see:
// https://github.com/open-telemetry/opentelemetry-rust/issues/761
// - Completely restrict logs from `hyper`, `tonic`, `h2`, and `reqwest`.
//
// Note: This filtering will also drop logs from these components even when
// they are used outside of the OTLP Exporter.
let filter_otel = EnvFilter::new("info")
.add_directive("hyper=off".parse().unwrap())
.add_directive("opentelemetry=off".parse().unwrap())
.add_directive("tonic=off".parse().unwrap())
.add_directive("h2=off".parse().unwrap())
.add_directive("reqwest=off".parse().unwrap());
Expand Down
10 changes: 10 additions & 0 deletions opentelemetry-sdk/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,16 @@

## vNext

[#2868](https://github.com/open-telemetry/opentelemetry-rust/pull/2868)
`SdkLogger`, `SdkTracer` modified to respect telemetry suppression based on
`Context`. In other words, if the current context has telemetry suppression
enabled, then logs/spans will be ignored. The flag is typically set by OTel
components to prevent telemetry from itself being fed back into OTel.
`BatchLogProcessor`, `BatchSpanProcessor`, and `PeriodicReader` modified to set
the suppression flag in their dedicated thread, so that telemetry generated from
those threads will not be fed back into OTel. Similarly, `SimpleLogProcessor`
also modified to suppress telemetry before invoking exporters.

## 0.29.0

Released 2025-Mar-21
Expand Down
4 changes: 2 additions & 2 deletions opentelemetry-sdk/benches/log_enabled.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,8 @@
Total Number of Cores:   14 (10 performance and 4 efficiency)
| Test | Average time|
|---------------------------------------------|-------------|
| exporter_disabled_concurrent_processor | 1.1 ns |
| exporter_disabled_simple_processor | 4.3 ns |
| exporter_disabled_concurrent_processor | 2.5 ns |
| exporter_disabled_simple_processor | 5.3 ns |
*/

// cargo bench --bench log_enabled --features="spec_unstable_logs_enabled,experimental_logs_concurrent_log_processor"
Expand Down
3 changes: 2 additions & 1 deletion opentelemetry-sdk/src/logs/batch_log_processor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ use crate::{
};
use std::sync::mpsc::{self, RecvTimeoutError, SyncSender};

use opentelemetry::{otel_debug, otel_error, otel_warn, InstrumentationScope};
use opentelemetry::{otel_debug, otel_error, otel_warn, Context, InstrumentationScope};

use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
use std::{cmp::min, env, sync::Mutex};
Expand Down Expand Up @@ -342,6 +342,7 @@ impl BatchLogProcessor {
let handle = thread::Builder::new()
.name("OpenTelemetry.Logs.BatchProcessor".to_string())
.spawn(move || {
let _suppress_guard = Context::enter_telemetry_suppressed_scope();
otel_debug!(
name: "BatchLogProcessor.ThreadStarted",
interval_in_millisecs = config.scheduled_delay.as_millis(),
Expand Down
6 changes: 6 additions & 0 deletions opentelemetry-sdk/src/logs/logger.rs
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,9 @@

/// Emit a `LogRecord`.
fn emit(&self, mut record: Self::LogRecord) {
if Context::is_current_telemetry_suppressed() {
return;
}
let provider = &self.provider;
let processors = provider.log_processors();

Expand All @@ -52,6 +55,9 @@
#[cfg(feature = "spec_unstable_logs_enabled")]
#[inline]
fn event_enabled(&self, level: Severity, target: &str, name: Option<&str>) -> bool {
if Context::is_current_telemetry_suppressed() {
return false;

Check warning on line 59 in opentelemetry-sdk/src/logs/logger.rs

View check run for this annotation

Codecov / codecov/patch

opentelemetry-sdk/src/logs/logger.rs#L59

Added line #L59 was not covered by tests
}
self.provider
.log_processors()
.iter()
Expand Down
Loading
Loading