Some of the discussion in this issue seems relevant.
It sounds like instrumented async fns just tend to produce a lot of recursion depth rather quickly. (This means it's probably an okay approach to just increase the configured depth a little bit and you don't necessarily have to worry about your code being particularly terrible for running into this.)
If you want to figure out where the issue is triggered, one way to do so is the self-profiling functionality of the compiler.
Basically, you can do this:
- in preparation, install the measureme/crox tool
cargo +stable install --git https://github.com/rust-lang/measureme --branch stable crox and make sure that you have some chromium-based browser installed
- run
cargo check -v to create verbose output of what rustc commands cargo uses
actually let's follow an example, I'm setting up a test crate for myself, called queries and following the issue comment contents I had linked above
[binary crate named queries; dependency on tracing 0.1]
#[tracing::instrument]
async fn l1() { l2().await }
#[tracing::instrument]
async fn l2() { l3().await }
#[tracing::instrument]
async fn l3() { l4().await }
#[tracing::instrument]
async fn l4() { l5().await }
#[tracing::instrument]
async fn l5() { l6().await }
#[tracing::instrument]
async fn l6() { l7().await }
#[tracing::instrument]
async fn l7() { l8().await }
#[tracing::instrument]
async fn l8() { l9().await }
#[tracing::instrument]
async fn l9() { l10().await }
#[tracing::instrument]
async fn l10() { l11().await }
#[tracing::instrument]
async fn l11() { l12().await }
#[tracing::instrument]
async fn l12() { l13().await }
#[tracing::instrument]
async fn l13() {}
fn main() { let _ = l1(); }
to reproduce the issue.
[Lots of output ommitted...]
Checking queries v0.1.0 (/home/frank/playground/queries)
Running `/home/frank/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/rustc --crate-name queries --edition=2024 src/main.rs --error-format=json --json=diagnostic-rendered-ansi,artifacts,future-incompat --diagnostic-width=141 --crate-type bin --emit=dep-info,metadata -C embed-bitcode=no -C debuginfo=2 --check-cfg 'cfg(docsrs,test)' --check-cfg 'cfg(feature, values())' -C metadata=90befbcb87e49566 -C extra-filename=-da342e6bca11a93c --out-dir /home/frank/playground/queries/target/debug/deps -C incremental=/home/frank/playground/queries/target/debug/incremental -L dependency=/home/frank/playground/queries/target/debug/deps --extern tracing=/home/frank/playground/queries/target/debug/deps/libtracing-9806f1dbdcaac669.rmeta`
error: queries overflow the depth limit!
|
= help: consider increasing the recursion limit by adding a `#![recursion_limit = "256"]` attribute to your crate (`queries`)
= note: query depth increased by 130 when computing layout of `{async fn body of l1()}`
error: could not compile `queries` (bin "queries") due to 1 previous error
Caused by:
process didn't exit successfully: `/home/frank/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/rustc --crate-name queries --edition=2024 src/main.rs --error-format=json --json=diagnostic-rendered-ansi,artifacts,future-incompat --diagnostic-width=141 --crate-type bin --emit=dep-info,metadata -C embed-bitcode=no -C debuginfo=2 --check-cfg 'cfg(docsrs,test)' --check-cfg 'cfg(feature, values())' -C metadata=90befbcb87e49566 -C extra-filename=-da342e6bca11a93c --out-dir /home/frank/playground/queries/target/debug/deps -C incremental=/home/frank/playground/queries/target/debug/incremental -L dependency=/home/frank/playground/queries/target/debug/deps --extern tracing=/home/frank/playground/queries/target/debug/deps/libtracing-9806f1dbdcaac669.rmeta` (exit status: 1)
-
copy the failing command at the end of that output
/home/frank/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/rustc --crate-name queries --edition=2024 src/main.rs --error-format=json --json=diagnostic-rendered-ansi,artifacts,future-incompat --diagnostic-width=141 --crate-type bin --emit=dep-info,metadata -C embed-bitcode=no -C debuginfo=2 --check-cfg 'cfg(docsrs,test)' --check-cfg 'cfg(feature, values())' -C metadata=90befbcb87e49566 -C extra-filename=-da342e6bca11a93c --out-dir /home/frank/playground/queries/target/debug/deps -C incremental=/home/frank/playground/queries/target/debug/incremental -L dependency=/home/frank/playground/queries/target/debug/deps --extern tracing=/home/frank/playground/queries/target/debug/deps/libtracing-9806f1dbdcaac669.rmeta
(I assume this will fail with your top-level crate, otherwise maybe things are more complicated to approach, I'm not quite sure how recursion_limit works with dependencies..)
-
now add #![recursion_limit = "256"], or whatever value needed to make things compile to your crate
-
run cargo check to see it actually works now
-
run the previously saved rustc invocation with some modifications:
we make use of unstable/nightly features for the self-profiling; to minimize variability, if you aren't on nightly, you can use this with the stable compiler by adding RUSTC_BOOTSTRAP=1 as an environment variable. (Note that of course nonetheless, these specific behaviors and options can break in the future.)
modify the copied command by prefixing the environment variable setting step (assuming a linux/unix style terminal, IDK how it works e.g. on Windows), and adding -Zself-profile options as follows:
RUSTC_BOOTSTRAP=1 …command-from-above… -Zself-profile -Zself-profile-events=default,args
so in my case this becomes
RUSTC_BOOTSTRAP=1 /home/frank/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/rustc --crate-name queries --edition=2024 src/main.rs --error-format=json --json=diagnostic-rendered-ansi,artifacts,future-incompat --diagnostic-width=141 --crate-type bin --emit=dep-info,metadata -C embed-bitcode=no -C debuginfo=2 --check-cfg 'cfg(docsrs,test)' --check-cfg 'cfg(feature, values())' -C metadata=90befbcb87e49566 -C extra-filename=-da342e6bca11a93c --out-dir /home/frank/playground/queries/target/debug/deps -C incremental=/home/frank/playground/queries/target/debug/incremental -L dependency=/home/frank/playground/queries/target/debug/deps --extern tracing=/home/frank/playground/queries/target/debug/deps/libtracing-9806f1dbdcaac669.rmeta -Zself-profile -Zself-profile-events=default,args
-
observe this produces a file named queries-0000000.mm_profdata with some arbitrary number in place of 0000000
-
run crox on this file, e.g. in my case that was crox queries-0611608.mm_profdata
-
observe this produces a file named chrome_profiler.json
-
load this into the profiler as explained in the measureme/crox README
you should be able to spot the deepest query stacks visually now. By having the args enabled, you can also find out more easily what parts of your code these correspond to. E.g. here:
I can spot in the args along the large stack that e.g. this particular step I'm pointing at above has something to do with the l6 function in my queries crate.