Merge branch 'v0.1.x' into v0.1.x

README.md

@@ -169,7 +169,7 @@ pub fn shave_all(yaks: usize) -> usize {
 
         if let Err(ref error) = res {
             // Like spans, events can also use the field initialization shorthand.
-            // In this instance, `yak` is the field being initalized.
+            // In this instance, `yak` is the field being initialized.
             error!(yak, error = error.as_ref(), "failed to shave yak!");
         } else {
             yaks_shaved += 1;
@@ -192,7 +192,7 @@ set the default later.
 
 ### In Asynchronous Code
 
-To trace `async fn`s, the preferred method is using the [`#[instrument]`] attribute:
+To trace `async fn`s, the preferred method is using the [`#[instrument]`][instrument] attribute:
 
 ```rust
 use tracing::{info, instrument};
@@ -244,14 +244,14 @@ my_future
 `Future::instrument` attaches a span to the future, ensuring that the span's lifetime
 is as long as the future's.
 
-Under the hood, the `#[instrument]` macro performs same the explicit span
+Under the hood, the [`#[instrument]`][instrument] macro performs same the explicit span
 attachment that `Future::instrument` does.
 
 [std-future]: https://doc.rust-lang.org/stable/std/future/trait.Future.html
 [`tracing-futures`]: https://docs.rs/tracing-futures
 [closing]: https://docs.rs/tracing/latest/tracing/span/index.html#closing-spans
 [`Future::instrument`]: https://docs.rs/tracing/latest/tracing/trait.Instrument.html#method.instrument
-[`#[instrument]`]: https://docs.rs/tracing/0.1.11/tracing/attr.instrument.html
+[instrument]: https://docs.rs/tracing/0.1.11/tracing/attr.instrument.html
 
 ## Supported Rust Versions
 

examples/Cargo.toml

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

examples/examples/opentelemetry.rs

@@ -15,9 +15,12 @@ fn expensive_work() -> &'static str {
 }
 
 fn main() -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
-    let (tracer, _uninstall) = opentelemetry_jaeger::new_pipeline()
+    // Install an otel pipeline with a simple span processor that exports data one at a time when
+    // spans end. See the `install_batch` option on each exporter's pipeline builder to see how to
+    // export in batches.
+    let tracer = opentelemetry_jaeger::new_pipeline()
         .with_service_name("report_example")
-        .install()?;
+        .install_simple()?;
     let opentelemetry = tracing_opentelemetry::layer().with_tracer(tracer);
     tracing_subscriber::registry()
         .with(opentelemetry)

tracing-core/src/field.rs

@@ -662,7 +662,7 @@ impl FieldSet {
     {
         ValueSet {
             fields: self,
-            values: &values.borrow()[..],
+            values: values.borrow(),
         }
     }
 

tracing-core/src/metadata.rs

@@ -366,10 +366,10 @@ impl From<Option<Level>> for LevelFilter {
     }
 }
 
-impl Into<Option<Level>> for LevelFilter {
+impl From<LevelFilter> for Option<Level> {
     #[inline]
-    fn into(self) -> Option<Level> {
-        self.into_level()
+    fn from(filter: LevelFilter) -> Self {
+        filter.into_level()
     }
 }
 

tracing-core/src/span.rs

@@ -97,9 +97,9 @@ impl Id {
     }
 }
 
-impl<'a> Into<Option<Id>> for &'a Id {
-    fn into(self) -> Option<Id> {
-        Some(self.clone())
+impl<'a> From<&'a Id> for Option<Id> {
+    fn from(id: &'a Id) -> Self {
+        Some(id.clone())
     }
 }
 
@@ -293,26 +293,29 @@ impl Current {
     }
 }
 
-impl<'a> Into<Option<&'a Id>> for &'a Current {
-    fn into(self) -> Option<&'a Id> {
-        self.id()
+impl<'a> From<&'a Current> for Option<&'a Id> {
+    fn from(cur: &'a Current) -> Self {
+        cur.id()
     }
 }
 
-impl<'a> Into<Option<Id>> for &'a Current {
-    fn into(self) -> Option<Id> {
-        self.id().cloned()
+impl<'a> From<&'a Current> for Option<Id> {
+    fn from(cur: &'a Current) -> Self {
+        cur.id().cloned()
     }
 }
 
-impl Into<Option<Id>> for Current {
-    fn into(self) -> Option<Id> {
-        self.id().cloned()
+impl From<Current> for Option<Id> {
+    fn from(cur: Current) -> Self {
+        match cur.inner {
+            CurrentInner::Current { id, .. } => Some(id),
+            _ => None,
+        }
     }
 }
 
-impl<'a> Into<Option<&'static Metadata<'static>>> for &'a Current {
-    fn into(self) -> Option<&'static Metadata<'static>> {
-        self.metadata()
+impl<'a> From<&'a Current> for Option<&'static Metadata<'static>> {
+    fn from(cur: &'a Current) -> Self {
+        cur.metadata()
     }
 }

tracing-opentelemetry/Cargo.toml

@@ -22,12 +22,12 @@ edition = "2018"
 default = ["tracing-log"]
 
 [dependencies]
-opentelemetry = { version = "0.12", default-features = false, features = ["trace"] }
+opentelemetry = { version = "0.13", default-features = false, features = ["trace"] }
 tracing = { path = "../tracing", version = "0.1", default-features = false, features = ["std"] }
 tracing-core = { path = "../tracing-core", version = "0.1" }
 tracing-subscriber = { path = "../tracing-subscriber", version = "0.2", default-features = false, features = ["registry"] }
 tracing-log = { path = "../tracing-log", version = "0.1", default-features = false, optional = true }
 
 [dev-dependencies]
 async-trait = "0.1"
-opentelemetry-jaeger = "0.11"
+opentelemetry-jaeger = "0.12"

tracing-opentelemetry/src/layer.rs

@@ -108,7 +108,7 @@ impl<'a> field::Visit for SpanEventVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_bool(&mut self, field: &field::Field, value: bool) {
         match field.name() {
-            "message" => self.0.name = value.to_string(),
+            "message" => self.0.name = value.to_string().into(),
             // Skip fields that are actually log metadata that have already been handled
             #[cfg(feature = "tracing-log")]
             name if name.starts_with("log.") => (),
@@ -123,7 +123,7 @@ impl<'a> field::Visit for SpanEventVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_i64(&mut self, field: &field::Field, value: i64) {
         match field.name() {
-            "message" => self.0.name = value.to_string(),
+            "message" => self.0.name = value.to_string().into(),
             // Skip fields that are actually log metadata that have already been handled
             #[cfg(feature = "tracing-log")]
             name if name.starts_with("log.") => (),
@@ -138,7 +138,7 @@ impl<'a> field::Visit for SpanEventVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_str(&mut self, field: &field::Field, value: &str) {
         match field.name() {
-            "message" => self.0.name = value.to_string(),
+            "message" => self.0.name = value.to_string().into(),
             // Skip fields that are actually log metadata that have already been handled
             #[cfg(feature = "tracing-log")]
             name if name.starts_with("log.") => (),
@@ -156,7 +156,7 @@ impl<'a> field::Visit for SpanEventVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_debug(&mut self, field: &field::Field, value: &dyn fmt::Debug) {
         match field.name() {
-            "message" => self.0.name = format!("{:?}", value),
+            "message" => self.0.name = format!("{:?}", value).into(),
             // Skip fields that are actually log metadata that have already been handled
             #[cfg(feature = "tracing-log")]
             name if name.starts_with("log.") => (),
@@ -201,7 +201,7 @@ impl<'a> field::Visit for SpanAttributeVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_str(&mut self, field: &field::Field, value: &str) {
         if field.name() == SPAN_NAME_FIELD {
-            self.0.name = value.to_string();
+            self.0.name = value.to_string().into();
         } else if field.name() == SPAN_KIND_FIELD {
             self.0.span_kind = str_to_span_kind(value);
         } else {
@@ -220,7 +220,7 @@ impl<'a> field::Visit for SpanAttributeVisitor<'a> {
     /// [`Span`]: opentelemetry::trace::Span
     fn record_debug(&mut self, field: &field::Field, value: &dyn fmt::Debug) {
         if field.name() == SPAN_NAME_FIELD {
-            self.0.name = format!("{:?}", value);
+            self.0.name = format!("{:?}", value).into();
         } else if field.name() == SPAN_KIND_FIELD {
             self.0.span_kind = str_to_span_kind(&format!("{:?}", value));
         } else {
@@ -253,9 +253,10 @@ where
     /// use tracing_subscriber::Registry;
     ///
     /// // Create a jaeger exporter pipeline for a `trace_demo` service.
-    /// let (tracer, _uninstall) = opentelemetry_jaeger::new_pipeline()
+    /// let tracer = opentelemetry_jaeger::new_pipeline()
     ///     .with_service_name("trace_demo")
-    ///     .install().expect("Error initializing Jaeger exporter");
+    ///     .install_simple()
+    ///     .expect("Error initializing Jaeger exporter");
     ///
     /// // Create a layer with the configured tracer
     /// let otel_layer = OpenTelemetryLayer::new(tracer);
@@ -287,9 +288,10 @@ where
     /// use tracing_subscriber::Registry;
     ///
     /// // Create a jaeger exporter pipeline for a `trace_demo` service.
-    /// let (tracer, _uninstall) = opentelemetry_jaeger::new_pipeline()
+    /// let tracer = opentelemetry_jaeger::new_pipeline()
     ///     .with_service_name("trace_demo")
-    ///     .install().expect("Error initializing Jaeger exporter");
+    ///     .install_simple()
+    ///     .expect("Error initializing Jaeger exporter");
     ///
     /// // Create a layer with the configured tracer
     /// let otel_layer = tracing_opentelemetry::layer().with_tracer(tracer);
@@ -423,23 +425,31 @@ where
     }
 
     fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) {
+        if !self.tracked_inactivity {
+            return;
+        }
+
         let span = ctx.span(id).expect("Span not found, this is a bug");
         let mut extensions = span.extensions_mut();
 
         if let Some(timings) = extensions.get_mut::<Timings>() {
             let now = Instant::now();
-            timings.idle += (now - timings.last).as_nanos() as u64;
+            timings.idle += (now - timings.last).as_nanos() as i64;
             timings.last = now;
         }
     }
 
     fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) {
+        if !self.tracked_inactivity {
+            return;
+        }
+
         let span = ctx.span(id).expect("Span not found, this is a bug");
         let mut extensions = span.extensions_mut();
 
         if let Some(timings) = extensions.get_mut::<Timings>() {
             let now = Instant::now();
-            timings.busy += (now - timings.last).as_nanos() as u64;
+            timings.busy += (now - timings.last).as_nanos() as i64;
             timings.last = now;
         }
     }
@@ -535,16 +545,18 @@ where
         let span = ctx.span(&id).expect("Span not found, this is a bug");
         let mut extensions = span.extensions_mut();
         if let Some(mut builder) = extensions.remove::<otel::SpanBuilder>() {
-            // Append busy/idle timings when enabled.
-            if let Some(timings) = extensions.get_mut::<Timings>() {
-                let mut timings_attributes = vec![
-                    KeyValue::new("busy_ns", timings.busy.to_string()),
-                    KeyValue::new("idle_ns", timings.idle.to_string()),
-                ];
-
-                match builder.attributes {
-                    Some(ref mut attributes) => attributes.append(&mut timings_attributes),
-                    None => builder.attributes = Some(timings_attributes),
+            if self.tracked_inactivity {
+                // Append busy/idle timings when enabled.
+                if let Some(timings) = extensions.get_mut::<Timings>() {
+                    let busy_ns = KeyValue::new("busy_ns", timings.busy);
+                    let idle_ns = KeyValue::new("idle_ns", timings.idle);
+
+                    if let Some(ref mut attributes) = builder.attributes {
+                        attributes.push(busy_ns);
+                        attributes.push(idle_ns);
+                    } else {
+                        builder.attributes = Some(vec![busy_ns, idle_ns]);
+                    }
                 }
             }
 
@@ -567,8 +579,8 @@ where
 }
 
 struct Timings {
-    idle: u64,
-    busy: u64,
+    idle: i64,
+    busy: i64,
     last: Instant,
 }
 
@@ -648,7 +660,7 @@ mod tests {
         });
 
         let recorded_name = tracer.0.lock().unwrap().as_ref().map(|b| b.name.clone());
-        assert_eq!(recorded_name, Some(dynamic_name))
+        assert_eq!(recorded_name, Some(dynamic_name.into()))
     }
 
     #[test]

tracing-opentelemetry/src/lib.rs

@@ -54,7 +54,7 @@
 //! use tracing_subscriber::Registry;
 //!
 //! // Create a new OpenTelemetry pipeline
-//! let (tracer, _uninstall) = stdout::new_pipeline().install();
+//! let tracer = stdout::new_pipeline().install_simple();
 //!
 //! // Create a tracing layer with the configured tracer
 //! let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);

tracing-opentelemetry/src/tracer.rs

@@ -284,7 +284,7 @@ mod tests {
     fn sampled_context() {
         for (name, sampler, parent_cx, previous_sampling_result, is_sampled) in sampler_data() {
             let provider = TracerProvider::builder()
-                .with_config(config().with_default_sampler(sampler))
+                .with_config(config().with_sampler(sampler))
                 .build();
             let tracer = provider.get_tracer("test", None);
             let mut builder = SpanBuilder::from_name("parent".to_string());

tracing-serde/src/fields.rs

@@ -21,7 +21,7 @@ impl<'a> Serialize for SerializeFieldMap<'a, Event<'_>> {
     where
         S: Serializer,
     {
-        let len = self.0.metadata().fields().len();
+        let len = self.0.fields().count();
         let serializer = serializer.serialize_map(Some(len))?;
         let mut visitor = SerdeMapVisitor::new(serializer);
         self.0.record(&mut visitor);

tracing-subscriber/src/fmt/format/json.rs

@@ -501,7 +501,7 @@ impl<'a> fmt::Debug for WriteAdaptor<'a> {
 
 #[cfg(test)]
 mod test {
-    use crate::fmt::{test::MockWriter, time::FormatTime};
+    use crate::fmt::{format::FmtSpan, test::MockWriter, time::FormatTime};
     use lazy_static::lazy_static;
     use tracing::{self, subscriber::with_default};
 
@@ -672,6 +672,39 @@ mod test {
         });
     }
 
+    #[test]
+    fn json_span_event() {
+        // Check span events serialize correctly.
+        // Discussion: https://github.com/tokio-rs/tracing/issues/829#issuecomment-661984255
+        //
+        lazy_static! {
+            static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
+        }
+        let expected = r#"{"timestamp":"fake time","level":"INFO","fields":{"message":"enter"},"target":"tracing_subscriber::fmt::format::json::test"}"#;
+
+        let make_writer = || MockWriter::new(&BUF);
+        let subscriber = crate::fmt::Subscriber::builder()
+            .json()
+            .flatten_event(false)
+            .with_current_span(false)
+            .with_span_list(false)
+            .with_span_events(FmtSpan::ENTER)
+            .with_writer(make_writer)
+            .with_timer(MockTime)
+            .finish();
+
+        with_default(subscriber, || {
+            tracing::info_span!("valid_json").in_scope(|| {});
+        });
+
+        let actual = String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap();
+        assert_eq!(
+            serde_json::from_str::<std::collections::HashMap<&str, serde_json::Value>>(expected)
+                .unwrap(),
+            serde_json::from_str(actual.as_str()).unwrap()
+        );
+    }
+
     #[cfg(feature = "json")]
     fn test_json<T, U>(
         make_writer: T,