instrument macro messes up compiler errors/backtraces when combined with other proc macros

[chanks]

Bug Report

Version

tracing = { version = "0.1.19", features = ["attributes"] }
tokio = { version = "0.2.22", features = ["full"] }

(both current as of this date)

Platform

Linux ada 5.4.0-42-generic #46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

Description

Hi! I've discovered that compiler error locations and backtraces get messed up when combining the instrument macro with tokio's tokio::test macro. I've put together a reproduction here:

https://github.com/chanks/tracing-bug/blob/master/src/main.rs

If the #[tracing::instrument] line is removed then the compiler error points to the correct place. If the #[tracing::instrument] line is moved before the #[tokio::test] line, a new use of undeclared type or module tracing_futures compiler error occurs, but that seems like a separate issue.

This also seems to affect backtraces, which makes debugging difficult - if you change the nonexistent_function to a panic! and set RUST_BACKTRACE=1, you'll see that the generated backtrace points to the beginning of the file (src/main.rs:1:1) rather than the correct line - again, if #[tracing::instrument] is removed, this doesn't occur.

I'm not certain that this is tracing's fault, it might be due to a bug in the tokio crate. It's not clear to me how to debug this.

Thanks!

[hawkw]

Hmm, I wonder if this is related to the issues we've seen in the past when using #[instrument] alongside #[async_trait] resulting in missing locations for compiler diagnostics (#768)? It certainly sounds related. I believe this was due to a compiler bug --- do you happen to know what Rust compiler you're using?

If the #[tracing::instrument] line is removed then the compiler error points to the correct place. If the #[tracing::instrument] line is moved before the #[tokio::test] line, a new use of undeclared type or module tracing_futures compiler error occurs, but that seems like a separate issue.

As a side note, this can be fixed by adding a dependency on the tracing-futures crate to your Cargo.toml. Using #[instrument] with async fn currently requires that crate.

[chanks]

My compiler version is rustc 1.48.0-nightly (d006f5734 2020-08-28)

Good to know about the tracing-futures dependency, I guess tokio was setting that up for me when the macro declarations were reversed?