Skip to content

Commit 42f68fa

Browse files
authored
fix: report dropped OpenTelemetry spans (#686)
#### Overview Report OpenTelemetry batch-queue span loss through plugin runtime diagnostics instead of relying only on SDK warning logs that language bindings do not configure or expose consistently. - [x] I confirm this contribution is my own work, or I have the right to submit it under this project's license. - [x] I searched existing issues and open pull requests, and this does not duplicate existing work. #### Details - Wrap each plugin-managed OpenTelemetry batch processor with counters for completed and exporter-accepted spans. - Emit `otel.spans_dropped` with the exact dropped count, the indexed endpoint configuration field, and the configured endpoint URL during graceful shutdown. - Treat the diagnostic as a recoverable runtime delivery failure so teardown retains the plugin report without disabling later configuration. - Aggregate every OpenTelemetry provider shutdown result and permit reconfiguration only when every failure is a dropped-span delivery failure. - Add a deterministic saturated-queue regression test and document the runtime diagnostic behavior. Validation: - `cargo fmt --all` passed. - `cargo clippy --workspace --all-targets -- -D warnings` passed. - Focused dropped-span, provider-shutdown aggregation, and teardown-classification tests passed. - `uv run pre-commit run --all-files` passed. - `just docs` passed; the redirects check was skipped after the remote FDR service returned 403. - `just test-rust`: the core and non-FFI workspace passed. The FFI phase inherited `/Users/wkillian/.nemo-relay/plugins.toml`, failed its first empty-diagnostics assertion, and then reported 10 poisoned-lock cascades. - `just test-python`: 603 tests passed; 11 failures came from the same discovered user configuration and its active-plugin cascade. - `just test-go` passed. - `just test-node`: 339 tests passed; 10 failures came from the same discovered user configuration and its active-plugin cascade. #### Where should the reviewer start? Start with `DiagnosticBatchSpanProcessor` in `crates/core/src/observability/otel.rs`, then review `dropped_spans_are_recorded_in_the_active_plugin_report` and the recoverable teardown marker handling in `crates/core/src/plugin.rs`. #### Related Issues: (use one of the action keywords Closes / Fixes / Resolves / Relates to) - Closes RELAY-602 ## Summary by CodeRabbit - **New Features** - Added runtime diagnostics for OpenTelemetry spans dropped during batching, including the drop count and affected endpoint. - Delivery failures are now reported consistently during OpenTelemetry and ATIF plugin shutdowns. - Shutdown now preserves diagnostics and reports failures across multiple endpoints, supporting safer reconfiguration. - **Documentation** - Updated OpenTelemetry guidance with details about drop diagnostics and graceful shutdown. - Clarified that clearing the plugin enables final queued spans to be exported and records remaining delivery failures. Authors: - Will Killian (https://github.com/willkill07) Approvers: - Eric Evans II (https://github.com/ericevans-nv) URL: #686
1 parent 0ef068f commit 42f68fa

7 files changed

Lines changed: 482 additions & 37 deletions

File tree

crates/core/src/observability/otel.rs

Lines changed: 174 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
use std::borrow::Cow;
1818
use std::cell::RefCell;
1919
use std::collections::{HashMap, HashSet, VecDeque};
20+
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
2021
use std::sync::mpsc;
2122
use std::sync::{Arc, Mutex};
2223
use std::thread;
@@ -42,13 +43,22 @@ use opentelemetry::trace::{
4243
Tracer, TracerProvider as _,
4344
};
4445
use opentelemetry::{Context, KeyValue};
45-
use opentelemetry_otlp::{Protocol, SpanExporter, WithExportConfig, WithHttpConfig};
46+
use opentelemetry_otlp::{
47+
Protocol, SpanExporter as OtlpSpanExporter, WithExportConfig, WithHttpConfig,
48+
};
4649
use opentelemetry_sdk::Resource;
50+
use opentelemetry_sdk::error::{OTelSdkError, OTelSdkResult};
4751
use opentelemetry_sdk::trace::{
48-
IdGenerator, RandomIdGenerator, SdkTracer, SdkTracerProvider, Span,
52+
BatchSpanProcessor, IdGenerator, RandomIdGenerator, SdkTracer, SdkTracerProvider, Span,
53+
SpanData, SpanExporter, SpanProcessor,
4954
};
5055
use uuid::Uuid;
5156

57+
use crate::plugin::{
58+
OTEL_RUNTIME_DELIVERY_FAILURE_MARKER, RuntimeDiagnostic,
59+
record_active_plugin_runtime_diagnostic,
60+
};
61+
5262
pub(super) const COMPLETED_SPAN_CONTEXT_LIMIT: usize = 4096;
5363

5464
use opentelemetry_otlp::WithTonicConfig;
@@ -397,6 +407,25 @@ impl Drop for ExporterRuntime {
397407
impl OpenTelemetrySubscriber {
398408
/// Builds a subscriber backed by a new OTLP tracer provider.
399409
pub fn new(config: OpenTelemetryConfig) -> Result<Self> {
410+
Self::new_with_runtime_diagnostics(config, None)
411+
}
412+
413+
pub(crate) fn new_for_plugin(
414+
config: OpenTelemetryConfig,
415+
endpoint_index: usize,
416+
) -> Result<Self> {
417+
Self::new_with_runtime_diagnostics(
418+
config,
419+
Some(format!(
420+
"opentelemetry.endpoints[{endpoint_index}].endpoint"
421+
)),
422+
)
423+
}
424+
425+
fn new_with_runtime_diagnostics(
426+
config: OpenTelemetryConfig,
427+
diagnostic_field: Option<String>,
428+
) -> Result<Self> {
400429
if config.endpoint.trim().is_empty() {
401430
return Err(OpenTelemetryError::ExporterBuild(
402431
"endpoint must be a nonblank string".to_string(),
@@ -406,7 +435,7 @@ impl OpenTelemetrySubscriber {
406435
.map_err(OpenTelemetryError::InvalidAttributeMappings)?;
407436
reject_global_header_environment()?;
408437
validate_headers(&config.headers)?;
409-
let (provider, runtime) = build_owned_tracer_provider(config.clone())?;
438+
let (provider, runtime) = build_owned_tracer_provider(config.clone(), diagnostic_field)?;
410439
Ok(Self::from_tracer_provider_with_scope_and_type(
411440
provider,
412441
config.instrumentation_scope,
@@ -617,6 +646,7 @@ impl OpenTelemetrySubscriber {
617646

618647
fn build_owned_tracer_provider(
619648
config: OpenTelemetryConfig,
649+
diagnostic_field: Option<String>,
620650
) -> Result<(SdkTracerProvider, ExporterRuntime)> {
621651
let (result_sender, result_receiver) = mpsc::sync_channel(1);
622652
let (stop_sender, stop_receiver) = mpsc::channel();
@@ -637,7 +667,7 @@ fn build_owned_tracer_provider(
637667
};
638668
let provider = {
639669
let _guard = runtime.enter();
640-
build_tracer_provider(&config)
670+
build_tracer_provider(&config, diagnostic_field)
641671
};
642672
let keep_runtime_alive = provider.is_ok();
643673
let _ = result_sender.send(provider);
@@ -696,10 +726,13 @@ pub(crate) fn validate_headers(headers: &HashMap<String, String>) -> Result<()>
696726
Ok(())
697727
}
698728

699-
fn build_tracer_provider(config: &OpenTelemetryConfig) -> Result<SdkTracerProvider> {
729+
fn build_tracer_provider(
730+
config: &OpenTelemetryConfig,
731+
diagnostic_field: Option<String>,
732+
) -> Result<SdkTracerProvider> {
700733
let exporter = match config.transport {
701734
OtlpTransport::HttpBinary => {
702-
let mut builder = SpanExporter::builder()
735+
let mut builder = OtlpSpanExporter::builder()
703736
.with_http()
704737
.with_protocol(Protocol::HttpBinary)
705738
.with_timeout(config.timeout);
@@ -713,7 +746,7 @@ fn build_tracer_provider(config: &OpenTelemetryConfig) -> Result<SdkTracerProvid
713746
.map_err(|e| OpenTelemetryError::ExporterBuild(e.to_string()))?
714747
}
715748
OtlpTransport::Grpc => {
716-
let mut builder = SpanExporter::builder()
749+
let mut builder = OtlpSpanExporter::builder()
717750
.with_tonic()
718751
.with_protocol(Protocol::Grpc)
719752
.with_timeout(config.timeout);
@@ -754,7 +787,140 @@ fn build_tracer_provider(config: &OpenTelemetryConfig) -> Result<SdkTracerProvid
754787
.with_max_attributes_per_span(u32::MAX)
755788
.with_max_attributes_per_event(u32::MAX);
756789

757-
Ok(builder.with_batch_exporter(exporter).build())
790+
let processor =
791+
DiagnosticBatchSpanProcessor::new(exporter, config.endpoint.clone(), diagnostic_field);
792+
Ok(builder.with_span_processor(processor).build())
793+
}
794+
795+
#[derive(Debug)]
796+
struct CountingSpanExporter<E> {
797+
inner: E,
798+
accepted_spans: Arc<AtomicU64>,
799+
}
800+
801+
impl<E: SpanExporter> SpanExporter for CountingSpanExporter<E> {
802+
async fn export(&self, batch: Vec<SpanData>) -> OTelSdkResult {
803+
self.accepted_spans
804+
.fetch_add(batch.len() as u64, Ordering::Relaxed);
805+
self.inner.export(batch).await
806+
}
807+
808+
fn shutdown_with_timeout(&self, timeout: Duration) -> OTelSdkResult {
809+
self.inner.shutdown_with_timeout(timeout)
810+
}
811+
812+
fn force_flush(&self) -> OTelSdkResult {
813+
self.inner.force_flush()
814+
}
815+
816+
fn set_resource(&mut self, resource: &Resource) {
817+
self.inner.set_resource(resource);
818+
}
819+
}
820+
821+
#[derive(Debug)]
822+
struct DiagnosticBatchSpanProcessor {
823+
inner: BatchSpanProcessor,
824+
completed_spans: AtomicU64,
825+
accepted_spans: Arc<AtomicU64>,
826+
endpoint: String,
827+
diagnostic_field: Option<String>,
828+
diagnostic_reported: AtomicBool,
829+
}
830+
831+
impl DiagnosticBatchSpanProcessor {
832+
fn new<E: SpanExporter + 'static>(
833+
exporter: E,
834+
endpoint: String,
835+
diagnostic_field: Option<String>,
836+
) -> Self {
837+
Self::new_with_batch_config(
838+
exporter,
839+
endpoint,
840+
diagnostic_field,
841+
opentelemetry_sdk::trace::BatchConfig::default(),
842+
)
843+
}
844+
845+
fn new_with_batch_config<E: SpanExporter + 'static>(
846+
exporter: E,
847+
endpoint: String,
848+
diagnostic_field: Option<String>,
849+
batch_config: opentelemetry_sdk::trace::BatchConfig,
850+
) -> Self {
851+
let accepted_spans = Arc::new(AtomicU64::new(0));
852+
let exporter = CountingSpanExporter {
853+
inner: exporter,
854+
accepted_spans: Arc::clone(&accepted_spans),
855+
};
856+
Self {
857+
inner: BatchSpanProcessor::builder(exporter)
858+
.with_batch_config(batch_config)
859+
.build(),
860+
completed_spans: AtomicU64::new(0),
861+
accepted_spans,
862+
endpoint,
863+
diagnostic_field,
864+
diagnostic_reported: AtomicBool::new(false),
865+
}
866+
}
867+
868+
fn record_dropped_spans(&self) -> u64 {
869+
let dropped = self
870+
.completed_spans
871+
.load(Ordering::Relaxed)
872+
.saturating_sub(self.accepted_spans.load(Ordering::Relaxed));
873+
if dropped == 0
874+
|| self.diagnostic_field.is_none()
875+
|| self.diagnostic_reported.swap(true, Ordering::Relaxed)
876+
{
877+
return dropped;
878+
}
879+
record_active_plugin_runtime_diagnostic(RuntimeDiagnostic {
880+
code: "otel.spans_dropped".to_string(),
881+
component: "observability".to_string(),
882+
field: self.diagnostic_field.clone(),
883+
message: format!(
884+
"OpenTelemetry dropped {dropped} spans before export to endpoint {} because the batch queue was full",
885+
self.endpoint
886+
),
887+
session_id: None,
888+
count: dropped,
889+
});
890+
dropped
891+
}
892+
}
893+
894+
impl SpanProcessor for DiagnosticBatchSpanProcessor {
895+
fn on_start(&self, span: &mut Span, cx: &Context) {
896+
self.inner.on_start(span, cx);
897+
}
898+
899+
fn on_end(&self, span: SpanData) {
900+
self.completed_spans.fetch_add(1, Ordering::Relaxed);
901+
self.inner.on_end(span);
902+
}
903+
904+
fn force_flush(&self) -> OTelSdkResult {
905+
self.inner.force_flush()
906+
}
907+
908+
fn shutdown_with_timeout(&self, timeout: Duration) -> OTelSdkResult {
909+
let result = self.inner.shutdown_with_timeout(timeout);
910+
if result.is_ok() {
911+
let dropped = self.record_dropped_spans();
912+
if dropped > 0 && self.diagnostic_field.is_some() {
913+
return Err(OTelSdkError::InternalFailure(format!(
914+
"{OTEL_RUNTIME_DELIVERY_FAILURE_MARKER}: otel.spans_dropped ({dropped})"
915+
)));
916+
}
917+
}
918+
result
919+
}
920+
921+
fn set_resource(&mut self, resource: &Resource) {
922+
self.inner.set_resource(resource);
923+
}
758924
}
759925

760926
fn build_grpc_metadata(headers: &HashMap<String, String>) -> Result<MetadataMap> {

crates/core/src/observability/plugin_component.rs

Lines changed: 32 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -60,17 +60,15 @@ use crate::observability::{
6060
validate_attribute_mappings,
6161
};
6262
use crate::plugin::{
63-
ConfigDiagnostic, ConfigPolicy, DiagnosticLevel, Plugin, PluginComponentSpec, PluginError,
63+
ATIF_RUNTIME_DELIVERY_FAILURE_MARKER, ConfigDiagnostic, ConfigPolicy, DiagnosticLevel,
64+
OTEL_RUNTIME_DELIVERY_FAILURE_MARKER, Plugin, PluginComponentSpec, PluginError,
6465
PluginRegistration, PluginRegistrationContext, Result as PluginResult, UnsupportedBehavior,
6566
apply_global_config_policy, deregister_plugin, register_builtin_plugin,
6667
};
6768
use crate::plugin::{RuntimeDiagnostic, record_active_plugin_runtime_diagnostic};
6869

6970
/// The plugin kind registered by the core crate.
7071
pub const OBSERVABILITY_PLUGIN_KIND: &str = "observability";
71-
/// Identifies teardown errors caused by recoverable ATIF delivery failures.
72-
pub(crate) const ATIF_RUNTIME_DELIVERY_FAILURE_MARKER: &str = "ATIF runtime delivery failures";
73-
7472
/// Top-level observability component wrapper.
7573
///
7674
/// Use this wrapper when constructing a [`PluginComponentSpec`] from Rust
@@ -1036,14 +1034,14 @@ fn build_opentelemetry_subscribers(
10361034
let mut subscribers = Vec::with_capacity(endpoints.len());
10371035
for (index, endpoint) in endpoints.into_iter().enumerate() {
10381036
let subscriber = build_otel_config(index, endpoint).and_then(|config| {
1039-
OpenTelemetrySubscriber::new(config)
1037+
OpenTelemetrySubscriber::new_for_plugin(config, index)
10401038
.map(Arc::new)
10411039
.map_err(observability_registration_error)
10421040
});
10431041
match subscriber {
10441042
Ok(subscriber) => subscribers.push(subscriber),
10451043
Err(error) => {
1046-
if let Some(_rollback_error) = shutdown_opentelemetry_providers(&subscribers) {
1044+
if !shutdown_opentelemetry_providers(&subscribers).is_empty() {
10471045
log::warn!(
10481046
target: "nemo_relay.plugin",
10491047
event = "plugin_resource_rollback_failed",
@@ -1063,28 +1061,43 @@ fn build_opentelemetry_subscribers(
10631061
fn shutdown_opentelemetry_subscribers(
10641062
subscribers: &[Arc<OpenTelemetrySubscriber>],
10651063
) -> Option<PluginError> {
1066-
let mut first_error = flush_subscribers().err().map(|error| {
1067-
observability_registration_error(crate::observability::otel::OpenTelemetryError::Core(
1068-
error,
1069-
))
1070-
});
1071-
let provider_error = shutdown_opentelemetry_providers(subscribers);
1072-
if first_error.is_none() {
1073-
first_error = provider_error;
1064+
let mut errors = Vec::new();
1065+
if let Err(error) = flush_subscribers() {
1066+
errors.push(crate::observability::otel::OpenTelemetryError::Core(error));
10741067
}
1075-
first_error
1068+
errors.extend(shutdown_opentelemetry_providers(subscribers));
1069+
if errors.is_empty() {
1070+
return None;
1071+
}
1072+
1073+
let all_delivery_failures = errors.iter().all(|error| {
1074+
error
1075+
.to_string()
1076+
.contains(OTEL_RUNTIME_DELIVERY_FAILURE_MARKER)
1077+
});
1078+
let summary = errors
1079+
.into_iter()
1080+
.map(|error| error.to_string())
1081+
.collect::<Vec<_>>()
1082+
.join("; ");
1083+
let message = if all_delivery_failures {
1084+
format!("{OTEL_RUNTIME_DELIVERY_FAILURE_MARKER}: {summary}")
1085+
} else {
1086+
format!("OpenTelemetry shutdown failures: {summary}")
1087+
};
1088+
Some(PluginError::RegistrationFailed(message))
10761089
}
10771090

10781091
fn shutdown_opentelemetry_providers(
10791092
subscribers: &[Arc<OpenTelemetrySubscriber>],
1080-
) -> Option<PluginError> {
1081-
let mut first_error = None;
1093+
) -> Vec<crate::observability::otel::OpenTelemetryError> {
1094+
let mut errors = Vec::new();
10821095
for subscriber in subscribers {
10831096
if let Err(error) = subscriber.shutdown_provider() {
1084-
first_error.get_or_insert_with(|| observability_registration_error(error));
1097+
errors.push(error);
10851098
}
10861099
}
1087-
first_error
1100+
errors
10881101
}
10891102

10901103
struct AtifDispatcher {

crates/core/src/plugin.rs

Lines changed: 16 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,6 @@ use crate::api::runtime::{
4444
ToolExecutionFn, ToolInterceptFn, ToolSanitizeFn,
4545
};
4646
use crate::api::subscriber::{deregister_subscriber, register_subscriber};
47-
use crate::observability::plugin_component::ATIF_RUNTIME_DELIVERY_FAILURE_MARKER;
4847
pub use nemo_relay_types::plugin::{ConfigDiagnostic, DiagnosticLevel};
4948

5049
pub mod dynamic;
@@ -127,6 +126,12 @@ pub enum PluginError {
127126
/// Specialized [`Result`](std::result::Result) type for plugin operations.
128127
pub type Result<T> = std::result::Result<T, PluginError>;
129128

129+
/// Identifies teardown errors caused by recoverable ATIF delivery failures.
130+
pub(crate) const ATIF_RUNTIME_DELIVERY_FAILURE_MARKER: &str = "ATIF runtime delivery failures";
131+
/// Identifies teardown errors caused by recoverable OpenTelemetry delivery failures.
132+
pub(crate) const OTEL_RUNTIME_DELIVERY_FAILURE_MARKER: &str =
133+
"OpenTelemetry runtime delivery failures";
134+
130135
/// Canonical plugin configuration document.
131136
#[derive(Debug, Clone, Serialize, Deserialize)]
132137
#[cfg_attr(feature = "schema", derive(schemars::JsonSchema))]
@@ -2138,7 +2143,7 @@ fn clear_plugin_configuration_inner() -> PluginHostClearOutcome {
21382143
// removal itself as unsafe.
21392144
let callbacks_cleared = deregistration_errors
21402145
.iter()
2141-
.all(|error| error.contains(ATIF_RUNTIME_DELIVERY_FAILURE_MARKER));
2146+
.all(|error| is_runtime_delivery_failure(error));
21422147
let deregistration_error = (!deregistration_errors.is_empty()).then(|| {
21432148
PluginError::RegistrationFailed(format!(
21442149
"plugin teardown failed: {}",
@@ -2169,6 +2174,15 @@ fn clear_plugin_configuration_inner() -> PluginHostClearOutcome {
21692174
}
21702175
}
21712176

2177+
fn is_runtime_delivery_failure(error: &str) -> bool {
2178+
[
2179+
ATIF_RUNTIME_DELIVERY_FAILURE_MARKER,
2180+
OTEL_RUNTIME_DELIVERY_FAILURE_MARKER,
2181+
]
2182+
.iter()
2183+
.any(|marker| error.contains(&format!("registration failed: {marker}:")))
2184+
}
2185+
21722186
pub(crate) fn plugin_configuration_is_active() -> Result<bool> {
21732187
ACTIVE_PLUGIN_CONFIGURATION
21742188
.lock()

0 commit comments

Comments
 (0)