opentelemetry: update to otel 0.14.x (#1394)

## Motivation

Support the latest OpenTelemetry specification.

## Solution

Update `opentelemetry` to the latest `0.14.x` release. Despite breaking
changes upstream, no additional public API or behavioral changes are
necessary in `tracing-opentelemetry`, but simplifications in the
propagation of span information have removed the need for the current
internal `CompatSpan` and custom parent context construction.

Performance has improved by ~30% on current benchmarks.

Author: jtescher

examples/Cargo.toml

@@ -51,5 +51,5 @@ inferno = "0.10.0"
 tempdir = "0.3.7"
 
 # opentelemetry example
-opentelemetry = { version = "0.13", default-features = false, features = ["trace"] }
-opentelemetry-jaeger = "0.12"
+opentelemetry = { version = "0.14", default-features = false, features = ["trace"] }
+opentelemetry-jaeger = "0.13"

tracing-opentelemetry/Cargo.toml

@@ -22,7 +22,7 @@ edition = "2018"
 default = ["tracing-log"]
 
 [dependencies]
-opentelemetry = { version = "0.13", default-features = false, features = ["trace"] }
+opentelemetry = { version = "0.14", default-features = false, features = ["trace"] }
 tracing = { path = "../tracing", version = "0.2", default-features = false, features = ["std"] }
 tracing-core = { path = "../tracing-core", version = "0.2" }
 tracing-subscriber = { path = "../tracing-subscriber", version = "0.3", default-features = false, features = ["registry"] }
@@ -31,7 +31,7 @@ tracing-log = { path = "../tracing-log", version = "0.2", default-features = fal
 [dev-dependencies]
 async-trait = "0.1"
 criterion = { version = "0.3", default_features = false }
-opentelemetry-jaeger = "0.12"
+opentelemetry-jaeger = "0.13"
 
 [lib]
 bench = false

tracing-opentelemetry/src/span_ext.rs

@@ -78,7 +78,9 @@ impl OpenTelemetrySpanExt for tracing::Span {
         self.with_collector(move |(id, collector)| {
             if let Some(get_context) = collector.downcast_ref::<WithContext>() {
                 get_context.with_context(collector, id, move |builder, _tracer| {
-                    builder.parent_context = cx.take();
+                    if let Some(cx) = cx.take() {
+                        builder.parent_context = cx;
+                    }
                 });
             }
         });

tracing-opentelemetry/src/subscriber.rs

@@ -210,7 +210,7 @@ impl<'a> field::Visit for SpanAttributeVisitor<'a> {
             SPAN_NAME_FIELD => self.0.name = value.to_string().into(),
             SPAN_KIND_FIELD => self.0.span_kind = str_to_span_kind(value),
             SPAN_STATUS_CODE_FIELD => self.0.status_code = str_to_status_code(value),
-            SPAN_STATUS_MESSAGE_FIELD => self.0.status_message = Some(value.to_owned()),
+            SPAN_STATUS_MESSAGE_FIELD => self.0.status_message = Some(value.to_owned().into()),
             _ => {
                 let attribute = KeyValue::new(field.name(), value.to_string());
                 if let Some(attributes) = &mut self.0.attributes {
@@ -233,7 +233,9 @@ impl<'a> field::Visit for SpanAttributeVisitor<'a> {
             SPAN_STATUS_CODE_FIELD => {
                 self.0.status_code = str_to_status_code(&format!("{:?}", value))
             }
-            SPAN_STATUS_MESSAGE_FIELD => self.0.status_message = Some(format!("{:?}", value)),
+            SPAN_STATUS_MESSAGE_FIELD => {
+                self.0.status_message = Some(format!("{:?}", value).into())
+            }
             _ => {
                 let attribute = Key::new(field.name()).string(format!("{:?}", value));
                 if let Some(attributes) = &mut self.0.attributes {
@@ -410,25 +412,12 @@ where
             .tracer
             .span_builder(attrs.metadata().name())
             .with_start_time(SystemTime::now())
+            .with_parent_context(self.parent_context(attrs, &ctx))
             // Eagerly assign span id so children have stable parent id
             .with_span_id(self.tracer.new_span_id());
 
-        // Set optional parent span context from attrs
-        builder.parent_context = Some(self.parent_context(attrs, &ctx));
-
-        // Ensure trace id exists so spans are associated with the proper trace.
-        //
-        // Parent contexts are in 4 possible states, first two require a new
-        // trace ids, second two have existing trace ids:
-        //   * Empty - explicit new tracing root span, needs new id
-        //   * A parent context containing no active or remote span, needs new id
-        //   * A parent context containing an active span, defer to that span's trace
-        //   * A parent context containing a remote span context, defer to remote trace
-        let needs_trace_id = builder.parent_context.as_ref().map_or(true, |cx| {
-            !cx.has_active_span() && cx.remote_span_context().is_none()
-        });
-
-        if needs_trace_id {
+        // Record new trace id if there is no active parent span
+        if !builder.parent_context.has_active_span() {
             builder.trace_id = Some(self.tracer.new_trace_id());
         }
 
@@ -532,6 +521,7 @@ where
                     Key::new("level").string(meta.level().to_string()),
                     Key::new("target").string(meta.target().to_string()),
                 ],
+                0,
             );
             event.record(&mut SpanEventVisitor(&mut otel_event));
 
@@ -541,10 +531,10 @@ where
                     builder.status_code = Some(otel::StatusCode::Error);
                 }
 
-                if let Some(ref mut events) = builder.message_events {
+                if let Some(ref mut events) = builder.events {
                     events.push(otel_event);
                 } else {
-                    builder.message_events = Some(vec![otel_event]);
+                    builder.events = Some(vec![otel_event]);
                 }
             }
         };
@@ -611,6 +601,7 @@ impl Timings {
 mod tests {
     use super::*;
     use opentelemetry::trace::SpanKind;
+    use std::borrow::Cow;
     use std::sync::{Arc, Mutex};
     use std::time::SystemTime;
     use tracing_subscriber::prelude::*;
@@ -622,11 +613,17 @@ mod tests {
         fn invalid(&self) -> Self::Span {
             otel::NoopSpan::new()
         }
-        fn start_with_context(&self, _name: &str, _context: OtelContext) -> Self::Span {
+        fn start_with_context<T>(&self, _name: T, _context: OtelContext) -> Self::Span
+        where
+            T: Into<Cow<'static, str>>,
+        {
             self.invalid()
         }
-        fn span_builder(&self, name: &str) -> otel::SpanBuilder {
-            otel::SpanBuilder::from_name(name.to_string())
+        fn span_builder<T>(&self, name: T) -> otel::SpanBuilder
+        where
+            T: Into<Cow<'static, str>>,
+        {
+            otel::SpanBuilder::from_name(name)
         }
         fn build(&self, builder: otel::SpanBuilder) -> Self::Span {
             *self.0.lock().unwrap() = Some(builder);
@@ -649,17 +646,17 @@ mod tests {
     #[derive(Debug, Clone)]
     struct TestSpan(otel::SpanContext);
     impl otel::Span for TestSpan {
-        fn add_event_with_timestamp(&self, _: String, _: SystemTime, _: Vec<KeyValue>) {}
+        fn add_event_with_timestamp(&mut self, _: String, _: SystemTime, _: Vec<KeyValue>) {}
         fn span_context(&self) -> &otel::SpanContext {
             &self.0
         }
         fn is_recording(&self) -> bool {
             false
         }
-        fn set_attribute(&self, _attribute: KeyValue) {}
-        fn set_status(&self, _code: otel::StatusCode, _message: String) {}
-        fn update_name(&self, _new_name: String) {}
-        fn end_with_timestamp(&self, _timestamp: SystemTime) {}
+        fn set_attribute(&mut self, _attribute: KeyValue) {}
+        fn set_status(&mut self, _code: otel::StatusCode, _message: String) {}
+        fn update_name(&mut self, _new_name: String) {}
+        fn end_with_timestamp(&mut self, _timestamp: SystemTime) {}
     }
 
     #[test]
@@ -725,7 +722,7 @@ mod tests {
             .status_message
             .clone();
 
-        assert_eq!(recorded_status_message, Some(message.to_string()))
+        assert_eq!(recorded_status_message, Some(message.into()))
     }
 
     #[test]
@@ -754,8 +751,6 @@ mod tests {
             .as_ref()
             .unwrap()
             .parent_context
-            .as_ref()
-            .unwrap()
             .span()
             .span_context()
             .trace_id();

tracing-opentelemetry/src/tracer.rs

@@ -5,9 +5,8 @@ use opentelemetry::{
         SpanBuilder, SpanContext, SpanId, SpanKind, TraceContextExt, TraceId, TraceState,
         TRACE_FLAG_SAMPLED,
     },
-    Context as OtelContext, KeyValue,
+    Context as OtelContext,
 };
-use std::time::SystemTime;
 
 /// An interface for authors of OpenTelemetry SDKs to build pre-sampled tracers.
 ///
@@ -51,10 +50,7 @@ pub trait PreSampledTracer {
 
 impl PreSampledTracer for otel::NoopTracer {
     fn sampled_context(&self, builder: &mut otel::SpanBuilder) -> OtelContext {
-        builder
-            .parent_context
-            .clone()
-            .unwrap_or_else(OtelContext::new)
+        builder.parent_context.clone()
     }
 
     fn new_trace_id(&self) -> otel::TraceId {
@@ -73,9 +69,7 @@ impl PreSampledTracer for Tracer {
             return OtelContext::new();
         }
         let provider = self.provider().unwrap();
-
-        // Ensure parent context exists and contains data necessary for sampling
-        let parent_cx = build_parent_context(&builder);
+        let parent_cx = &builder.parent_context;
 
         // Gather trace state
         let (no_parent, trace_id, remote_parent, parent_trace_flags) =
@@ -85,7 +79,7 @@ impl PreSampledTracer for Tracer {
         let (flags, trace_state) = if let Some(result) = &builder.sampling_result {
             process_sampling_result(result, parent_trace_flags)
         } else if no_parent || remote_parent {
-            builder.sampling_result = Some(provider.config().default_sampler.should_sample(
+            builder.sampling_result = Some(provider.config().sampler.should_sample(
                 Some(&parent_cx),
                 trace_id,
                 &builder.name,
@@ -109,7 +103,7 @@ impl PreSampledTracer for Tracer {
 
         let span_id = builder.span_id.unwrap_or_else(SpanId::invalid);
         let span_context = SpanContext::new(trace_id, span_id, flags, false, trace_state);
-        parent_cx.with_span(CompatSpan(span_context))
+        parent_cx.with_remote_span_context(span_context)
     }
 
     fn new_trace_id(&self) -> otel::TraceId {
@@ -125,31 +119,14 @@ impl PreSampledTracer for Tracer {
     }
 }
 
-fn build_parent_context(builder: &SpanBuilder) -> OtelContext {
-    builder
-        .parent_context
-        .as_ref()
-        .map(|cx| {
-            // Sampling expects to be able to access the parent span via `span` so wrap remote span
-            // context in a wrapper span if necessary. Remote span contexts will be passed to
-            // subsequent context's, so wrapping is only necessary if there is no active span.
-            match cx.remote_span_context() {
-                Some(remote_sc) if !cx.has_active_span() => {
-                    cx.with_span(CompatSpan(remote_sc.clone()))
-                }
-                _ => cx.clone(),
-            }
-        })
-        .unwrap_or_default()
-}
-
 fn current_trace_state(
     builder: &SpanBuilder,
     parent_cx: &OtelContext,
     provider: &TracerProvider,
 ) -> (bool, TraceId, bool, u8) {
     if parent_cx.has_active_span() {
-        let sc = parent_cx.span().span_context();
+        let span = parent_cx.span();
+        let sc = span.span_context();
         (false, sc.trace_id(), sc.is_remote(), sc.trace_flags())
     } else {
         (
@@ -185,58 +162,6 @@ fn process_sampling_result(
     }
 }
 
-#[derive(Debug)]
-struct CompatSpan(otel::SpanContext);
-impl otel::Span for CompatSpan {
-    fn add_event_with_timestamp(
-        &self,
-        _name: String,
-        _timestamp: std::time::SystemTime,
-        _attributes: Vec<KeyValue>,
-    ) {
-        #[cfg(debug_assertions)]
-        panic!(
-            "OpenTelemetry and tracing APIs cannot be mixed, use `tracing::event!` macro instead."
-        );
-    }
-
-    /// This method is used by OpenTelemetry propagators to inject span context
-    /// information into [`Injector`]s.
-    ///
-    /// [`Injector`]: opentelemetry::propagation::Injector
-    fn span_context(&self) -> &otel::SpanContext {
-        &self.0
-    }
-
-    fn is_recording(&self) -> bool {
-        #[cfg(debug_assertions)]
-        panic!("cannot record via OpenTelemetry API when using extracted span in tracing");
-
-        #[cfg(not(debug_assertions))]
-        false
-    }
-
-    fn set_attribute(&self, _attribute: KeyValue) {
-        #[cfg(debug_assertions)]
-        panic!("OpenTelemetry and tracing APIs cannot be mixed, use `tracing::span!` macro or `span.record()` instead.");
-    }
-
-    fn set_status(&self, _code: otel::StatusCode, _message: String) {
-        #[cfg(debug_assertions)]
-        panic!("OpenTelemetry and tracing APIs cannot be mixed, use `tracing::span!` macro or `span.record()` with `otel.status_code` and `otel.status_message` instead.");
-    }
-
-    fn update_name(&self, _new_name: String) {
-        #[cfg(debug_assertions)]
-        panic!("OpenTelemetry and tracing APIs cannot be mixed, use `span.record()` with `otel.name` instead.");
-    }
-
-    fn end_with_timestamp(&self, _timestamp: SystemTime) {
-        #[cfg(debug_assertions)]
-        panic!("OpenTelemetry and tracing APIs cannot be mixed, span end times are set when the underlying tracing span closes.");
-    }
-}
-
 #[cfg(test)]
 mod tests {
     use super::*;
@@ -251,7 +176,8 @@ mod tests {
         builder.span_id = Some(SpanId::from_u64(1));
         builder.trace_id = None;
         let cx = tracer.sampled_context(&mut builder);
-        let span_context = cx.span().span_context();
+        let span = cx.span();
+        let span_context = span.span_context();
 
         assert!(span_context.is_valid());
     }
@@ -287,7 +213,7 @@ mod tests {
                 .build();
             let tracer = provider.get_tracer("test", None);
             let mut builder = SpanBuilder::from_name("parent".to_string());
-            builder.parent_context = Some(parent_cx);
+            builder.parent_context = parent_cx;
             builder.sampling_result = previous_sampling_result;
             let sampled = tracer.sampled_context(&mut builder);
 

tracing-opentelemetry/tests/trace_state_propagation.rs

@@ -17,14 +17,15 @@ use tracing_subscriber::prelude::*;
 
 #[test]
 fn trace_with_active_otel_context() {
-    let (cx, subscriber, exporter, _provider) = build_sampled_context();
+    let (cx, subscriber, exporter, provider) = build_sampled_context();
     let attached = cx.attach();
 
     tracing::collect::with_default(subscriber, || {
         tracing::debug_span!("child");
     });
 
     drop(attached); // end implicit parent
+    drop(provider); // flush all spans
 
     let spans = exporter.0.lock().unwrap();
     assert_eq!(spans.len(), 2);
@@ -33,28 +34,30 @@ fn trace_with_active_otel_context() {
 
 #[test]
 fn trace_with_assigned_otel_context() {
-    let (cx, subscriber, exporter, _provider) = build_sampled_context();
+    let (cx, subscriber, exporter, provider) = build_sampled_context();
 
     tracing::collect::with_default(subscriber, || {
         let child = tracing::debug_span!("child");
         child.set_parent(cx);
     });
 
+    drop(provider); // flush all spans
     let spans = exporter.0.lock().unwrap();
     assert_eq!(spans.len(), 2);
     assert_shared_attrs_eq(&spans[0].span_context, &spans[1].span_context);
 }
 
 #[test]
 fn trace_root_with_children() {
-    let (_tracer, _provider, exporter, subscriber) = test_tracer();
+    let (_tracer, provider, exporter, subscriber) = test_tracer();
 
     tracing::collect::with_default(subscriber, || {
         // Propagate trace information through tracing parent -> child
         let root = tracing::debug_span!("root");
         root.in_scope(|| tracing::debug_span!("child"));
     });
 
+    drop(provider); // flush all spans
     let spans = exporter.0.lock().unwrap();
     assert_eq!(spans.len(), 2);
     assert_shared_attrs_eq(&spans[0].span_context, &spans[1].span_context);