Span 与 Entered

#[derive(Clone)]
pub struct Span {
    /// A handle used to enter the span when it is not executing.
    ///
    /// If this is `None`, then the span has either closed or was never enabled.
    inner: Option<Inner>,
    /// Metadata describing the span.
    ///
    /// This might be `Some` even if `inner` is `None`, in the case that the
    /// span is disabled but the metadata is needed for `log` support.
    meta: Option<&'static Metadata<'static>>,
}

#[derive(Debug)]
pub(crate) struct Inner {
    /// The span's ID, as provided by `subscriber`.
    id: Id,

    /// The subscriber that will receive events relating to this span.
    ///
    /// This should be the same subscriber that provided this span with its
    /// `id`.
    subscriber: Dispatch,
}

    #[inline]
    #[cfg(feature = "log")]
    pub fn __disabled_span(meta: &'static Metadata<'static>) -> crate::Span {
        crate::Span::new_disabled(meta)
    }

    // ...
    #[inline]
    #[cfg(not(feature = "log"))]
    pub fn __disabled_span(_: &'static Metadata<'static>) -> crate::Span {
        crate::Span::none()
    }

    #[inline(always)]
    pub fn enter(&self) -> Entered<'_> {
        self.do_enter();
        Entered { span: self }
    }

impl Drop for Entered<'_> {
    #[inline(always)]
    fn drop(&mut self) {
        self.span.do_exit()
    }
}

tokio::spawn(async {
  let span = info_span!("a");
  let _g = span.enter();
  tokio::task::yield_now().await;
})

let span = info_span!("work");
let _g = span.enter();

pub struct EnteredSpan {
    span: Span,

    /// ```compile_fail
    /// use tracing::span::*;
    /// trait AssertSend: Send {}
    ///
    /// impl AssertSend for EnteredSpan {}
    /// ```
    _not_send: PhantomNotSend,
}

/// Technically, `EnteredSpan` _can_ implement both `Send` *and*
/// `Sync` safely. It doesn't, because it has a `PhantomNotSend` field,
/// specifically added in order to make it `!Send`.
///
/// Sending an `EnteredSpan` guard between threads cannot cause memory unsafety.
/// However, it *would* result in incorrect behavior, so we add a
/// `PhantomNotSend` to prevent it from being sent between threads. This is
/// because it must be *dropped* on the same thread that it was created;
/// otherwise, the span will never be exited on the thread where it was entered,
/// and it will attempt to exit the span on a thread that may never have entered
/// it. However, we still want them to be `Sync` so that a struct holding an
/// `Entered` guard can be `Sync`.

tokio::spawn(async {
  let _g = info_span!("b").entered();
  tokio::task::yield_now().await;
})

error: future cannot be sent between threads safely
   --> src/bin/not_send.rs:15:3
    |
 15 | /   tokio::spawn(async {
 16 | |     let _g = info_span!("b").entered();
 17 | |     tokio::task::yield_now().await;
 18 | |   })
    | |____^ future created by async block is not `Send`
    |
    = help: within `{async block@src/bin/not_send.rs:15:16: 15:21}`, the trait `Send` is not implemented for `*mut ()`
note: future is not `Send` as this value is used across an await
   --> src/bin/not_send.rs:17:30
    |
 16 |     let _g = info_span!("b").entered();
    |         -- has type `EnteredSpan` which is not `Send`
 17 |     tokio::task::yield_now().await;
    |                              ^^^^^ await occurs here, with `_g` maybe used later

    pub fn in_scope<F: FnOnce() -> T, T>(&self, f: F) -> T {
        let _enter = self.enter();
        f()
    }

impl Clone for Inner {
    fn clone(&self) -> Self {
        Inner {
            id: self.subscriber.clone_span(&self.id),
            subscriber: self.subscriber.clone(),
        }
    }
}

impl Drop for Span {
    #[inline(always)]
    fn drop(&mut self) {
        if let Some(Inner {
            ref id,
            ref subscriber,
        }) = self.inner
        {
            subscriber.try_close(id.clone());
        }
        // ...
    }
}

    pub fn record<Q: field::AsField + ?Sized, V: field::Value>(
        &self,
        field: &Q,
        value: V,
    ) -> &Self {
        if let Some(meta) = self.meta {
            if let Some(field) = field.as_field(meta) {
                self.record_all(
                    &meta
                        .fields()
                        .value_set(&[(&field, Some(&value as &dyn field::Value))]),
                );
            }
        }

        self
    }

let span = info_span!("req", id = 1, status = field::Empty);
// ...
span.record("status", 200);

    pub fn follows_from(&self, from: impl Into<Option<Id>>) -> &Self {
        if let Some(ref inner) = self.inner {
            if let Some(from) = from.into() {
                inner.follows_from(&from);
            }
        }
        self
    }

    pub fn current() -> Span {
        dispatcher::get_default(|dispatch| {
            if let Some((id, meta)) = dispatch.current_span().into_inner() {
                let id = dispatch.clone_span(&id);
                Self {
                    inner: Some(Inner::new(id, dispatch)),
                    meta: Some(meta),
                }
            } else {
                Self::none()
            }
        })
    }

tracing = "=0.1.44"
tracing-core = "=0.1.36"

// src/printer.rs
use std::{
  cell::RefCell,
  collections::HashMap,
  sync::{
    Mutex,
    atomic::{AtomicU64, Ordering},
  },
};

use tracing::{
  Event, Level, Metadata, Subscriber, field,
  span::{Attributes, Id, Record},
};
use tracing_core::span::Current;

// 每个回调打印一行；自己分配 Id、数引用、维护线程局部的 span 栈
pub struct Printer {
  next_id: AtomicU64,
  spans: Mutex<HashMap<u64, (&'static Metadata<'static>, usize)>>, // id -> (元数据, 引用计数)
}

thread_local! {
  static STACK: RefCell<Vec<Id>> = const { RefCell::new(Vec::new()) };
}

impl Printer {
  pub fn new() -> Self {
    Printer { next_id: AtomicU64::new(1), spans: Mutex::new(HashMap::new()) }
  }

  fn name(&self, id: &Id) -> &'static str {
    self.spans.lock().unwrap()[&id.into_u64()].0.name()
  }
}

// 把字段拼成 "k=v k=v"
fn fields(rec: impl FnOnce(&mut dyn field::Visit)) -> String {
  let mut out = String::new();
  let mut visit = |f: &field::Field, v: &dyn std::fmt::Debug| {
    out.push_str(&format!(" {}={:?}", f.name(), v));
  };
  rec(&mut visit);
  out
}

impl Subscriber for Printer {
  fn enabled(&self, meta: &Metadata<'_>) -> bool {
    *meta.level() <= Level::INFO
  }
  fn new_span(&self, attrs: &Attributes<'_>) -> Id {
    let id = self.next_id.fetch_add(1, Ordering::Relaxed);
    let name = attrs.metadata().name();
    self.spans.lock().unwrap().insert(id, (attrs.metadata(), 1));
    println!("  new_span({name}) -> {id}{}", fields(|v| attrs.record(v)));
    Id::from_u64(id)
  }
  fn record(&self, id: &Id, values: &Record<'_>) {
    println!("  record({}){}", self.name(id), fields(|v| values.record(v)));
  }
  fn record_follows_from(&self, id: &Id, follows: &Id) {
    println!("  record_follows_from({}, {})", self.name(id), self.name(follows));
  }
  fn event(&self, event: &Event<'_>) {
    // 事件发生时栈顶是哪个 span
    let top = STACK.with(|s| s.borrow().last().map(|id| self.name(id)));
    println!("  event{} (in {})", fields(|v| event.record(v)), top.unwrap_or("-"));
  }
  fn enter(&self, id: &Id) {
    STACK.with(|s| s.borrow_mut().push(id.clone()));
    println!("  enter({})", self.name(id));
  }
  fn exit(&self, id: &Id) {
    STACK.with(|s| s.borrow_mut().pop());
    println!("  exit({})", self.name(id));
  }
  fn clone_span(&self, id: &Id) -> Id {
    let mut spans = self.spans.lock().unwrap();
    let entry = spans.get_mut(&id.into_u64()).unwrap();
    entry.1 += 1;
    println!("  clone_span({}) refs={}", entry.0.name(), entry.1);
    id.clone()
  }
  fn try_close(&self, id: Id) -> bool {
    let mut spans = self.spans.lock().unwrap();
    let entry = spans.get_mut(&id.into_u64()).unwrap();
    entry.1 -= 1;
    let closed = entry.1 == 0;
    println!("  try_close({}) refs={} -> {closed}", entry.0.name(), entry.1);
    closed
  }
  fn current_span(&self) -> Current {
    println!("  current_span()");
    match STACK.with(|s| s.borrow().last().cloned()) {
      Some(id) => {
        let meta = self.spans.lock().unwrap()[&id.into_u64()].0;
        Current::new(id, meta)
      }
      None => Current::none(),
    }
  }
}

// src/bin/span_ops.rs
#[path = "../printer.rs"]
mod printer;

use tracing::{Span, field, info, info_span};

fn main() {
  let sub = printer::Printer::new();
  tracing::subscriber::with_default(sub, || {
    println!("[1] info_span!(\"a\", x = 1, later = field::Empty)");
    let a = info_span!("a", x = 1, later = field::Empty);

    println!("[2] debug_span!(\"off\")");
    let off = tracing::debug_span!("off");
    println!(
      "    off: is_disabled={} is_none={} | Span::none(): is_disabled={} is_none={}",
      off.is_disabled(),
      off.is_none(),
      Span::none().is_disabled(),
      Span::none().is_none(),
    );

    println!("[3] a.record(\"later\", 5); a.record(\"nope\", 6)");
    a.record("later", 5);
    a.record("nope", 6);

    println!("[4] let b = a.clone()");
    let b = a.clone();

    println!("[5] let g = a.enter(); info!(..); Span::current()");
    let g = a.enter();
    info!("inside a");
    let cur = Span::current();
    println!("[6] drop(cur); drop(g)");
    drop(cur);
    drop(g);

    println!("[7] a.in_scope(|| info!(..))");
    a.in_scope(|| info!("in scope"));

    println!("[8] let e = info_span!(\"e\").entered(); b.follows_from(&e)");
    let e = info_span!("e").entered();
    b.follows_from(&e);
    println!("[9] let e = e.exit()");
    let e = e.exit();

    println!("[10] off.enter(); off.record(..); off.clone()");
    let _g = off.enter();
    off.record("x", 1);
    let _off2 = off.clone();

    println!("[11] drop(e); drop(b); drop(a)");
    drop(e);
    drop(b);
    drop(a);
    println!("[end]");
  });
}

[1] info_span!("a", x = 1, later = field::Empty)
  new_span(a) -> 1 x=1
[2] debug_span!("off")
    off: is_disabled=true is_none=true | Span::none(): is_disabled=true is_none=true
[3] a.record("later", 5); a.record("nope", 6)
  record(a) later=5
[4] let b = a.clone()
  clone_span(a) refs=2
[5] let g = a.enter(); info!(..); Span::current()
  enter(a)
  event message=inside a (in a)
  current_span()
  clone_span(a) refs=3
[6] drop(cur); drop(g)
  try_close(a) refs=2 -> false
  exit(a)
[7] a.in_scope(|| info!(..))
  enter(a)
  event message=in scope (in a)
  exit(a)
[8] let e = info_span!("e").entered(); b.follows_from(&e)
  new_span(e) -> 2
  enter(e)
  record_follows_from(a, e)
[9] let e = e.exit()
  exit(e)
[10] off.enter(); off.record(..); off.clone()

[11] drop(e); drop(b); drop(a)
  try_close(e) refs=0 -> true
  try_close(a) refs=1 -> false
  try_close(a) refs=0 -> true
[end]