From 8e6d8cfbd9ea1a20765477608fda3993fca94513 Mon Sep 17 00:00:00 2001 From: Nalu Tripician Date: Wed, 15 Jul 2026 11:49:38 -0700 Subject: [PATCH] Add span backdating to core tracing traits Add explicit start/end timestamp support to the tracing traits so late-bound (tail-sampled) spans can be reconstructed from an already-completed operation with their original timestamps, rather than being stamped at "now". typespec_client_core (`tracing/mod.rs`): - `Tracer::start_span_at` and `Tracer::start_span_with_parent_at` - `Span::end_at` All three are additive with default implementations that delegate to the existing non-backdating methods, so existing `Tracer`/`Span` implementations keep compiling unchanged (non-breaking, minor-release friendly). `azure_core` re-exports these traits, so its public API gains the methods transitively. azure_core_opentelemetry: - Implement the new methods by mapping to raw OpenTelemetry `SpanBuilder::with_start_time` and `SpanRef::end_with_timestamp`. - Refactor span construction into shared `build_span` / `parent_context` helpers to avoid duplication across the four start_span variants. - Add in-memory-exporter unit tests proving a backdated span (and a backdated parent/child pair) carries the injected PAST timestamps. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- sdk/core/azure_core/CHANGELOG.md | 2 + .../azure_core_opentelemetry/CHANGELOG.md | 2 + sdk/core/azure_core_opentelemetry/src/span.rs | 80 ++++++++++++++++ .../azure_core_opentelemetry/src/tracer.rs | 96 ++++++++++++------- sdk/core/typespec_client_core/CHANGELOG.md | 2 + .../typespec_client_core/src/tracing/mod.rs | 91 +++++++++++++++++- 6 files changed, 239 insertions(+), 34 deletions(-) diff --git a/sdk/core/azure_core/CHANGELOG.md b/sdk/core/azure_core/CHANGELOG.md index a2ccd040ed1..ef3996b6554 100644 --- a/sdk/core/azure_core/CHANGELOG.md +++ b/sdk/core/azure_core/CHANGELOG.md @@ -4,6 +4,8 @@ ### Features Added +- Added `Tracer::start_span_at`, `Tracer::start_span_with_parent_at`, and `Span::end_at` (re-exported from `typespec_client_core`) to allow reconstructing spans with explicit (backdated) start and end timestamps. + ### Breaking Changes ### Bugs Fixed diff --git a/sdk/core/azure_core_opentelemetry/CHANGELOG.md b/sdk/core/azure_core_opentelemetry/CHANGELOG.md index a7f23e09b30..df1229ad3fc 100644 --- a/sdk/core/azure_core_opentelemetry/CHANGELOG.md +++ b/sdk/core/azure_core_opentelemetry/CHANGELOG.md @@ -4,6 +4,8 @@ ### Features Added +- Implemented span backdating (`Tracer::start_span_at`, `Tracer::start_span_with_parent_at`, and `Span::end_at`) by mapping to the OpenTelemetry `SpanBuilder::with_start_time` and `Span::end_with_timestamp` APIs, so late-bound (tail-sampled) spans can be emitted with their original timestamps. + ### Breaking Changes ### Bugs Fixed diff --git a/sdk/core/azure_core_opentelemetry/src/span.rs b/sdk/core/azure_core_opentelemetry/src/span.rs index 84614d11bb4..ccde426037c 100644 --- a/sdk/core/azure_core_opentelemetry/src/span.rs +++ b/sdk/core/azure_core_opentelemetry/src/span.rs @@ -63,6 +63,10 @@ impl Span for OpenTelemetrySpan { self.context.span().end(); } + fn end_at(&self, end_time: std::time::SystemTime) { + self.context.span().end_with_timestamp(end_time); + } + fn span_id(&self) -> [u8; 8] { self.context.span().span_context().span_id().to_bytes() } @@ -154,6 +158,7 @@ mod tests { use opentelemetry_sdk::trace::{in_memory_exporter::InMemorySpanExporter, SdkTracerProvider}; use std::io::{Error, ErrorKind}; use std::sync::Arc; + use std::time::{Duration, SystemTime}; use tracing::trace; fn create_exportable_tracer_provider() -> (Arc, InMemorySpanExporter) { @@ -302,6 +307,81 @@ mod tests { } } + #[test] + fn test_open_telemetry_span_backdated() { + let (otel_tracer_provider, otel_exporter) = create_exportable_tracer_provider(); + let tracer_provider = OpenTelemetryTracerProvider::new(otel_tracer_provider); + let tracer = tracer_provider.get_tracer(Some("Backdated"), "test", Some("0.1.0")); + + // Choose timestamps clearly in the past so we can prove the span is *not* + // stamped at "now". + let now = SystemTime::now(); + let past_start = now - Duration::from_secs(3600); + let past_end = now - Duration::from_secs(1800); + + let span = tracer.start_span_at( + "backdated_span".into(), + SpanKind::Client, + vec![], + past_start, + ); + span.end_at(past_end); + + let spans = otel_exporter.get_finished_spans().unwrap(); + assert_eq!(spans.len(), 1); + let span = &spans[0]; + assert_eq!(span.name, "backdated_span"); + // The injected past timestamps must be preserved exactly, not replaced with "now". + assert_eq!(span.start_time, past_start); + assert_eq!(span.end_time, past_end); + assert!(span.start_time < span.end_time); + assert!(span.end_time < now); + } + + #[test] + fn test_open_telemetry_span_backdated_with_parent() { + let (otel_tracer_provider, otel_exporter) = create_exportable_tracer_provider(); + let tracer_provider = OpenTelemetryTracerProvider::new(otel_tracer_provider); + let tracer = tracer_provider.get_tracer(Some("Backdated"), "test", Some("0.1.0")); + + // Reconstruct a completed operation: a backdated root with a backdated attempt child. + let now = SystemTime::now(); + let root_start = now - Duration::from_secs(600); + let child_start = now - Duration::from_secs(590); + let child_end = now - Duration::from_secs(585); + let root_end = now - Duration::from_secs(580); + + let root = tracer.start_span_at("operation".into(), SpanKind::Client, vec![], root_start); + let child = tracer.start_span_with_parent_at( + "attempt".into(), + SpanKind::Client, + vec![], + root.clone(), + child_start, + ); + child.end_at(child_end); + root.end_at(root_end); + + let spans = otel_exporter.get_finished_spans().unwrap(); + assert_eq!(spans.len(), 2); + + let root_span = spans.iter().find(|s| s.name == "operation").unwrap(); + let child_span = spans.iter().find(|s| s.name == "attempt").unwrap(); + + assert_eq!(root_span.start_time, root_start); + assert_eq!(root_span.end_time, root_end); + assert_eq!(child_span.start_time, child_start); + assert_eq!(child_span.end_time, child_end); + assert!(root_span.end_time < now); + + // The child must be parented to the backdated root. + assert_ne!( + child_span.parent_span_id, + opentelemetry::trace::SpanId::INVALID + ); + assert_eq!(child_span.parent_span_id.to_bytes(), root.span_id()); + } + #[test] fn test_open_telemetry_span_set_attribute() { let (otel_tracer_provider, otel_exporter) = create_exportable_tracer_provider(); diff --git a/sdk/core/azure_core_opentelemetry/src/tracer.rs b/sdk/core/azure_core_opentelemetry/src/tracer.rs index 5d123d25909..fd36e8e5f19 100644 --- a/sdk/core/azure_core_opentelemetry/src/tracer.rs +++ b/sdk/core/azure_core_opentelemetry/src/tracer.rs @@ -12,7 +12,7 @@ use opentelemetry::{ trace::{TraceContextExt, Tracer as OpenTelemetryTracerTrait}, Context, KeyValue, }; -use std::{borrow::Cow, fmt::Debug, sync::Arc}; +use std::{borrow::Cow, fmt::Debug, sync::Arc, time::SystemTime}; pub struct OpenTelemetryTracer { namespace: Option<&'static str>, @@ -27,6 +27,45 @@ impl OpenTelemetryTracer { inner: tracer, } } + + /// Builds a span within `context`, optionally backdated to `start_time`. + fn build_span( + &self, + name: Cow<'static, str>, + kind: SpanKind, + attributes: Vec, + start_time: Option, + context: Context, + ) -> Arc { + let mut span_builder = opentelemetry::trace::SpanBuilder::from_name(name) + .with_kind(OpenTelemetrySpanKind(kind).into()) + .with_attributes( + attributes + .iter() + .map(|attr| KeyValue::from(OpenTelemetryAttribute(attr.clone()))), + ); + if let Some(start_time) = start_time { + span_builder = span_builder.with_start_time(start_time); + } + let span = self.inner.build_with_context(span_builder, &context); + + OpenTelemetrySpan::new(context.with_span(span)) + } + + /// Extracts the OpenTelemetry context from a parent span. + fn parent_context(parent: &Arc) -> Context { + parent + .as_any() + .downcast_ref::() + .unwrap_or_else(|| { + panic!( + "Could not downcast parent span to OpenTelemetrySpan. Actual type: {}", + std::any::type_name::() + ) + }) + .context() + .clone() + } } impl Debug for OpenTelemetryTracer { @@ -48,17 +87,17 @@ impl Tracer for OpenTelemetryTracer { kind: SpanKind, attributes: Vec, ) -> Arc { - let span_builder = opentelemetry::trace::SpanBuilder::from_name(name) - .with_kind(OpenTelemetrySpanKind(kind).into()) - .with_attributes( - attributes - .iter() - .map(|attr| KeyValue::from(OpenTelemetryAttribute(attr.clone()))), - ); - let context = Context::current(); - let span = self.inner.build_with_context(span_builder, &context); + self.build_span(name, kind, attributes, None, Context::current()) + } - OpenTelemetrySpan::new(context.with_span(span)) + fn start_span_at( + &self, + name: Cow<'static, str>, + kind: SpanKind, + attributes: Vec, + start_time: SystemTime, + ) -> Arc { + self.build_span(name, kind, attributes, Some(start_time), Context::current()) } fn start_span_with_parent( @@ -68,29 +107,20 @@ impl Tracer for OpenTelemetryTracer { attributes: Vec, parent: Arc, ) -> Arc { - let span_builder = opentelemetry::trace::SpanBuilder::from_name(name) - .with_kind(OpenTelemetrySpanKind(kind).into()) - .with_attributes( - attributes - .iter() - .map(|attr| KeyValue::from(OpenTelemetryAttribute(attr.clone()))), - ); - - // Cast the parent span to Any type - let context = parent - .as_any() - .downcast_ref::() - .unwrap_or_else(|| { - panic!( - "Could not downcast parent span to OpenTelemetrySpan. Actual type: {}", - std::any::type_name::() - ) - }) - .context() - .clone(); - let span = self.inner.build_with_context(span_builder, &context); + let context = Self::parent_context(&parent); + self.build_span(name, kind, attributes, None, context) + } - OpenTelemetrySpan::new(context.with_span(span)) + fn start_span_with_parent_at( + &self, + name: Cow<'static, str>, + kind: SpanKind, + attributes: Vec, + parent: Arc, + start_time: SystemTime, + ) -> Arc { + let context = Self::parent_context(&parent); + self.build_span(name, kind, attributes, Some(start_time), context) } } diff --git a/sdk/core/typespec_client_core/CHANGELOG.md b/sdk/core/typespec_client_core/CHANGELOG.md index b833ee03eb0..b06a9c90d18 100644 --- a/sdk/core/typespec_client_core/CHANGELOG.md +++ b/sdk/core/typespec_client_core/CHANGELOG.md @@ -4,6 +4,8 @@ ### Features Added +- Added `Tracer::start_span_at`, `Tracer::start_span_with_parent_at`, and `Span::end_at` to allow reconstructing spans with explicit (backdated) start and end timestamps. These are additive with default implementations, so existing `Tracer`/`Span` implementations continue to work unchanged. + ### Breaking Changes ### Bugs Fixed diff --git a/sdk/core/typespec_client_core/src/tracing/mod.rs b/sdk/core/typespec_client_core/src/tracing/mod.rs index cd425d84843..854ba110572 100644 --- a/sdk/core/typespec_client_core/src/tracing/mod.rs +++ b/sdk/core/typespec_client_core/src/tracing/mod.rs @@ -4,7 +4,7 @@ //! Distributed tracing trait definitions //! use crate::http::{Context, Request}; -use std::{borrow::Cow, fmt::Debug, sync::Arc}; +use std::{borrow::Cow, fmt::Debug, sync::Arc, time::SystemTime}; /// Overall architecture for distributed tracing in the SDK. /// @@ -83,6 +83,75 @@ pub trait Tracer: Send + Sync + Debug { parent: Arc, ) -> Arc; + /// Starts a new span with the given name and type, backdated to an explicit start time. + /// + /// This is the backdating variant of [`Tracer::start_span`]. It lets a caller + /// reconstruct a span for an operation that has *already completed* by recording the + /// timestamp at which the operation actually started, rather than "now". This is + /// required for tail-based (late-bound) sampling, where the decision to emit a span is + /// made after the operation finishes. The newly created span will have the "current" + /// span as a parent. + /// + /// # Arguments + /// - `name`: The name of the span to start. + /// - `kind`: The type of the span to start. + /// - `attributes`: A vector of attributes to associate with the span. + /// - `start_time`: The explicit start time to record for the span. + /// + /// # Returns + /// An `Arc` representing the started span. + /// + /// # Note + /// The default implementation ignores `start_time` and delegates to + /// [`Tracer::start_span`] so that existing implementations remain source-compatible. + /// Implementations backed by a tracing system that supports explicit timestamps (such + /// as the OpenTelemetry bridge) override this to honor `start_time`. + fn start_span_at( + &self, + name: Cow<'static, str>, + kind: SpanKind, + attributes: Vec, + start_time: SystemTime, + ) -> Arc { + let _ = start_time; + self.start_span(name, kind, attributes) + } + + /// Starts a new child span with the given name, type, and parent span, backdated to an explicit start time. + /// + /// This is the backdating variant of [`Tracer::start_span_with_parent`]. It lets a + /// caller reconstruct a child span (for example, a single retry attempt) under an + /// explicit parent using the timestamp at which the child operation actually started. + /// + /// # Arguments + /// - `name`: The name of the span to start. + /// - `kind`: The type of the span to start. + /// - `attributes`: A vector of attributes to associate with the span. + /// - `parent`: The parent span to use for the new span. + /// - `start_time`: The explicit start time to record for the span. + /// + /// # Returns + /// An `Arc` representing the started span. + /// + /// # Note + /// The default implementation ignores `start_time` and delegates to + /// [`Tracer::start_span_with_parent`] so that existing implementations remain + /// source-compatible. Implementations backed by a tracing system that supports explicit + /// timestamps (such as the OpenTelemetry bridge) override this to honor `start_time`. + /// + /// Note: This method may panic if the parent span cannot be downcasted to the expected type. + fn start_span_with_parent_at( + &self, + name: Cow<'static, str>, + kind: SpanKind, + attributes: Vec, + parent: Arc, + start_time: SystemTime, + ) -> Arc { + let _ = start_time; + self.start_span_with_parent(name, kind, attributes, parent) + } + /// Returns the namespace the tracer was configured with (if any). /// /// # Returns @@ -147,6 +216,26 @@ pub trait Span: AsAny + Send + Sync { /// Ends the current span. fn end(&self); + /// Ends the current span at an explicit end time. + /// + /// This is the backdating variant of [`Span::end`]. It lets a caller close a + /// reconstructed span at the timestamp the operation actually finished, rather than + /// "now" — the counterpart to [`Tracer::start_span_at`] for late-bound (tail-sampled) + /// spans. + /// + /// # Arguments + /// - `end_time`: The explicit end time to record for the span. + /// + /// # Note + /// The default implementation ignores `end_time` and delegates to [`Span::end`] so that + /// existing implementations remain source-compatible. Implementations backed by a + /// tracing system that supports explicit timestamps (such as the OpenTelemetry bridge) + /// override this to honor `end_time`. + fn end_at(&self, end_time: SystemTime) { + let _ = end_time; + self.end(); + } + /// Sets the status of the current span. /// # Arguments /// - `status`: The status to set for the current span.