sync: follows-from relationship for resource_spans

tokio/Cargo.toml

@@ -107,6 +107,9 @@ socket2 = { version = "0.5.3", optional = true, features = [ "all" ] }
 [target.'cfg(tokio_unstable)'.dependencies]
 tracing = { version = "0.1.25", default-features = false, features = ["std"], optional = true } # Not in full
 
+[target.'cfg(tokio_unstable)'.dev-dependencies]
+tracing-core = { version = "0.1.25", default-features = false }
+
 # Currently unstable. The API exposed by these features may be broken at any time.
 # Requires `--cfg tokio_unstable` to enable.
 [target.'cfg(tokio_taskdump)'.dependencies]

tokio/src/sync/barrier.rs

@@ -73,6 +73,7 @@ impl Barrier {
         #[cfg(all(tokio_unstable, feature = "tracing"))]
         let resource_span = {
             let location = std::panic::Location::caller();
+            let current_span = tracing::Span::current();
             let resource_span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
@@ -82,6 +83,7 @@ impl Barrier {
                 loc.line = location.line(),
                 loc.col = location.column(),
             );
+            resource_span.follows_from(current_span);
 
             resource_span.in_scope(|| {
                 tracing::trace!(

tokio/src/sync/batch_semaphore.rs

@@ -146,13 +146,15 @@ impl Semaphore {
 
         #[cfg(all(tokio_unstable, feature = "tracing"))]
         let resource_span = {
+            let current_span = tracing::Span::current();
             let resource_span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
                 concrete_type = "Semaphore",
                 kind = "Sync",
                 is_internal = true
             );
+            resource_span.follows_from(current_span);
 
             resource_span.in_scope(|| {
                 tracing::trace!(

tokio/src/sync/mutex.rs

@@ -339,15 +339,18 @@ impl<T: ?Sized> Mutex<T> {
         let resource_span = {
             let location = std::panic::Location::caller();
 
-            tracing::trace_span!(
+            let current_span = tracing::Span::current();
+            let span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
                 concrete_type = "Mutex",
                 kind = "Sync",
                 loc.file = location.file(),
                 loc.line = location.line(),
                 loc.col = location.column(),
-            )
+            );
+            span.follows_from(current_span);
+            span
         };
 
         #[cfg(all(tokio_unstable, feature = "tracing"))]

tokio/src/sync/rwlock.rs

@@ -208,6 +208,7 @@ impl<T: ?Sized> RwLock<T> {
         #[cfg(all(tokio_unstable, feature = "tracing"))]
         let resource_span = {
             let location = std::panic::Location::caller();
+            let current_span = tracing::Span::current();
             let resource_span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
@@ -217,6 +218,7 @@ impl<T: ?Sized> RwLock<T> {
                 loc.line = location.line(),
                 loc.col = location.column(),
             );
+            resource_span.follows_from(current_span);
 
             resource_span.in_scope(|| {
                 tracing::trace!(
@@ -282,6 +284,7 @@ impl<T: ?Sized> RwLock<T> {
         let resource_span = {
             let location = std::panic::Location::caller();
 
+            let current_span = tracing::Span::current();
             let resource_span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
@@ -291,6 +294,7 @@ impl<T: ?Sized> RwLock<T> {
                 loc.line = location.line(),
                 loc.col = location.column(),
             );
+            resource_span.follows_from(current_span);
 
             resource_span.in_scope(|| {
                 tracing::trace!(

tokio/src/sync/semaphore.rs

@@ -399,7 +399,8 @@ impl Semaphore {
         let resource_span = {
             let location = std::panic::Location::caller();
 
-            tracing::trace_span!(
+            let current_span = tracing::Span::current();
+            let span = tracing::trace_span!(
                 parent: None,
                 "runtime.resource",
                 concrete_type = "Semaphore",
@@ -408,7 +409,9 @@ impl Semaphore {
                 loc.line = location.line(),
                 loc.col = location.column(),
                 inherits_child_attrs = true,
-            )
+            );
+            span.follows_from(current_span);
+            span
         };
 
         #[cfg(all(tokio_unstable, feature = "tracing"))]

tokio/src/time/interval.rs

@@ -121,15 +121,18 @@ fn internal_interval_at(
     let resource_span = {
         let location = location.expect("should have location if tracing");
 
-        tracing::trace_span!(
+        let current_span = tracing::Span::current();
+        let span = tracing::trace_span!(
             parent: None,
             "runtime.resource",
             concrete_type = "Interval",
             kind = "timer",
             loc.file = location.file(),
             loc.line = location.line(),
             loc.col = location.column(),
-        )
+        );
+        span.follows_from(current_span);
+        span
     };
 
     #[cfg(all(tokio_unstable, feature = "tracing"))]

tokio/tests/sync_mutex.rs

@@ -6,20 +6,24 @@ use wasm_bindgen_test::wasm_bindgen_test as test;
 #[cfg(all(target_family = "wasm", not(target_os = "wasi")))]
 use wasm_bindgen_test::wasm_bindgen_test as maybe_tokio_test;
 
-#[cfg(feature = "tracing")]
+#[cfg(all(tokio_unstable, feature = "tracing"))]
 use tracing::{
     span::{Attributes, Record},
     subscriber::Subscriber,
     Event, Id, Metadata,
 };
 
+#[cfg(all(tokio_unstable, feature = "tracing"))]
+use tracing_core::span::Current;
+
 #[cfg(not(all(target_family = "wasm", not(target_os = "wasi"))))]
 use tokio::test as maybe_tokio_test;
 
 use tokio::sync::Mutex;
 use tokio_test::task::spawn;
 use tokio_test::{assert_pending, assert_ready};
 
+#[cfg(all(tokio_unstable, feature = "tracing"))]
 use std::collections::HashMap;
 use std::sync::Arc;
 
@@ -186,23 +190,15 @@ async fn mutex_debug() {
 }
 
 #[tokio::test]
-#[cfg(feature = "tracing")]
-async fn mutex_new_is_root_span() {
+#[cfg(all(tokio_unstable, feature = "tracing"))]
+async fn mutex_new_resource_span_follows_from_current_span() {
     #[derive(Default, Debug)]
     struct MockSubscriber {
-        pub spans: std::sync::Mutex<HashMap<u64, (String, bool)>>,
+        pub spans: std::sync::Mutex<HashMap<u64, (&'static Metadata<'static>, bool)>>,
+        pub follows_from: std::sync::Mutex<HashMap<Id, Id>>,
         current_id: std::sync::Mutex<u64>,
     }
 
-    impl MockSubscriber {
-        fn new() -> Self {
-            Self {
-                spans: Default::default(),
-                current_id: std::sync::Mutex::new(1),
-            }
-        }
-    }
-
     impl Subscriber for MockSubscriber {
         fn enabled(&self, _metadata: &Metadata<'_>) -> bool {
             true
@@ -211,10 +207,9 @@ async fn mutex_new_is_root_span() {
         fn new_span(&self, span: &Attributes<'_>) -> Id {
             let mut spans = self.spans.lock().unwrap();
             let mut current_id = self.current_id.lock().unwrap();
-            spans.insert(*current_id, (span.metadata().name().into(), span.is_root()));
-            let id = Id::from_u64(*current_id);
             *current_id += 1;
-            id
+            spans.insert(*current_id, (span.metadata(), span.is_root()));
+            Id::from_u64(*current_id)
         }
 
         fn enter(&self, _span: &Id) {}
@@ -223,25 +218,40 @@ async fn mutex_new_is_root_span() {
 
         fn event(&self, _event: &Event<'_>) {}
 
-        fn record_follows_from(&self, _span: &Id, _follows: &Id) {}
+        fn record_follows_from(&self, span: &Id, follows: &Id) {
+            let mut follows_from = self.follows_from.lock().unwrap();
+            follows_from.insert(span.clone(), follows.clone());
+        }
 
         fn record(&self, _span: &Id, _values: &Record<'_>) {}
+
+        fn current_span(&self) -> Current {
+            let spans = self.spans.lock().unwrap();
+            let current_id = self.current_id.lock().unwrap();
+            let metadata = spans[&current_id].0;
+            Current::new(Id::from_u64(*current_id), &metadata)
+        }
     }
 
-    let mock_subscriber = Arc::new(MockSubscriber::new());
+    let mock_subscriber = Arc::new(MockSubscriber::default());
 
     tracing::subscriber::with_default(mock_subscriber.clone(), || {
         let parent = tracing::info_span!("parent");
-        let guard = parent.enter();
+        let _guard = parent.enter();
         let _m = Mutex::new(0);
-        drop(guard);
-        drop(parent);
     });
 
     let spans = mock_subscriber.spans.lock().unwrap();
+    let follows = mock_subscriber.follows_from.lock().unwrap();
+
+    // Parent span created first, not a root
+    assert_eq!("parent", spans[&1].0.name());
+    assert_eq!(false, spans[&1].1);
+
+    // Mutex span created second, has no parent
+    assert_eq!("runtime.resource", spans[&2].0.name());
+    assert_eq!(true, spans[&2].1);
 
-    // Parent span, has a parent.
-    assert_eq!(spans[&1], ("parent".into(), false));
-    // Mutex resource span, has no parent.
-    assert_eq!(spans[&2], ("runtime.resource".into(), true));
+    // ID 2 (mutex runtime.resource) follow from ID 1 (parent)
+    assert_eq!(Id::from_u64(1), follows[&Id::from_u64(2)]);
 }