Use tracing::Instrument in generated bindings to avoid holding spans across await points#9217
Merged
pchickey merged 2 commits intobytecodealliance:mainfrom Sep 10, 2024
Merged
Conversation
across await points
Previously, if we had a WIT file with a function
async-fn: func();
then the generated code in `add_to_linker_get_host` would look like
this (if tracing is enabled and the function is async)
inst.func_wrap_async(
"my-func",
move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| {
wasmtime::component::__internal::Box::new(async move {
let span = tracing::span!(
tracing::Level::TRACE,
"wit-bindgen import",
module = "test",
function = "my-func",
);
let _enter = span.enter();
tracing::event!(tracing::Level::TRACE, "call");
let host = &mut host_getter(caller.data_mut());
let r = Host::my_func(host).await;
tracing::event!(
tracing::Level::TRACE,
result = tracing::field::debug(&r),
"return"
);
Ok(r)
})
},
)?;
This keeps the tracing span active, even when the resulting future is
suspended. The end result is that other unrelated tokio tasks running on
the same thread in the meantime will be shown as executing within the
`wit-bindgen import` span.
This commit changes the codegen to instead generate
inst.func_wrap_async(
"async-fn",
move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| {
use tracing::Instrument;
let span = tracing::span!(
tracing::Level::TRACE,
"wit-bindgen import",
module = "test",
function = "async-fn",
);
wasmtime::component::__internal::Box::new(
async move {
tracing::event!(tracing::Level::TRACE, "call");
let host = &mut host_getter(caller.data_mut());
let r = Host::async_fn(host).await;
tracing::event!(
tracing::Level::TRACE,
result = tracing::field::debug(&r),
"return"
);
Ok(r)
}
.instrument(span),
)
},
)?;
Here, `tracing::Instrument` takes care of entering the span when the
future is polled and exiting it when it is suspended.
Fixes bytecodealliance#9210
Contributor
Author
|
The macos wasmtime CI job seems to be stalled when running |
Contributor
|
Sometimes runners just flake, lets try it again |
elliottt
pushed a commit
to elliottt/wasmtime
that referenced
this pull request
Sep 16, 2024
…s across await points (bytecodealliance#9217) * Use `tracing::Instrument` in generated bindings to avoid holding spans across await points Previously, if we had a WIT file with a function async-fn: func(); then the generated code in `add_to_linker_get_host` would look like this (if tracing is enabled and the function is async) inst.func_wrap_async( "my-func", move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| { wasmtime::component::__internal::Box::new(async move { let span = tracing::span!( tracing::Level::TRACE, "wit-bindgen import", module = "test", function = "my-func", ); let _enter = span.enter(); tracing::event!(tracing::Level::TRACE, "call"); let host = &mut host_getter(caller.data_mut()); let r = Host::my_func(host).await; tracing::event!( tracing::Level::TRACE, result = tracing::field::debug(&r), "return" ); Ok(r) }) }, )?; This keeps the tracing span active, even when the resulting future is suspended. The end result is that other unrelated tokio tasks running on the same thread in the meantime will be shown as executing within the `wit-bindgen import` span. This commit changes the codegen to instead generate inst.func_wrap_async( "async-fn", move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| { use tracing::Instrument; let span = tracing::span!( tracing::Level::TRACE, "wit-bindgen import", module = "test", function = "async-fn", ); wasmtime::component::__internal::Box::new( async move { tracing::event!(tracing::Level::TRACE, "call"); let host = &mut host_getter(caller.data_mut()); let r = Host::async_fn(host).await; tracing::event!( tracing::Level::TRACE, result = tracing::field::debug(&r), "return" ); Ok(r) } .instrument(span), ) }, )?; Here, `tracing::Instrument` takes care of entering the span when the future is polled and exiting it when it is suspended. Fixes bytecodealliance#9210 * Bless expanded macro outputs
alexcrichton
pushed a commit
that referenced
this pull request
Sep 16, 2024
* Use `tracing::Instrument` in generated bindings to avoid holding spans across await points (#9217) * Use `tracing::Instrument` in generated bindings to avoid holding spans across await points Previously, if we had a WIT file with a function async-fn: func(); then the generated code in `add_to_linker_get_host` would look like this (if tracing is enabled and the function is async) inst.func_wrap_async( "my-func", move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| { wasmtime::component::__internal::Box::new(async move { let span = tracing::span!( tracing::Level::TRACE, "wit-bindgen import", module = "test", function = "my-func", ); let _enter = span.enter(); tracing::event!(tracing::Level::TRACE, "call"); let host = &mut host_getter(caller.data_mut()); let r = Host::my_func(host).await; tracing::event!( tracing::Level::TRACE, result = tracing::field::debug(&r), "return" ); Ok(r) }) }, )?; This keeps the tracing span active, even when the resulting future is suspended. The end result is that other unrelated tokio tasks running on the same thread in the meantime will be shown as executing within the `wit-bindgen import` span. This commit changes the codegen to instead generate inst.func_wrap_async( "async-fn", move |mut caller: wasmtime::StoreContextMut<'_, T>, (): ()| { use tracing::Instrument; let span = tracing::span!( tracing::Level::TRACE, "wit-bindgen import", module = "test", function = "async-fn", ); wasmtime::component::__internal::Box::new( async move { tracing::event!(tracing::Level::TRACE, "call"); let host = &mut host_getter(caller.data_mut()); let r = Host::async_fn(host).await; tracing::event!( tracing::Level::TRACE, result = tracing::field::debug(&r), "return" ); Ok(r) } .instrument(span), ) }, )?; Here, `tracing::Instrument` takes care of entering the span when the future is polled and exiting it when it is suspended. Fixes #9210 * Bless expanded macro outputs * Update the release notes --------- Co-authored-by: Sean Lynch <42618346+swlynch99@users.noreply.github.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
This PR fixes #9210.
Previously, if we had a WIT file with a function
then the generated code in
add_to_linker_get_hostwould look like this (if tracing is enabled and the function is async)This keeps the tracing span active, even when the resulting future is suspended. The end result is that other unrelated tokio tasks running on the same thread in the meantime will be shown as executing within the
wit-bindgen importspan.This commit changes the codegen to instead generate
Here,
tracing::Instrumenttakes care of entering the span when the future is polled and exiting it when it is suspended.I have also manually verified that the codegen for sync functions remains exactly the same.