Exponential compile times with chained #[instrument]

[audunska]

Bug Report

Version

• tracing v0.1.26
• tracing-attributes v0.1.15
• tracing-core v0.1.18

Platform

Linux 5.11.0-16-generic / Ubuntu 21.04 / x86_64

Crates

Probably tracing-attributes

Description

cargo build takes exponential time in the number of #[instrument]s chained after each other on async functions.
Using #[instrument(err)] makes the problem worse.

In our rust codebase at Cognite, we found that adding just a few #[instrument(err)] statements increased compile times drastically. After some investigation, I found the cause to be exponential behavior in the number of such statements. This is demonstrated in this github repository:

https://github.com/audunska/tracing-exponential

Plotting the excess average compile time in seconds vs. the number of #[instrument]s (note the logarithmic y axis):

[hawkw]

Out of interest, what Rust compiler version are you using?

There was a regression introduced in rustc 1.50 (rust-lang/rust#84873) that causes a significant increase in compile time (and in the compiler's memory use) when compiling code with complex nested types, such as those produced by future combinators (including instrument). It's possible that the use of #[instrument] is triggering this issue in the compiler.

[audunska]

Your hunch is correct! This is on 1.52, and with 1.49 the issue goes away.

[audunska]

In fact, it goes bad on nightly-2020-12-19, the same version as your linked issue.

[audunska]

Adding boxing as a workaround helps!

[hawkw]

Your hunch is correct! This is on 1.52, and with 1.49 the issue goes away.

Great, glad I could help!

I'm going to close this since it's an upstream bug and, as far as I know, there isn't anything tracing can do about this. If there's anything we should do, please let me know and we can reopen this issue?

[audunska]

No problem!