Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions prdoc/pr_11095.prdoc
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
title: '`prefix_logs_with`: Ensure the macro works correctly for futures'
doc:
- audience: Node Dev
description: |-
When setting up a tracing span in an async future, it may gets invalidated by any `await` point. The problem is that after continuing a future, it may runs on a different thread where the `span` isn't active anymore. The solution for this is to `instrument` the future properly.
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
When setting up a tracing span in an async future, it may gets invalidated by any `await` point. The problem is that after continuing a future, it may runs on a different thread where the `span` isn't active anymore. The solution for this is to `instrument` the future properly.
When setting up a tracing span in an async future, it may get invalidated by any `await` point. The problem is that after continuing a future, it may run on a different thread where the `span` isn't active anymore. The solution for this is to `instrument` the future properly.

crates:
- name: sc-tracing-proc-macro
bump: patch
45 changes: 33 additions & 12 deletions substrate/client/tracing/proc-macro/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -123,19 +123,40 @@ pub fn prefix_logs_with(arg: TokenStream, item: TokenStream) -> TokenStream {

let syn::ItemFn { attrs, vis, sig, block } = item_fn;

(quote! {
#(#attrs)*
#vis #sig {
let span = #crate_name::tracing::info_span!(
#crate_name::logging::PREFIX_LOG_SPAN,
name = #prefix_expr,
);
let _enter = span.enter();
if sig.asyncness.is_some() {
// For async functions, use `Instrument::instrument` to properly propagate the span
// across `.await` points. Using `span.enter()` in async functions is incorrect because
// the guard can be held across `.await` points where the task may migrate between
// threads, losing the span from thread-local state.
(quote! {
#(#attrs)*
#vis #sig {
let span = #crate_name::tracing::info_span!(
#crate_name::logging::PREFIX_LOG_SPAN,
name = #prefix_expr,
);

#block
}
})
.into()
#crate_name::tracing::Instrument::instrument(async move {
#block
}, span).await
}
})
.into()
} else {
(quote! {
#(#attrs)*
#vis #sig {
let span = #crate_name::tracing::info_span!(
#crate_name::logging::PREFIX_LOG_SPAN,
name = #prefix_expr,
);
let _enter = span.enter();

#block
}
})
.into()
}
}

/// Resolve the correct path for sc_tracing:
Expand Down
Loading