From caa4246ca3aea391375e1c504c3ae144809cc234 Mon Sep 17 00:00:00 2001 From: Cijo Thomas Date: Sat, 12 Oct 2024 10:29:11 -0700 Subject: [PATCH] Add tests to confirm known deadlock issues (#2199) --- opentelemetry-appender-tracing/Cargo.toml | 1 + opentelemetry-appender-tracing/src/layer.rs | 73 ++++++++++++++++++++- 2 files changed, 71 insertions(+), 3 deletions(-) diff --git a/opentelemetry-appender-tracing/Cargo.toml b/opentelemetry-appender-tracing/Cargo.toml index e443b91fba..38e2cb21d9 100644 --- a/opentelemetry-appender-tracing/Cargo.toml +++ b/opentelemetry-appender-tracing/Cargo.toml @@ -26,6 +26,7 @@ tracing-subscriber = { workspace = true, features = ["registry", "std", "env-fil tracing-log = "0.2" async-trait = { workspace = true } criterion = { workspace = true } +tokio = { workspace = true, features = ["full"]} [target.'cfg(not(target_os = "windows"))'.dev-dependencies] pprof = { version = "0.13", features = ["flamegraph", "criterion"] } diff --git a/opentelemetry-appender-tracing/src/layer.rs b/opentelemetry-appender-tracing/src/layer.rs index 1bfbef0fcf..fbbf8e4d97 100644 --- a/opentelemetry-appender-tracing/src/layer.rs +++ b/opentelemetry-appender-tracing/src/layer.rs @@ -208,17 +208,20 @@ const fn severity_of_level(level: &Level) -> Severity { #[cfg(test)] mod tests { use crate::layer; - use opentelemetry::logs::Severity; + use async_trait::async_trait; + use opentelemetry::logs::{LogResult, Severity}; use opentelemetry::trace::TracerProvider as _; use opentelemetry::trace::{TraceContextExt, TraceFlags, Tracer}; use opentelemetry::{logs::AnyValue, Key}; + use opentelemetry_sdk::export::logs::{LogBatch, LogExporter}; use opentelemetry_sdk::logs::{LogRecord, LoggerProvider}; use opentelemetry_sdk::testing::logs::InMemoryLogsExporter; use opentelemetry_sdk::trace; use opentelemetry_sdk::trace::{Sampler, TracerProvider}; - use tracing::error; + use tracing::{error, warn}; use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt; - use tracing_subscriber::Layer; + use tracing_subscriber::util::SubscriberInitExt; + use tracing_subscriber::{EnvFilter, Layer}; pub fn attributes_contains(log_record: &LogRecord, key: &Key, value: &AnyValue) -> bool { log_record @@ -238,6 +241,70 @@ mod tests { } // cargo test --features=testing + + #[derive(Clone, Debug, Default)] + struct ReentrantLogExporter; + + #[async_trait] + impl LogExporter for ReentrantLogExporter { + async fn export(&mut self, _batch: LogBatch<'_>) -> LogResult<()> { + // 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 = "otel@opentelemetry.io"); + 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 = LoggerProvider::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 = "otel@opentelemetry.io"); + } + + #[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 = LoggerProvider::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 = "otel@opentelemetry.io"); + } + + #[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 = LoggerProvider::builder() + .with_batch_exporter(exporter.clone(), opentelemetry_sdk::runtime::Tokio) + .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 = "otel@opentelemetry.io"); + } + #[test] fn tracing_appender_standalone() { // Arrange