From 169ee3be0f50eb55e3b6ef0af304dff7ed492fa7 Mon Sep 17 00:00:00 2001 From: andylokandy Date: Mon, 4 May 2026 22:13:40 +0800 Subject: [PATCH 1/4] refactor!: clean up async span instrumentation APIs --- AGENTS.md | 8 +- CHANGELOG.md | 10 + examples/asynchronous.rs | 12 +- examples/basic.rs | 2 +- examples/harness.rs | 7 +- examples/logging.rs | 2 +- examples/synchronous.rs | 5 +- fastrace-futures/src/lib.rs | 206 ++++++++---------- fastrace-macro/src/lib.rs | 90 ++++---- fastrace/benches/compare.rs | 2 +- fastrace/benches/trace.rs | 9 +- fastrace/src/future.rs | 96 +++----- fastrace/src/lib.rs | 29 ++- fastrace/src/local/local_collector.rs | 10 +- fastrace/src/local/local_span.rs | 16 +- fastrace/src/span.rs | 103 ++------- fastrace/tests/lib.rs | 93 ++++---- .../ui/err/has-enter-on-poll-and-sync.stderr | 7 - ...-and-sync.rs => has-poll-span-and-sync.rs} | 2 +- .../ui/err/has-poll-span-and-sync.stderr | 7 + .../err/has-properties-and-enter-on-poll.rs | 6 - .../has-properties-and-enter-on-poll.stderr | 7 - ...{has-enter-on-poll.rs => has-poll-span.rs} | 2 +- tests/statically-disable/src/main.rs | 13 +- 24 files changed, 305 insertions(+), 439 deletions(-) delete mode 100644 tests/macros/tests/ui/err/has-enter-on-poll-and-sync.stderr rename tests/macros/tests/ui/err/{has-enter-on-poll-and-sync.rs => has-poll-span-and-sync.rs} (59%) create mode 100644 tests/macros/tests/ui/err/has-poll-span-and-sync.stderr delete mode 100644 tests/macros/tests/ui/err/has-properties-and-enter-on-poll.rs delete mode 100644 tests/macros/tests/ui/err/has-properties-and-enter-on-poll.stderr rename tests/macros/tests/ui/ok/{has-enter-on-poll.rs => has-poll-span.rs} (60%) diff --git a/AGENTS.md b/AGENTS.md index fb14d462..dccebbf2 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -19,14 +19,14 @@ - Tail sampling: spans are held until root commit; `Span::cancel()` on the root triggers `CancelCollect` to discard the trace. ## Key Types & Behaviors -- `Span` (`fastrace/src/span.rs`): thread-safe span, can be cross-thread; supports `enter_with_parent(s)`, `enter_with_local_parent`, `add_event`, `add_properties`, `push_child_spans`, `elapsed`, `cancel`. +- `Span` (`fastrace/src/span.rs`): thread-safe span, can be cross-thread; supports `start`, `start_with_local_parent`, `set_local_parent`, `add_event`, `add_properties`, `push_child_spans`, `elapsed`, `cancel`. - `LocalSpan` (`local/local_span.rs`): single-thread fast path; requires an active local parent (`Span::set_local_parent` or nested `LocalSpan`). Stack discipline enforced; dropping out of order panics in tests. - `LocalCollector` (`local/local_collector.rs`): start/collect local spans when parent may be set later; returns `LocalSpans` attachable via `Span::push_child_spans` or convertible to `SpanRecord`s without a reporter. - ID types (`collector/id.rs`): `TraceId(u128)`, `SpanId(u64)`; thread-local generator (`SpanId::next_id`) and W3C traceparent encode/decode helpers. `SpanContext` carries trace, parent span id, and `sampled` flag. - `Config` (`collector/mod.rs`): `report_interval`; note `max_spans_per_trace` deprecated no-op and `tail_sampled` deprecated no-op. - `Reporter` trait (`collector/global_collector.rs`): synchronous `report(Vec)`. TestReporter collects into a shared Vec; ConsoleReporter prints. -- Async adapters: `FutureExt::{in_span, enter_on_poll}` (`src/future.rs`); Stream/Sink adapters in `fastrace-futures`. -- Proc macro `#[trace]` (`fastrace-macro/src/lib.rs`): wraps sync fns with `LocalSpan`; async fns with `Span::enter_with_local_parent` plus `in_span` by default or `enter_on_poll=true`. Options: `name`, `short_name`, `enter_on_poll`, `properties={k:"fmt"}`, `crate=path`. +- Async adapters: `FutureExt::in_span(Span::start(...)).with_poll_span(...)` (`src/future.rs`); Stream/Sink adapters in `fastrace-futures`. +- Proc macro `#[trace]` (`fastrace-macro/src/lib.rs`): wraps sync fns with `LocalSpan`; async fns with `Span::start_with_local_parent` plus the owned future wrapper, and `poll_span = true` adds per-poll spans. Options: `name`, `short_name`, `poll_span`, `properties={k:"fmt"}`, `crate=path`. - `enable` feature gates runtime collection; workspace members (examples/tests) request it, so full builds usually compile with tracing enabled. Ensure any changes keep the no-feature path compiling (many functions are #[cfg(feature="enable")] guarded). ## Reporters @@ -50,7 +50,7 @@ ## Gotchas & Tips - Always call `set_reporter` early; spans emitted before reporter init are dropped. Call `flush()` before shutdown to drain SPSC queues. -- `LocalSpan` does nothing without a local parent; `Span::enter_with_local_parent` falls back to noop if no stack token exists. +- `LocalSpan` does nothing without a local parent; `Span::start_with_local_parent` falls back to noop if no stack token exists. - Default local stack capacity: 4096 span lines and span queue size 10240; overflows drop spans silently (return None). - Tail sampling is the default; `Span::cancel()` on the root discards spans collected up to the root's drop (spans submitted after the root finishes may still be reported). - Keep both code paths healthy: when `enable` is off, public APIs stay callable but must remain no-ops without panicking. diff --git a/CHANGELOG.md b/CHANGELOG.md index 357195b5..bd79fb27 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,16 @@ All significant changes to this project will be documented in this file. - Upgrade MSRV to 1.85 and Edition to 2024. +### Breaking Changes + +- Rename async poll instrumentation APIs: remove `enter_on_poll` and use + `in_span(Span::start(...)).with_poll_span(name)` for future and stream polling. +- Rename span constructors from `Span::enter_with_parent` and + `Span::enter_with_local_parent` to `Span::start` and `Span::start_with_local_parent`. +- Rename `LocalSpan::enter_with_local_parent` to `LocalSpan::start`. +- Rename the macro option `enter_on_poll` to `poll_span`; it now creates the async function + lifecycle span and adds a poll span on each poll. + ## v0.7.17 ### Breaking Changes diff --git a/examples/asynchronous.rs b/examples/asynchronous.rs index 3e9407cb..48203567 100644 --- a/examples/asynchronous.rs +++ b/examples/asynchronous.rs @@ -25,11 +25,11 @@ use fastrace::collector::Reporter; use fastrace::prelude::*; use opentelemetry_otlp::WithExportConfig; -fn parallel_job() -> Vec> { +fn parallel_job(parent: &Span) -> Vec> { let mut v = Vec::with_capacity(4); for i in 0..4 { v.push(tokio::spawn( - iter_job(i).in_span(Span::enter_with_local_parent("iter job")), + iter_job(i).in_span(Span::start("iter job", parent)), )); } v @@ -41,7 +41,7 @@ async fn iter_job(iter: u64) { other_job().await; } -#[trace(enter_on_poll = true)] +#[trace(poll_span = true)] async fn other_job() { for i in 0..20 { if i == 10 { @@ -61,9 +61,9 @@ async fn main() { let f = async { let jhs = { - let _span = LocalSpan::enter_with_local_parent("a span") + let span = Span::start_with_local_parent("a span") .with_property(|| ("a property", "a value")); - parallel_job() + parallel_job(&span) }; other_job().await; @@ -72,7 +72,7 @@ async fn main() { jh.await.unwrap(); } } - .in_span(span); + .in_span(Span::start("main task", &span)); tokio::spawn(f).await.unwrap(); } diff --git a/examples/basic.rs b/examples/basic.rs index 3371733e..41c5c207 100644 --- a/examples/basic.rs +++ b/examples/basic.rs @@ -26,7 +26,7 @@ fn do_main() { let parent = SpanContext::random(); let root = Span::root("root", parent); let _g = root.set_local_parent(); - let _g = LocalSpan::enter_with_local_parent("child"); + let _g = LocalSpan::start("child"); // do business } diff --git a/examples/harness.rs b/examples/harness.rs index 7d4829ae..4ff2af9b 100644 --- a/examples/harness.rs +++ b/examples/harness.rs @@ -35,7 +35,9 @@ mod test_util { use fastrace::prelude::*; pub fn setup_fastrace(test: F) - where F: FnOnce() -> anyhow::Result<()> + 'static { + where + F: FnOnce() -> anyhow::Result<()> + 'static, + { fastrace::set_reporter(ConsoleReporter, Config::default()); { let root = Span::root(closure_name::(), SpanContext::random()); @@ -57,7 +59,8 @@ mod test_util { .build() .unwrap(); let root = Span::root(closure_name::(), SpanContext::random()); - rt.block_on(test().in_span(root)).unwrap(); + rt.block_on(test().in_span(Span::start("test", &root))) + .unwrap(); fastrace::flush(); } diff --git a/examples/logging.rs b/examples/logging.rs index 76495af5..4c86fc31 100644 --- a/examples/logging.rs +++ b/examples/logging.rs @@ -48,7 +48,7 @@ fn do_main() { info!("event in root span"); - let _local_span_guard = LocalSpan::enter_with_local_parent("child"); + let _local_span_guard = LocalSpan::start("child"); info!("event in child span"); diff --git a/examples/synchronous.rs b/examples/synchronous.rs index d2bc0d73..e084fb50 100644 --- a/examples/synchronous.rs +++ b/examples/synchronous.rs @@ -25,7 +25,7 @@ use fastrace::prelude::*; use opentelemetry_otlp::WithExportConfig; fn func1(i: u64) { - let _guard = LocalSpan::enter_with_local_parent("func1"); + let _guard = LocalSpan::start("func1"); std::thread::sleep(Duration::from_millis(i)); func2(i); } @@ -44,8 +44,7 @@ async fn main() { let root = Span::root("root", parent); let _g = root.set_local_parent(); - let _span = LocalSpan::enter_with_local_parent("a span") - .with_property(|| ("a property", "a value")); + let _span = LocalSpan::start("a span").with_property(|| ("a property", "a value")); for i in 1..=10 { func1(i); diff --git a/fastrace-futures/src/lib.rs b/fastrace-futures/src/lib.rs index f96b44e8..a0a06683 100644 --- a/fastrace-futures/src/lib.rs +++ b/fastrace-futures/src/lib.rs @@ -37,7 +37,7 @@ pub trait StreamExt: Stream + Sized { /// yield i; /// } /// } - /// .in_span(Span::enter_with_parent("task", &root)); + /// .in_span(Span::start("task", &root)); /// /// tokio::pin!(s); /// @@ -51,68 +51,7 @@ pub trait StreamExt: Stream + Sized { InSpan { inner: self, span: Some(span), - } - } - - /// Starts a [`LocalSpan`] at every [`Stream::poll_next()`]. - /// - /// This is useful for tracing each **poll** of a stream (not each yielded item), - /// e.g. to observe how often an async stream is woken. If you need a single span - /// that covers the whole stream lifecycle, use [`StreamExt::in_span`] instead. - /// - /// The span name can be any `impl Into>`. - /// - /// # Important: Local parent required - /// - /// `enter_on_poll` creates [`LocalSpan`]s, which require an existing local parent - /// context at the time of each poll. Without one, the spans will be no-ops. - /// - /// The typical way to provide a local parent is to wrap the stream with - /// [`StreamExt::in_span`] **after** `enter_on_poll`: - /// - /// ```text - /// stream.enter_on_poll("poll").in_span(span) - /// ``` - /// - /// ⚠️ Do **not** reverse the order: - /// - /// ```text - /// // WRONG: in_span sets the local parent *after* enter_on_poll tries to create - /// // the LocalSpan, so the poll spans will be no-ops. - /// stream.in_span(span).enter_on_poll("poll") - /// ``` - /// - /// # Examples: - /// - /// ``` - /// # #[tokio::main] - /// # async fn main() { - /// use async_stream::stream; - /// use fastrace::prelude::*; - /// use fastrace_futures::StreamExt as _; - /// use futures::StreamExt; - /// - /// let root = Span::root("root", SpanContext::random()); - /// - /// let s = stream! { - /// for i in 0..2 { - /// yield i; - /// } - /// } - /// .enter_on_poll("poll") - /// .in_span(Span::enter_with_parent("stream", &root)); - /// - /// tokio::pin!(s); - /// - /// assert_eq!(s.next().await.unwrap(), 0); - /// assert_eq!(s.next().await.unwrap(), 1); - /// assert_eq!(s.next().await, None); - /// # } - /// ``` - fn enter_on_poll(self, name: impl Into>) -> EnterOnPollStream { - EnterOnPollStream { - inner: self, - name: name.into(), + poll_span: None, } } } @@ -121,7 +60,8 @@ impl StreamExt for T where T: Stream {} /// An extension trait for [`Sink`] that provides tracing instrument adapters. pub trait SinkExt: Sink + Sized { - /// Binds a [`Span`] to the [`Sink`] that continues to record until the sink is **closed**. + /// Binds a [`Span`] to the [`Sink`] that continues to record until the sink is + /// **closed**. /// /// In addition, it sets the span as the local parent at every poll so that /// [`fastrace::local::LocalSpan`] becomes available within the future. Internally, it @@ -139,7 +79,7 @@ pub trait SinkExt: Sink + Sized { /// /// let root = Span::root("root", SpanContext::random()); /// - /// let mut drain = sink::drain().in_span(Span::enter_with_parent("task", &root)); + /// let mut drain = sink::drain().in_span(Span::start("task", &root)); /// /// drain.send(1).await.unwrap(); /// drain.send(2).await.unwrap(); @@ -151,6 +91,7 @@ pub trait SinkExt: Sink + Sized { InSpan { inner: self, span: Some(span), + poll_span: None, } } } @@ -164,18 +105,66 @@ pub struct InSpan { #[pin] inner: T, span: Option, + poll_span: Option>, +} + +impl InSpan { + /// Starts a [`LocalSpan`] at every [`Stream::poll_next()`]. + /// + /// If the stream gets polled multiple times, it will create multiple short spans. + /// The poll span is always created under the stream span. + /// + /// # Examples: + /// + /// ``` + /// # #[tokio::main] + /// # async fn main() { + /// use async_stream::stream; + /// use fastrace::prelude::*; + /// use fastrace_futures::StreamExt as _; + /// use futures::StreamExt; + /// + /// let root = Span::root("root", SpanContext::random()); + /// + /// let s = stream! { + /// for i in 0..2 { + /// yield i; + /// } + /// } + /// .in_span(Span::start("stream", &root)) + /// .with_poll_span("poll"); + /// + /// tokio::pin!(s); + /// + /// assert_eq!(s.next().await.unwrap(), 0); + /// assert_eq!(s.next().await.unwrap(), 1); + /// assert_eq!(s.next().await, None); + /// # } + /// ``` + #[inline] + pub fn with_poll_span(mut self, name: impl Into>) -> Self { + self.poll_span = Some(name.into()); + self + } } impl Stream for InSpan -where T: Stream +where + T: Stream, { type Item = T::Item; fn poll_next(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll> { let this = self.project(); - let _guard = this.span.as_ref().map(|s| s.set_local_parent()); + let guard = this.span.as_ref().map(|s| s.set_local_parent()); + let poll_span = this + .poll_span + .as_ref() + .map(|name| LocalSpan::start(name.clone())); let res = this.inner.poll_next(cx); + drop(poll_span); + drop(guard); match res { Poll::Pending => Poll::Pending, @@ -190,7 +179,8 @@ where T: Stream } impl Sink for InSpan -where T: Sink +where + T: Sink, { type Error = T::Error; @@ -215,8 +205,9 @@ where T: Sink fn poll_close(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll> { let this = self.project(); - let _guard = this.span.as_ref().map(|s| s.set_local_parent()); + let guard = this.span.as_ref().map(|s| s.set_local_parent()); let res = this.inner.poll_close(cx); + drop(guard); match res { r @ Poll::Pending => r, @@ -229,48 +220,37 @@ where T: Sink } } -/// Adapter for [`StreamExt::enter_on_poll()`](StreamExt::enter_on_poll). -#[pin_project::pin_project] -pub struct EnterOnPollStream { - #[pin] - inner: T, - name: Cow<'static, str>, -} - -impl Stream for EnterOnPollStream -where T: Stream -{ - type Item = T::Item; - - fn poll_next(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll> { - let this = self.project(); - let _guard = LocalSpan::enter_with_local_parent(this.name.clone()); - this.inner.poll_next(cx) - } -} - #[cfg(test)] mod tests { - use fastrace::local::LocalCollector; + use fastrace::collector::Config; + use fastrace::collector::TestReporter; use fastrace::prelude::*; use futures::StreamExt as _; use futures::stream; use crate::StreamExt as _; - #[tokio::test] - async fn test_enter_on_poll_creates_spans() { - let collector = LocalCollector::start(); + static REPORTER_LOCK: tokio::sync::Mutex<()> = tokio::sync::Mutex::const_new(()); - let s = stream::iter(vec![1, 2]).enter_on_poll("poll"); - tokio::pin!(s); - assert_eq!(s.next().await, Some(1)); - assert_eq!(s.next().await, Some(2)); - assert_eq!(s.next().await, None); + #[tokio::test] + async fn test_with_poll_span_creates_spans() { + let _lock = REPORTER_LOCK.lock().await; + let (reporter, collected_spans) = TestReporter::new(); + fastrace::set_reporter(reporter, Config::default()); + + { + let root = Span::root("root", SpanContext::random()); + let s = stream::iter(vec![1, 2]) + .in_span(Span::start("stream", &root)) + .with_poll_span("poll"); + tokio::pin!(s); + assert_eq!(s.next().await, Some(1)); + assert_eq!(s.next().await, Some(2)); + assert_eq!(s.next().await, None); + } - let local_spans = collector.collect(); - let parent_ctx = SpanContext::random(); - let spans = local_spans.to_span_records(parent_ctx); + fastrace::flush(); + let spans = collected_spans.lock(); let poll_count = spans.iter().filter(|s| s.name == "poll").count(); assert!( @@ -281,7 +261,7 @@ mod tests { } #[tokio::test] - async fn test_enter_on_poll_pending_then_ready() { + async fn test_with_poll_span_pending_then_ready() { use std::pin::Pin; use std::task::Context; use std::task::Poll; @@ -305,15 +285,21 @@ mod tests { } } - let collector = LocalCollector::start(); - - let s = PendOnce { polled: false }.enter_on_poll("poll"); - tokio::pin!(s); - assert_eq!(s.next().await, Some(42)); + let _lock = REPORTER_LOCK.lock().await; + let (reporter, collected_spans) = TestReporter::new(); + fastrace::set_reporter(reporter, Config::default()); + + { + let root = Span::root("root", SpanContext::random()); + let s = PendOnce { polled: false } + .in_span(Span::start("stream", &root)) + .with_poll_span("poll"); + tokio::pin!(s); + assert_eq!(s.next().await, Some(42)); + } - let local_spans = collector.collect(); - let parent_ctx = SpanContext::random(); - let spans = local_spans.to_span_records(parent_ctx); + fastrace::flush(); + let spans = collected_spans.lock(); let poll_count = spans.iter().filter(|s| s.name == "poll").count(); assert!( diff --git a/fastrace-macro/src/lib.rs b/fastrace-macro/src/lib.rs index ae32307e..614ecb80 100644 --- a/fastrace-macro/src/lib.rs +++ b/fastrace-macro/src/lib.rs @@ -37,8 +37,8 @@ use crate::visit_mut::VisitMut; /// * `name` - The name of the span. Defaults to the full path of the function. /// * `short_name` - Whether to use the function name without path as the span name. Defaults to /// `false`. -/// * `enter_on_poll` - Whether to enter the span on poll. If set to `false`, `in_span` will be -/// used. Only available for `async fn`. Defaults to `false`. +/// * `poll_span` - Whether to additionally create a span on each poll. Only available for +/// `async fn`. Defaults to `false`. /// * `properties` - A list of key-value pairs to be added as properties to the span. The value can /// be a format string, where the function arguments are accessible. Defaults to `{}`. /// * `crate` - The path to the fastrace crate. Defaults to `::fastrace`. @@ -58,7 +58,7 @@ use crate::visit_mut::VisitMut; /// // ... /// } /// -/// #[trace(name = "qux", enter_on_poll = true)] +/// #[trace(name = "qux", poll_span = true)] /// async fn baz() { /// // ... /// } @@ -75,29 +75,29 @@ use crate::visit_mut::VisitMut; /// # use fastrace::prelude::*; /// # use fastrace::local::LocalSpan; /// fn simple() { -/// let __guard__ = LocalSpan::enter_with_local_parent("example::simple"); +/// let __guard__ = LocalSpan::start("example::simple"); /// // ... /// } /// /// async fn simple_async() { -/// let __span__ = Span::enter_with_local_parent("simple_async"); -/// async { +/// let __span__ = Span::start_with_local_parent("simple_async"); +/// fastrace::future::FutureExt::in_span(async { /// // ... -/// } -/// .in_span(__span__) +/// }, __span__) /// .await /// } /// /// async fn baz() { -/// async { +/// let __span__ = Span::start_with_local_parent("qux"); +/// fastrace::future::FutureExt::in_span(async { /// // ... -/// } -/// .enter_on_poll("qux") +/// }, __span__) +/// .with_poll_span("qux") /// .await /// } /// /// async fn properties(a: u64) { -/// let __span__ = Span::enter_with_local_parent("example::properties").with_properties(|| { +/// let __span__ = Span::start_with_local_parent("example::properties").with_properties(|| { /// [ /// (std::borrow::Cow::from("k1"), std::borrow::Cow::from("v1")), /// ( @@ -106,10 +106,9 @@ use crate::visit_mut::VisitMut; /// ), /// ] /// }); -/// async { +/// fastrace::future::FutureExt::in_span(async { /// // ... -/// } -/// .in_span(__span__) +/// }, __span__) /// .await /// } /// ``` @@ -202,7 +201,7 @@ pub fn trace( struct Args { name: Option, short_name: bool, - enter_on_poll: bool, + poll_span: bool, properties: Vec<(LitStr, LitStr)>, crate_path: Path, } @@ -212,7 +211,7 @@ impl Default for Args { Self { name: None, short_name: false, - enter_on_poll: false, + poll_span: false, properties: Vec::new(), crate_path: parse_quote!(::fastrace), } @@ -237,7 +236,7 @@ impl Parse for Args { fn parse(input: ParseStream) -> Result { let mut name = None; let mut short_name = false; - let mut enter_on_poll = false; + let mut poll_span = false; let mut properties = Vec::new(); let mut crate_path = parse_quote!(::fastrace); let mut seen = HashSet::new(); @@ -261,9 +260,9 @@ impl Parse for Args { let parsed_short_name: LitBool = input.parse()?; short_name = parsed_short_name.value; } - "enter_on_poll" => { - let parsed_enter_on_poll: LitBool = input.parse()?; - enter_on_poll = parsed_enter_on_poll.value; + "poll_span" => { + let parsed_poll_span: LitBool = input.parse()?; + poll_span = parsed_poll_span.value; } "properties" => { let content; @@ -290,7 +289,7 @@ impl Parse for Args { Ok(Args { name, short_name, - enter_on_poll, + poll_span, properties, crate_path, }) @@ -321,10 +320,6 @@ fn gen_properties(args: &Args) -> proc_macro2::TokenStream { return quote::quote!(); } - if args.enter_on_poll { - abort_call_site!("`enter_on_poll` can not be used with `properties`") - } - let properties = args.properties.iter().map(|(k, v)| { quote!( (std::borrow::Cow::from(#k), match format_args!(#v) { @@ -362,28 +357,25 @@ fn gen_block( // If the function is an `async fn`, this will wrap it in an async block. // Otherwise, this will enter the span and then perform the rest of the body. if async_context { - let block = if args.enter_on_poll { - quote!( - #crate_path::future::FutureExt::enter_on_poll( - async move { #block }, - #name - ) - ) + let poll_span = if args.poll_span { + quote!(.with_poll_span( #name )) } else { - quote!( - { - let __span__ = #crate_path::Span::enter_with_local_parent( #name ) #properties; - #crate_path::future::FutureExt::in_span( - async move { - let __ret__: #output_ty_hint = #block; - #[allow(unreachable_code)] - __ret__ - }, - __span__, - ) - } - ) + quote!() }; + let block = quote!( + { + let __span__ = #crate_path::Span::start_with_local_parent( #name ) #properties; + #crate_path::future::FutureExt::in_span( + async move { + let __ret__: #output_ty_hint = #block; + #[allow(unreachable_code)] + __ret__ + }, + __span__, + ) + #poll_span + } + ); if async_keyword { quote!( @@ -393,12 +385,12 @@ fn gen_block( block } } else { - if args.enter_on_poll { - abort_call_site!("`enter_on_poll` can not be applied on non-async function"); + if args.poll_span { + abort_call_site!("`poll_span` can not be applied on non-async function"); } quote!( - let __guard__ = #crate_path::local::LocalSpan::enter_with_local_parent( #name ) #properties; + let __guard__ = #crate_path::local::LocalSpan::start( #name ) #properties; #block ) } diff --git a/fastrace/benches/compare.rs b/fastrace/benches/compare.rs index 4f25dfb7..74c0ca29 100644 --- a/fastrace/benches/compare.rs +++ b/fastrace/benches/compare.rs @@ -131,7 +131,7 @@ fn fastrace_harness(n: usize) { fn dummy_fastrace(n: usize) { for _ in 0..n { - let _guard = LocalSpan::enter_with_local_parent("child"); + let _guard = LocalSpan::start("child"); } } diff --git a/fastrace/benches/trace.rs b/fastrace/benches/trace.rs index e1f1b843..29b689ab 100644 --- a/fastrace/benches/trace.rs +++ b/fastrace/benches/trace.rs @@ -72,15 +72,18 @@ fn deep(bencher: Bencher, len: usize) { fn future(bencher: Bencher, len: u32) { init_fastrace(); - async fn f(i: u32) { + async fn f(i: u32, parent: &Span) { for _ in 0..i - 1 { - async {}.enter_on_poll(black_box("")).await + async {} + .in_span(Span::start("", parent)) + .with_poll_span("") + .await } } bencher.bench(|| { let root = Span::root("root", SpanContext::new(TraceId(12), SpanId::default())); - pollster::block_on(f(len).in_span(root)); + pollster::block_on(f(len, &root)); }); } diff --git a/fastrace/src/future.rs b/fastrace/src/future.rs index a3e63f30..426a527c 100644 --- a/fastrace/src/future.rs +++ b/fastrace/src/future.rs @@ -2,9 +2,8 @@ //! This module provides tools to trace a `Future`. //! -//! The [`FutureExt`] trait extends `Future` with two methods: [`in_span()`] and -//! [`enter_on_poll()`]. It is crucial that the outermost future uses `in_span()`, -//! otherwise, the traces inside the `Future` will be lost. +//! The [`FutureExt`] trait extends `Future` with [`in_span()`]. It is crucial that the +//! outermost future uses `in_span()`, otherwise, the traces inside the `Future` will be lost. //! //! # Example //! @@ -13,22 +12,18 @@ //! //! let root = Span::root("root", SpanContext::random()); //! -//! // Instrument the a task +//! // Instrument a task. //! let task = async { -//! async { -//! // ... -//! } -//! .enter_on_poll("future is polled") -//! .await; +//! // ... //! } -//! .in_span(Span::enter_with_parent("task", &root)); +//! .in_span(Span::start("task", &root)) +//! .with_poll_span("future is polled"); //! //! # let runtime = tokio::runtime::Runtime::new().unwrap(); //! runtime.spawn(task); //! ``` //! //! [`in_span()`]:(FutureExt::in_span) -//! [`enter_on_poll()`]:(FutureExt::enter_on_poll) use std::borrow::Cow; use std::task::Poll; @@ -44,7 +39,7 @@ pub trait FutureExt: std::future::Future + Sized { /// /// In addition, it sets the span as the local parent at every poll so that `LocalSpan` /// becomes available within the future. Internally, it calls [`Span::set_local_parent`] when - /// the executor [`poll`](std::future::Future::poll) it. + /// the executor [`polls`](std::future::Future::poll) it. /// /// # Examples /// @@ -57,7 +52,7 @@ pub trait FutureExt: std::future::Future + Sized { /// let task = async { /// // ... /// } - /// .in_span(Span::enter_with_parent("Task", &root)); + /// .in_span(Span::start("Task", &root)); /// /// tokio::spawn(task); /// # } @@ -69,39 +64,7 @@ pub trait FutureExt: std::future::Future + Sized { InSpan { inner: self, span: Some(span), - } - } - - /// Starts a [`LocalSpan`] at every [`Future::poll()`]. If the future gets polled multiple - /// times, it will create multiple _short_ spans. - /// - /// # Examples - /// - /// ``` - /// # #[tokio::main] - /// # async fn main() { - /// use fastrace::prelude::*; - /// - /// let root = Span::root("Root", SpanContext::random()); - /// let task = async { - /// async { - /// // ... - /// } - /// .enter_on_poll("Sub Task") - /// .await - /// } - /// .in_span(Span::enter_with_parent("Task", &root)); - /// - /// tokio::spawn(task); - /// # } - /// ``` - /// - /// [`Future::poll()`]:(std::future::Future::poll) - #[inline] - fn enter_on_poll(self, name: impl Into>) -> EnterOnPoll { - EnterOnPoll { - inner: self, - name: name.into(), + poll_span: None, } } } @@ -112,6 +75,21 @@ pub struct InSpan { #[pin] inner: T, span: Option, + poll_span: Option>, +} + +impl InSpan { + /// Starts a [`LocalSpan`] at every [`Future::poll()`]. + /// + /// If the future gets polled multiple times, it will create multiple short spans. + /// The poll span is always created under the future span. + /// + /// [`Future::poll()`]:(std::future::Future::poll) + #[inline] + pub fn with_poll_span(mut self, name: impl Into>) -> Self { + self.poll_span = Some(name.into()); + self + } } impl std::future::Future for InSpan { @@ -120,8 +98,14 @@ impl std::future::Future for InSpan { fn poll(self: std::pin::Pin<&mut Self>, cx: &mut std::task::Context<'_>) -> Poll { let this = self.project(); - let _guard = this.span.as_ref().map(|s| s.set_local_parent()); + let guard = this.span.as_ref().map(|s| s.set_local_parent()); + let poll_span = this + .poll_span + .as_ref() + .map(|name| LocalSpan::start(name.clone())); let res = this.inner.poll(cx); + drop(poll_span); + drop(guard); match res { r @ Poll::Pending => r, @@ -132,21 +116,3 @@ impl std::future::Future for InSpan { } } } - -/// Adapter for [`FutureExt::enter_on_poll()`](FutureExt::enter_on_poll). -#[pin_project::pin_project] -pub struct EnterOnPoll { - #[pin] - inner: T, - name: Cow<'static, str>, -} - -impl std::future::Future for EnterOnPoll { - type Output = T::Output; - - fn poll(self: std::pin::Pin<&mut Self>, cx: &mut std::task::Context<'_>) -> Poll { - let this = self.project(); - let _guard = LocalSpan::enter_with_local_parent(this.name.clone()); - this.inner.poll(cx) - } -} diff --git a/fastrace/src/lib.rs b/fastrace/src/lib.rs index 7fdeaa2b..5bcf6496 100644 --- a/fastrace/src/lib.rs +++ b/fastrace/src/lib.rs @@ -109,7 +109,7 @@ //! parent span id from a remote source. If there's no remote parent span, the parent span //! id is typically set to its default value of zero. //! -//! Once we have the root `Span`, we can create a child `Span` using [`Span::enter_with_parent()`], +//! Once we have the root `Span`, we can start a child `Span` using [`Span::start()`], //! thereby establishing the reference relationship between the spans. //! //! `Span` is thread-safe and can be sent across threads. @@ -124,7 +124,7 @@ //! let root_span = Span::root("root", SpanContext::random()); //! //! { -//! let child_span = Span::enter_with_parent("a child span", &root_span); +//! let child_span = Span::start("a child span", &root_span); //! //! // ... //! @@ -139,12 +139,12 @@ //! //! Sometimes, passing a `Span` through a function to create a child `Span` can be inconvenient. //! We can employ a thread-local approach to avoid an explicit argument passing in the function. -//! In fastrace, [`Span::set_local_parent()`] and [`Span::enter_with_local_parent()`] serve this +//! In fastrace, [`Span::set_local_parent()`] and [`Span::start_with_local_parent()`] serve this //! purpose. //! //! [`Span::set_local_parent()`] method sets __a local context of the `Span`__ for the current -//! thread. [`Span::enter_with_local_parent()`] accesses the parent `Span` from the local context -//! and creates a child `Span` with it. +//! thread. [`Span::start_with_local_parent()`] accesses the parent `Span` from the local context +//! and starts a child `Span` with it. //! //! ``` //! use fastrace::prelude::*; @@ -160,7 +160,7 @@ //! //! fn foo() { //! // The parent of this span is `root`. -//! let _child_span = Span::enter_with_local_parent("a child span"); +//! let _child_span = Span::start_with_local_parent("a child span"); //! //! // ... //! @@ -187,10 +187,9 @@ //! [`Span::set_local_parent()`] immediately after the creation of `Span`. //! //! After __a local context of a `Span`__ is set using [`Span::set_local_parent()`], -//! use [`LocalSpan::enter_with_local_parent()`] to start a `LocalSpan`, which then -//! becomes the new local parent. +//! use [`LocalSpan::start()`] to start a `LocalSpan`, which then becomes the new local parent. //! -//! If no local context is set, the [`LocalSpan::enter_with_local_parent()`] will do nothing. +//! If no local context is set, [`LocalSpan::start()`] will do nothing. //! ``` //! use fastrace::collector::Config; //! use fastrace::collector::ConsoleReporter; @@ -204,7 +203,7 @@ //! //! { //! // The parent of this span is `root`. -//! let _span1 = LocalSpan::enter_with_local_parent("a child span"); +//! let _span1 = LocalSpan::start("a child span"); //! //! foo(); //! } @@ -212,7 +211,7 @@ //! //! fn foo() { //! // The parent of this span is `span1`. -//! let _span2 = LocalSpan::enter_with_local_parent("a child span of child span"); +//! let _span2 = LocalSpan::start("a child span of child span"); //! } //! //! fastrace::flush(); @@ -238,7 +237,7 @@ //! root.add_event(Event::new("event in root")); //! //! { -//! let _span1 = LocalSpan::enter_with_local_parent("a child span"); +//! let _span1 = LocalSpan::start("a child span"); //! //! LocalSpan::add_event(Event::new("event in span1")); //! } @@ -284,7 +283,7 @@ //! async { //! do_something_async(100).await; //! } -//! .in_span(Span::enter_with_local_parent("async_job")), +//! .in_span(Span::start("async_job", &root)), //! ); //! } //! @@ -352,9 +351,9 @@ //! [`Span::root()`]: crate::Span::root //! [`Span::noop()`]: crate::Span::noop //! [`Span::cancel()`]: crate::Span::cancel -//! [`Span::enter_with_parent()`]: crate::Span::enter_with_parent +//! [`Span::start()`]: crate::Span::start //! [`Span::set_local_parent()`]: crate::Span::set_local_parent -//! [`LocalSpan::enter_with_local_parent()`]: crate::local::LocalSpan::enter_with_local_parent +//! [`LocalSpan::start()`]: crate::local::LocalSpan::start //! [`Event`]: crate::Event //! [`Reporter`]: crate::collector::Reporter //! [`ConsoleReporter`]: crate::collector::ConsoleReporter diff --git a/fastrace/src/local/local_collector.rs b/fastrace/src/local/local_collector.rs index 5b3f6cf7..e69bde25 100644 --- a/fastrace/src/local/local_collector.rs +++ b/fastrace/src/local/local_collector.rs @@ -31,7 +31,7 @@ use crate::util::RawSpans; /// /// // Collect local spans manually without a parent /// let collector = LocalCollector::start(); -/// let span = LocalSpan::enter_with_local_parent("a child span"); +/// let span = LocalSpan::start("a child span"); /// drop(span); /// let local_spans = collector.collect(); /// @@ -72,7 +72,7 @@ struct LocalCollectorInner { /// /// // Collect local spans manually without a parent /// let collector = LocalCollector::start(); -/// let span = LocalSpan::enter_with_local_parent("a child span"); +/// let span = LocalSpan::start("a child span"); /// drop(span); /// /// // Collect local spans into a LocalSpans instance @@ -205,7 +205,7 @@ impl LocalSpans { /// /// // Collect local spans manually without a parent /// let collector = LocalCollector::start(); - /// let span = LocalSpan::enter_with_local_parent("a child span"); + /// let span = LocalSpan::start("a child span"); /// drop(span); /// /// // Collect local spans into a LocalSpans instance @@ -319,8 +319,8 @@ span1 [] #[test] fn local_spans_to_span_record() { let collector = LocalCollector::start(); - let span1 = LocalSpan::enter_with_local_parent("span1").with_property(|| ("k1", "v1")); - let span2 = LocalSpan::enter_with_local_parent("span2").with_property(|| ("k2", "v2")); + let span1 = LocalSpan::start("span1").with_property(|| ("k1", "v1")); + let span2 = LocalSpan::start("span2").with_property(|| ("k2", "v2")); drop(span2); drop(span1); diff --git a/fastrace/src/local/local_span.rs b/fastrace/src/local/local_span.rs index 6fc6d2a6..7c246f2f 100644 --- a/fastrace/src/local/local_span.rs +++ b/fastrace/src/local/local_span.rs @@ -33,7 +33,7 @@ impl fmt::Debug for LocalSpan { } impl LocalSpan { - /// Create a new child span associated with the current local span in the current thread, and + /// Start a new child span associated with the current local span in the current thread, and /// then it will become the new local parent. /// /// If no local span is active, this function is no-op. @@ -46,10 +46,10 @@ impl LocalSpan { /// let root = Span::root("root", SpanContext::random()); /// let _g = root.set_local_parent(); /// - /// let child = LocalSpan::enter_with_local_parent("child"); + /// let child = LocalSpan::start("child"); /// ``` #[inline] - pub fn enter_with_local_parent(name: impl Into>) -> Self { + pub fn start(name: impl Into>) -> Self { #[cfg(not(feature = "enable"))] { LocalSpan::default() @@ -73,7 +73,7 @@ impl LocalSpan { /// use fastrace::prelude::*; /// /// let span = - /// LocalSpan::enter_with_local_parent("a child span").with_property(|| ("key", "value")); + /// LocalSpan::start("a child span").with_property(|| ("key", "value")); /// ``` #[inline] pub fn with_property(self, property: F) -> Self @@ -99,7 +99,7 @@ impl LocalSpan { /// let link = SpanContext::new(TraceId(1), SpanId(2)); /// let _g = root.set_local_parent(); /// - /// let _span = LocalSpan::enter_with_local_parent("child").with_link(link); + /// let _span = LocalSpan::start("child").with_link(link); /// ``` #[inline] pub fn with_link(self, link: SpanContext) -> Self { @@ -119,7 +119,7 @@ impl LocalSpan { /// ``` /// use fastrace::prelude::*; /// - /// let span = LocalSpan::enter_with_local_parent("a child span") + /// let span = LocalSpan::start("a child span") /// .with_properties(|| [("key1", "value1"), ("key2", "value2")]); /// ``` #[inline] @@ -173,7 +173,7 @@ impl LocalSpan { /// let link = SpanContext::new(TraceId(1), SpanId(2)); /// let _g = root.set_local_parent(); /// - /// let _span = LocalSpan::enter_with_local_parent("child"); + /// let _span = LocalSpan::start("child"); /// LocalSpan::add_link(link); /// ``` #[inline] @@ -313,7 +313,7 @@ span1 [] #[test] fn local_span_noop() { - let _span1 = LocalSpan::enter_with_local_parent("span1").with_property(|| ("k1", "v1")); + let _span1 = LocalSpan::start("span1").with_property(|| ("k1", "v1")); } #[test] diff --git a/fastrace/src/span.rs b/fastrace/src/span.rs index c66efc5e..d72137d8 100644 --- a/fastrace/src/span.rs +++ b/fastrace/src/span.rs @@ -103,7 +103,7 @@ impl Span { } } - /// Create a new child span associated with the specified parent span. + /// Start a new child span associated with the specified parent span. /// /// # Examples /// @@ -112,9 +112,10 @@ impl Span { /// /// let root = Span::root("root", SpanContext::random()); /// - /// let child = Span::enter_with_parent("child", &root); + /// let child = Span::start("child", &root); + /// ``` #[inline] - pub fn enter_with_parent(name: impl Into>, parent: &Span) -> Self { + pub fn start(name: impl Into>, parent: &Span) -> Self { #[cfg(not(feature = "enable"))] { Self::noop() @@ -129,71 +130,7 @@ impl Span { } } - /// Create a new child span associated with multiple parent spans. - /// - /// This API is deprecated. The first non-noop parent becomes the primary parent; any additional - /// parents are attached as links. - /// - /// Use [`Span::enter_with_parent`] plus [`Span::with_link`] instead. - /// - /// # Examples - /// - /// ``` - /// use fastrace::prelude::*; - /// - /// let parent1 = Span::root("parent1", SpanContext::random()); - /// let parent2 = Span::root("parent2", SpanContext::random()); - /// - /// let child = Span::enter_with_parent("child", &parent1) - /// .with_link(SpanContext::from_span(&parent2).unwrap()); - #[inline] - #[deprecated( - note = "Multiple-parent spans are deprecated. Use `enter_with_parent` and link other parents with `with_link`." - )] - pub fn enter_with_parents<'a>( - name: impl Into>, - parents: impl IntoIterator, - ) -> Self { - #[cfg(not(feature = "enable"))] - { - Self::noop() - } - - #[cfg(feature = "enable")] - { - let mut main: Option<&Span> = None; - let mut links = Vec::new(); - for parent in parents.into_iter() { - if parent.inner.is_none() { - continue; - } - - if main.is_none() { - main = Some(parent); - } else if let Some(ctx) = SpanContext::from_span(parent) { - links.push(ctx); - } - } - - let Some(main) = main else { - return Self::noop(); - }; - - let mut span = Self::new( - main.inner.as_ref().unwrap().issue_collect_token(), - name, - None, - ); - - for link in links { - span = span.with_link(link); - } - - span - } - } - - /// Create a new child span associated with the current local span in the current thread. + /// Start a new child span associated with the current local span in the current thread. /// /// If no local span is active, this function returns a no-op span. /// @@ -205,10 +142,10 @@ impl Span { /// let root = Span::root("root", SpanContext::random()); /// let _g = root.set_local_parent(); /// - /// let child = Span::enter_with_local_parent("child"); + /// let child = Span::start_with_local_parent("child"); /// ``` #[inline] - pub fn enter_with_local_parent(name: impl Into>) -> Self { + pub fn start_with_local_parent(name: impl Into>) -> Self { #[cfg(not(feature = "enable"))] { Self::noop() @@ -227,8 +164,7 @@ impl Span { /// This method is used to establish a `Span` as the local parent within the current scope. /// /// A local parent is necessary for creating a [`LocalSpan`] using - /// [`LocalSpan::enter_with_local_parent()`]. If no local parent is set, - /// `enter_with_local_parent()` will not perform any action. + /// [`LocalSpan::start()`]. If no local parent is set, `start()` will not perform any action. /// /// # Examples /// @@ -239,11 +175,11 @@ impl Span { /// let _guard = root.set_local_parent(); // root is now the local parent /// /// // Now we can create a LocalSpan with root as the local parent. - /// let _span = LocalSpan::enter_with_local_parent("a child span"); + /// let _span = LocalSpan::start("a child span"); /// ``` /// /// [`LocalSpan`]: crate::local::LocalSpan - /// [`LocalSpan::enter_with_local_parent()`]: crate::local::LocalSpan::enter_with_local_parent + /// [`LocalSpan::start()`]: crate::local::LocalSpan::start #[inline] pub fn set_local_parent(&self) -> LocalParentGuard { #[cfg(not(feature = "enable"))] @@ -349,7 +285,7 @@ impl Span { { #[cfg(feature = "enable")] { - let mut span = Span::enter_with_parent("", self).with_properties(properties); + let mut span = Span::start("", self).with_properties(properties); if let Some(mut inner) = span.inner.take() { inner.raw_span.raw_kind = RawKind::Properties; inner.submit_spans(); @@ -372,7 +308,7 @@ impl Span { pub fn add_event(&self, event: Event) { #[cfg(feature = "enable")] { - let mut span = Span::enter_with_parent(event.name, self); + let mut span = Span::start(event.name, self); if let Some(mut inner) = span.inner.take() { inner.raw_span.raw_kind = RawKind::Event; inner.raw_span.properties = event.properties; @@ -395,7 +331,7 @@ impl Span { /// let other = Span::root("other", SpanContext::random()); /// let link = SpanContext::from_span(&other).unwrap(); /// - /// let _span = Span::enter_with_parent("child", &root).with_link(link); + /// let _span = Span::start("child", &root).with_link(link); /// ``` #[inline] pub fn with_link(mut self, link: SpanContext) -> Self { @@ -417,14 +353,14 @@ impl Span { /// let other = Span::root("other", SpanContext::random()); /// let link = SpanContext::from_span(&other).unwrap(); /// - /// let child = Span::enter_with_parent("child", &root); + /// let child = Span::start("child", &root); /// child.add_link(link); /// ``` #[inline] pub fn add_link(&self, link: SpanContext) { #[cfg(feature = "enable")] { - let mut span = Span::enter_with_parent("", self); + let mut span = Span::start("", self); if let Some(mut inner) = span.inner.take() { inner.raw_span.raw_kind = RawKind::Link; inner.raw_span.links.push(link); @@ -447,7 +383,7 @@ impl Span { /// /// // Collect local spans manually without a parent /// let collector = LocalCollector::start(); - /// let span = LocalSpan::enter_with_local_parent("a child span"); + /// let span = LocalSpan::start("a child span"); /// drop(span); /// let local_spans = collector.collect(); /// @@ -849,10 +785,9 @@ root [] let routine = || { let parent_ctx = SpanContext::random(); let root = Span::root("root", parent_ctx); - let child1 = - Span::enter_with_parent("child1", &root).with_properties(|| [("k1", "v1")]); - let grandchild = Span::enter_with_parent("grandchild", &child1); - let child2 = Span::enter_with_parent("child2", &root); + let child1 = Span::start("child1", &root).with_properties(|| [("k1", "v1")]); + let grandchild = Span::start("grandchild", &child1); + let child2 = Span::start("child2", &root); crossbeam::scope(move |scope| { let mut rng = rng(); diff --git a/fastrace/tests/lib.rs b/fastrace/tests/lib.rs index 2164c071..5fb2688f 100644 --- a/fastrace/tests/lib.rs +++ b/fastrace/tests/lib.rs @@ -15,7 +15,7 @@ fn four_spans() { { // wide for i in 0..2 { - let _span = LocalSpan::enter_with_local_parent(format!("iter-span-{i}")) + let _span = LocalSpan::start(format!("iter-span-{i}")) .with_property(|| ("tmp_property", "tmp_value")); } } @@ -70,7 +70,7 @@ fn span_links() { let root2 = Span::root("root2", SpanContext::new(TraceId(2), SpanId(0))); let link = SpanContext::from_span(&root2).unwrap(); - let child = Span::enter_with_parent("child", &root1).with_link(link); + let child = Span::start("child", &root1).with_link(link); child.add_link(link); drop(child); @@ -96,7 +96,7 @@ fn local_span_links() { { let _g = root.set_local_parent(); - let _span = LocalSpan::enter_with_local_parent("local").with_link(link1); + let _span = LocalSpan::start("local").with_link(link1); LocalSpan::add_link(link2); } @@ -194,7 +194,7 @@ fn multiple_threads_single_span() { let mut handles = vec![]; for _ in 0..4 { - let child_span = Span::enter_with_local_parent("cross-thread"); + let child_span = Span::start_with_local_parent("cross-thread"); let h = scope.spawn(move |_| { let _g = child_span.set_local_parent(); four_spans(); @@ -305,39 +305,31 @@ fn test_macro() { impl Foo for Bar { #[trace(name = "run")] async fn run(&self, millis: &u64) { - let _g = Span::enter_with_local_parent("run-inner"); + let _g = Span::start_with_local_parent("run-inner"); work(millis).await; - let _g = LocalSpan::enter_with_local_parent("local-span"); + let _g = LocalSpan::start("local-span"); } } - #[trace(short_name = true, enter_on_poll = true)] + #[trace(short_name = true, poll_span = true)] async fn work(millis: &u64) { - let _g = Span::enter_with_local_parent("work-inner"); - tokio::time::sleep(Duration::from_millis(*millis)) - .enter_on_poll("sleep") - .await; + let _g = Span::start_with_local_parent("work-inner"); + tokio::time::sleep(Duration::from_millis(*millis)).await; } impl Bar { #[trace(short_name = true)] async fn work2(&self, millis: &u64) { - let _g = Span::enter_with_local_parent("work-inner"); - tokio::time::sleep(Duration::from_millis(*millis)) - .enter_on_poll("sleep") - .await; + let _g = Span::start_with_local_parent("work-inner"); + tokio::time::sleep(Duration::from_millis(*millis)).await; } } #[trace(short_name = true)] async fn work3(millis1: &u64, millis2: &u64) { - let _g = Span::enter_with_local_parent("work-inner"); - tokio::time::sleep(Duration::from_millis(*millis1)) - .enter_on_poll("sleep") - .await; - tokio::time::sleep(Duration::from_millis(*millis2)) - .enter_on_poll("sleep") - .await; + let _g = Span::start_with_local_parent("work-inner"); + tokio::time::sleep(Duration::from_millis(*millis1)).await; + tokio::time::sleep(Duration::from_millis(*millis2)).await; } let (reporter, collected_spans) = TestReporter::new(); @@ -359,7 +351,7 @@ fn test_macro() { Bar.work2(&100).await; work3(&100, &100).await; } - .in_span(root), + .in_span(Span::start("task", &root)), ), ) .unwrap(); @@ -370,24 +362,18 @@ fn test_macro() { let graph = tree_str_from_span_records(collected_spans.lock().clone()); insta::assert_snapshot!(graph, @r###" root [] - run [] - local-span [] - run-inner [] - work [] - sleep [] - work [] - sleep [] + task [] + run [] + local-span [] + run-inner [] + work [] + work [] + work [] + work-inner [] + work2 [] + work-inner [] + work3 [] work-inner [] - work2 [] - sleep [] - sleep [] - work-inner [] - work3 [] - sleep [] - sleep [] - sleep [] - sleep [] - work-inner [] "###); } @@ -447,13 +433,13 @@ fn multiple_local_parent() { { let root = Span::root("root", SpanContext::random()); let _g = root.set_local_parent(); - let _g = LocalSpan::enter_with_local_parent("span1"); - let span2 = Span::enter_with_local_parent("span2"); + let _g = LocalSpan::start("span1"); + let span2 = Span::start_with_local_parent("span2"); { let _g = span2.set_local_parent(); - let _g = LocalSpan::enter_with_local_parent("span3"); + let _g = LocalSpan::start("span3"); } - let _g = LocalSpan::enter_with_local_parent("span4"); + let _g = LocalSpan::start("span4"); } fastrace::flush(); @@ -476,8 +462,8 @@ fn early_local_collect() { { let local_collector = LocalCollector::start(); - let _g1 = LocalSpan::enter_with_local_parent("span1"); - let _g2 = LocalSpan::enter_with_local_parent("span2"); + let _g1 = LocalSpan::start("span1"); + let _g2 = LocalSpan::start("span2"); drop(_g2); let local_spans = local_collector.collect(); @@ -526,7 +512,7 @@ fn test_property() { let _g = root.set_local_parent(); LocalSpan::add_property(|| ("k7", "v7")); LocalSpan::add_properties(|| [("k8", "v8"), ("k9", "v9")]); - let _span = LocalSpan::enter_with_local_parent("span") + let _span = LocalSpan::start("span") .with_property(|| ("k10", "v10")) .with_properties(|| [("k11", "v11"), ("k12", "v12")]); LocalSpan::add_property(|| ("k13", "v13")); @@ -561,7 +547,7 @@ fn test_event() { .with_property(|| ("k4", "v4")) .with_properties(|| [("k5", "v5"), ("k6", "v6")]), ); - let _span = LocalSpan::enter_with_local_parent("span"); + let _span = LocalSpan::start("span"); LocalSpan::add_event( Event::new("event3 in span") .with_property(|| ("k7", "v7")) @@ -623,7 +609,7 @@ fn test_macro_properties() { foo_async(1, &Bar, Bar).await; bar_async().await; } - .in_span(root), + .in_span(Span::start("task", &root)), ), ) .unwrap(); @@ -635,9 +621,10 @@ fn test_macro_properties() { insta::assert_snapshot!(graph, @r###" root [] bar [] - bar_async [] foo [("k1", "v1"), ("a", "argument a is 1"), ("b", "Bar"), ("escaped1", "Bar{}"), ("escaped2", "{ \"a\": \"b\"}")] - foo_async [("k1", "v1"), ("a", "argument a is 1"), ("b", "Bar"), ("escaped1", "Bar{}"), ("escaped2", "{ \"a\": \"b\"}")] + task [] + bar_async [] + foo_async [("k1", "v1"), ("a", "argument a is 1"), ("b", "Bar"), ("escaped1", "Bar{}"), ("escaped2", "{ \"a\": \"b\"}")] "###); } @@ -649,7 +636,7 @@ fn test_not_sampled() { { let root = Span::root("root", SpanContext::random().sampled(true)); let _g = root.set_local_parent(); - let _span = LocalSpan::enter_with_local_parent("span"); + let _span = LocalSpan::start("span"); } fastrace::flush(); @@ -664,7 +651,7 @@ fn test_not_sampled() { { let root = Span::root("root", SpanContext::random().sampled(false)); let _g = root.set_local_parent(); - let _span = LocalSpan::enter_with_local_parent("span"); + let _span = LocalSpan::start("span"); } fastrace::flush(); assert!(collected_spans.lock().is_empty()); diff --git a/tests/macros/tests/ui/err/has-enter-on-poll-and-sync.stderr b/tests/macros/tests/ui/err/has-enter-on-poll-and-sync.stderr deleted file mode 100644 index c4f98b35..00000000 --- a/tests/macros/tests/ui/err/has-enter-on-poll-and-sync.stderr +++ /dev/null @@ -1,7 +0,0 @@ -error: `enter_on_poll` can not be applied on non-async function - --> tests/ui/err/has-enter-on-poll-and-sync.rs:3:1 - | -3 | #[trace(enter_on_poll = true)] - | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ - | - = note: this error originates in the attribute macro `trace` (in Nightly builds, run with -Z macro-backtrace for more info) diff --git a/tests/macros/tests/ui/err/has-enter-on-poll-and-sync.rs b/tests/macros/tests/ui/err/has-poll-span-and-sync.rs similarity index 59% rename from tests/macros/tests/ui/err/has-enter-on-poll-and-sync.rs rename to tests/macros/tests/ui/err/has-poll-span-and-sync.rs index 4555fcbb..25d44cc2 100644 --- a/tests/macros/tests/ui/err/has-enter-on-poll-and-sync.rs +++ b/tests/macros/tests/ui/err/has-poll-span-and-sync.rs @@ -1,6 +1,6 @@ use fastrace::trace; -#[trace(enter_on_poll = true)] +#[trace(poll_span = true)] fn f() {} fn main() {} diff --git a/tests/macros/tests/ui/err/has-poll-span-and-sync.stderr b/tests/macros/tests/ui/err/has-poll-span-and-sync.stderr new file mode 100644 index 00000000..138fad6f --- /dev/null +++ b/tests/macros/tests/ui/err/has-poll-span-and-sync.stderr @@ -0,0 +1,7 @@ +error: `poll_span` can not be applied on non-async function + --> tests/ui/err/has-poll-span-and-sync.rs:3:1 + | +3 | #[trace(poll_span = true)] + | ^^^^^^^^^^^^^^^^^^^^^^^^^^ + | + = note: this error originates in the attribute macro `trace` (in Nightly builds, run with -Z macro-backtrace for more info) diff --git a/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.rs b/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.rs deleted file mode 100644 index b0f71665..00000000 --- a/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.rs +++ /dev/null @@ -1,6 +0,0 @@ -use fastrace::trace; - -#[trace(enter_on_poll = true, properties = { "a": "b" })] -fn f() {} - -fn main() {} diff --git a/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.stderr b/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.stderr deleted file mode 100644 index 2caf0da4..00000000 --- a/tests/macros/tests/ui/err/has-properties-and-enter-on-poll.stderr +++ /dev/null @@ -1,7 +0,0 @@ -error: `enter_on_poll` can not be used with `properties` - --> tests/ui/err/has-properties-and-enter-on-poll.rs:3:1 - | -3 | #[trace(enter_on_poll = true, properties = { "a": "b" })] - | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ - | - = note: this error originates in the attribute macro `trace` (in Nightly builds, run with -Z macro-backtrace for more info) diff --git a/tests/macros/tests/ui/ok/has-enter-on-poll.rs b/tests/macros/tests/ui/ok/has-poll-span.rs similarity index 60% rename from tests/macros/tests/ui/ok/has-enter-on-poll.rs rename to tests/macros/tests/ui/ok/has-poll-span.rs index 57f68cdf..1308a35c 100644 --- a/tests/macros/tests/ui/ok/has-enter-on-poll.rs +++ b/tests/macros/tests/ui/ok/has-poll-span.rs @@ -1,6 +1,6 @@ use fastrace::trace; -#[trace(enter_on_poll = true)] +#[trace(poll_span = true, properties = { "a": "argument a is {a:?}" })] async fn f(a: u32) -> u32 { a } diff --git a/tests/statically-disable/src/main.rs b/tests/statically-disable/src/main.rs index 9457b341..53506961 100644 --- a/tests/statically-disable/src/main.rs +++ b/tests/statically-disable/src/main.rs @@ -61,24 +61,23 @@ fn main() { .with_properties(|| [("k1", "v1")]), ); - let _span1 = LocalSpan::enter_with_local_parent("span1").with_property(|| ("k0", "v0")); - let _span2 = LocalSpan::enter_with_local_parent("span2") + let _span1 = LocalSpan::start("span1").with_property(|| ("k0", "v0")); + let _span2 = LocalSpan::start("span2") .with_property(|| ("k1", "v1")) .with_properties(|| [("k", "v")]); - let _span3 = LocalSpan::enter_with_local_parent("span3") - .with_link(SpanContext::new(TraceId(1), SpanId(1))); + let _span3 = LocalSpan::start("span3").with_link(SpanContext::new(TraceId(1), SpanId(1))); LocalSpan::add_property(|| ("k0", "v0")); LocalSpan::add_properties(|| [("k", "v")]); LocalSpan::add_link(SpanContext::new(TraceId(1), SpanId(1))); let local_collector = LocalCollector::start(); - let _ = LocalSpan::enter_with_local_parent("span3"); + let _ = LocalSpan::start("span3"); let local_spans = local_collector.collect(); assert_eq!(local_spans.to_span_records(SpanContext::random()), vec![]); - let span3 = Span::enter_with_parent("span3", &root); - let span4 = Span::enter_with_local_parent("span4"); + let span3 = Span::start("span3", &root); + let span4 = Span::start_with_local_parent("span4"); span4.push_child_spans(local_spans); From 6ab084a62a0f2a60a0bded5920e3c3208203474d Mon Sep 17 00:00:00 2001 From: andylokandy Date: Mon, 4 May 2026 22:20:34 +0800 Subject: [PATCH 2/4] style: apply nightly rustfmt --- examples/harness.rs | 4 +--- fastrace-futures/src/lib.rs | 6 ++---- fastrace-macro/src/lib.rs | 31 ++++++++++++++++++++----------- fastrace/src/local/local_span.rs | 3 +-- 4 files changed, 24 insertions(+), 20 deletions(-) diff --git a/examples/harness.rs b/examples/harness.rs index 4ff2af9b..5698f823 100644 --- a/examples/harness.rs +++ b/examples/harness.rs @@ -35,9 +35,7 @@ mod test_util { use fastrace::prelude::*; pub fn setup_fastrace(test: F) - where - F: FnOnce() -> anyhow::Result<()> + 'static, - { + where F: FnOnce() -> anyhow::Result<()> + 'static { fastrace::set_reporter(ConsoleReporter, Config::default()); { let root = Span::root(closure_name::(), SpanContext::random()); diff --git a/fastrace-futures/src/lib.rs b/fastrace-futures/src/lib.rs index a0a06683..bcdedb7d 100644 --- a/fastrace-futures/src/lib.rs +++ b/fastrace-futures/src/lib.rs @@ -149,8 +149,7 @@ impl InSpan { } impl Stream for InSpan -where - T: Stream, +where T: Stream { type Item = T::Item; @@ -179,8 +178,7 @@ where } impl Sink for InSpan -where - T: Sink, +where T: Sink { type Error = T::Error; diff --git a/fastrace-macro/src/lib.rs b/fastrace-macro/src/lib.rs index 614ecb80..8a086b48 100644 --- a/fastrace-macro/src/lib.rs +++ b/fastrace-macro/src/lib.rs @@ -37,8 +37,8 @@ use crate::visit_mut::VisitMut; /// * `name` - The name of the span. Defaults to the full path of the function. /// * `short_name` - Whether to use the function name without path as the span name. Defaults to /// `false`. -/// * `poll_span` - Whether to additionally create a span on each poll. Only available for -/// `async fn`. Defaults to `false`. +/// * `poll_span` - Whether to additionally create a span on each poll. Only available for `async +/// fn`. Defaults to `false`. /// * `properties` - A list of key-value pairs to be added as properties to the span. The value can /// be a format string, where the function arguments are accessible. Defaults to `{}`. /// * `crate` - The path to the fastrace crate. Defaults to `::fastrace`. @@ -81,17 +81,23 @@ use crate::visit_mut::VisitMut; /// /// async fn simple_async() { /// let __span__ = Span::start_with_local_parent("simple_async"); -/// fastrace::future::FutureExt::in_span(async { -/// // ... -/// }, __span__) +/// fastrace::future::FutureExt::in_span( +/// async { +/// // ... +/// }, +/// __span__, +/// ) /// .await /// } /// /// async fn baz() { /// let __span__ = Span::start_with_local_parent("qux"); -/// fastrace::future::FutureExt::in_span(async { -/// // ... -/// }, __span__) +/// fastrace::future::FutureExt::in_span( +/// async { +/// // ... +/// }, +/// __span__, +/// ) /// .with_poll_span("qux") /// .await /// } @@ -106,9 +112,12 @@ use crate::visit_mut::VisitMut; /// ), /// ] /// }); -/// fastrace::future::FutureExt::in_span(async { -/// // ... -/// }, __span__) +/// fastrace::future::FutureExt::in_span( +/// async { +/// // ... +/// }, +/// __span__, +/// ) /// .await /// } /// ``` diff --git a/fastrace/src/local/local_span.rs b/fastrace/src/local/local_span.rs index 7c246f2f..94ca1922 100644 --- a/fastrace/src/local/local_span.rs +++ b/fastrace/src/local/local_span.rs @@ -72,8 +72,7 @@ impl LocalSpan { /// ``` /// use fastrace::prelude::*; /// - /// let span = - /// LocalSpan::start("a child span").with_property(|| ("key", "value")); + /// let span = LocalSpan::start("a child span").with_property(|| ("key", "value")); /// ``` #[inline] pub fn with_property(self, property: F) -> Self From 24611dd25df069ea96363e5ca378eb9d2b2abae9 Mon Sep 17 00:00:00 2001 From: andylokandy Date: Mon, 4 May 2026 22:24:25 +0800 Subject: [PATCH 3/4] fix: remove unused bench import --- fastrace/benches/trace.rs | 1 - 1 file changed, 1 deletion(-) diff --git a/fastrace/benches/trace.rs b/fastrace/benches/trace.rs index 29b689ab..3c419d3d 100644 --- a/fastrace/benches/trace.rs +++ b/fastrace/benches/trace.rs @@ -1,5 +1,4 @@ use divan::Bencher; -use divan::black_box; use fastrace::local::LocalCollector; use fastrace::prelude::*; From 470bdb825f152c326fedb7bc84029db89e465a4a Mon Sep 17 00:00:00 2001 From: andylokandy Date: Mon, 4 May 2026 22:28:46 +0800 Subject: [PATCH 4/4] fix: address async instrumentation review findings --- CHANGELOG.md | 1 + examples/harness.rs | 8 +++++--- fastrace-futures/src/lib.rs | 12 ++++++++---- fastrace/src/future.rs | 12 ++++++++---- 4 files changed, 22 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index bd79fb27..d311f8f8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ All significant changes to this project will be documented in this file. `in_span(Span::start(...)).with_poll_span(name)` for future and stream polling. - Rename span constructors from `Span::enter_with_parent` and `Span::enter_with_local_parent` to `Span::start` and `Span::start_with_local_parent`. +- Remove deprecated `Span::enter_with_parents`; use `Span::start(...).with_link(...)` instead. - Rename `LocalSpan::enter_with_local_parent` to `LocalSpan::start`. - Rename the macro option `enter_on_poll` to `poll_span`; it now creates the async function lifecycle span and adds a poll span on each poll. diff --git a/examples/harness.rs b/examples/harness.rs index 5698f823..8ac0066e 100644 --- a/examples/harness.rs +++ b/examples/harness.rs @@ -56,9 +56,11 @@ mod test_util { .enable_all() .build() .unwrap(); - let root = Span::root(closure_name::(), SpanContext::random()); - rt.block_on(test().in_span(Span::start("test", &root))) - .unwrap(); + { + let root = Span::root(closure_name::(), SpanContext::random()); + rt.block_on(test().in_span(Span::start("test", &root))) + .unwrap(); + } fastrace::flush(); } diff --git a/fastrace-futures/src/lib.rs b/fastrace-futures/src/lib.rs index bcdedb7d..67431790 100644 --- a/fastrace-futures/src/lib.rs +++ b/fastrace-futures/src/lib.rs @@ -157,10 +157,13 @@ where T: Stream let this = self.project(); let guard = this.span.as_ref().map(|s| s.set_local_parent()); - let poll_span = this - .poll_span - .as_ref() - .map(|name| LocalSpan::start(name.clone())); + let poll_span = if this.span.is_some() { + this.poll_span + .as_ref() + .map(|name| LocalSpan::start(name.clone())) + } else { + None + }; let res = this.inner.poll_next(cx); drop(poll_span); drop(guard); @@ -169,6 +172,7 @@ where T: Stream Poll::Pending => Poll::Pending, Poll::Ready(None) => { // finished + this.poll_span.take(); this.span.take(); Poll::Ready(None) } diff --git a/fastrace/src/future.rs b/fastrace/src/future.rs index 426a527c..8f8cde72 100644 --- a/fastrace/src/future.rs +++ b/fastrace/src/future.rs @@ -99,10 +99,13 @@ impl std::future::Future for InSpan { let this = self.project(); let guard = this.span.as_ref().map(|s| s.set_local_parent()); - let poll_span = this - .poll_span - .as_ref() - .map(|name| LocalSpan::start(name.clone())); + let poll_span = if this.span.is_some() { + this.poll_span + .as_ref() + .map(|name| LocalSpan::start(name.clone())) + } else { + None + }; let res = this.inner.poll(cx); drop(poll_span); drop(guard); @@ -110,6 +113,7 @@ impl std::future::Future for InSpan { match res { r @ Poll::Pending => r, other => { + this.poll_span.take(); this.span.take(); other }