Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: remove future names from task spans #3073

Closed
hawkw opened this issue Oct 29, 2020 · 3 comments · Fixed by #3074
Closed

tracing: remove future names from task spans #3073

hawkw opened this issue Oct 29, 2020 · 3 comments · Fixed by #3074
Assignees
Labels
A-tokio Area: The main tokio crate C-feature-request Category: A feature request. M-tracing Tracing support in Tokio

Comments

@hawkw
Copy link
Member

hawkw commented Oct 29, 2020

Is your feature request related to a problem? Please describe.
Currently, the per-task tracing spans generated by tokio's tracing feature flag include the std::any::type_name of the future that was spawned. When future combinators and/or libraries like Tower are in use, these future names can get quite long. Furthermore, when formatting the tracing spans with their parent spans as context, any other task spans in the span context where the future was spawned from can also include extremely long future names.

In some cases, this can result in extremely high memory use just to store the future names. For example, in Linkerd, when we enable tokio=trace to enable the task spans, there's a spawned task whose future name is 232990 characters long. A proxy with only 14 spawned tasks generates a task list that's over 690 KB. Enabling task spans under load results in the process getting OOM killed very quickly.

Describe the solution you'd like
We should remove the future name from the per-task spans. It's rarely useful for debugging, and its extreme length can make trace logs harder to read. Furthermore, it can result in out of control memory use.

Describe alternatives you've considered
When track_caller is supported on our MSRV, we may want to add #[track_caller] to tokio::spawn, so that the task spans can instead be annotated with the callsite location the task was spawned from. This would provide another way of identifying spawned futures without including their potentially extremely long type names.

We could even add track_caller support now by requiring users to enable a RUSTFLAGS cfg that states they're on the latest compiler.

@hawkw hawkw added A-tokio Area: The main tokio crate C-feature-request Category: A feature request. M-tracing Tracing support in Tokio labels Oct 29, 2020
@hawkw hawkw self-assigned this Oct 29, 2020
@sfackler
Copy link
Contributor

We could even add track_caller support now by requiring users to enable a RUSTFLAGS cfg that states they're on the latest compiler.

You can also have a build script figure out what rustc version is being used and automatically set an appropriate cfg.

@hawkw
Copy link
Member Author

hawkw commented Oct 29, 2020

We could even add track_caller support now by requiring users to enable a RUSTFLAGS cfg that states they're on the latest compiler.

You can also have a build script figure out what rustc version is being used and automatically set an appropriate cfg.

Yup, I was also thinking about doing that!

@hawkw
Copy link
Member Author

hawkw commented Oct 29, 2020

Another thought is that if anyone does like the future type name or actually finds it useful, we could also keep them, but truncate them at a certain number of characters to prevent them from getting unacceptably long. This could be in addition to adding spawn locations when available.

hawkw added a commit that referenced this issue Nov 1, 2020
## Motivation

Currently, the per-task `tracing` spans generated by tokio's `tracing`
feature flag include the `std::any::type_name` of the future that was
spawned. When future combinators and/or libraries like Tower are in use,
these future names can get _quite_ long. Furthermore, when formatting
the `tracing` spans with their parent spans as context, any other task
spans in the span context where the future was spawned from can _also_
include extremely long future names.

In some cases, this can result in extremely high memory use just to
store the future names. For example, in Linkerd, when we enable
`tokio=trace` to enable the task spans, there's a spawned task whose
future name is _232990 characters long_. A proxy with only 14 spawned
tasks generates a task list that's over 690 KB. Enabling task spans
under load results in the process getting OOM killed very quickly.

## Solution

This branch removes future type names from the spans generated by
`spawn`. As a replacement, to allow identifying which `spawn` call a
span corresponds to, the task span now contains the source code location
where `spawn` was called, when the compiler supports the
`#[track_caller]` attribute. Since `track_caller` was stabilized in Rust
1.46.0, and our minimum supported Rust version is 1.45.0, we can't
assume that `#[track_caller]` is always available. Instead, we have a
RUSTFLAGS cfg, `tokio_track_caller`, that guards whether or not we use
it. I've also added a `build.rs` that detects the compiler minor
version, and sets the cfg flag automatically if the current compiler
version is >= 1.46. This means users shouldn't have to enable
`tokio_track_caller` manually.

Here's the trace output from the `chat` example, before this change:
![Screenshot_20201030_110157](https://user-images.githubusercontent.com/2796466/97741071-6d408800-1a9f-11eb-9ed6-b25e72f58c7b.png)
...and after:
![Screenshot_20201030_110303](https://user-images.githubusercontent.com/2796466/97741112-7e899480-1a9f-11eb-9197-c5a3f9ea1c05.png)

Closes #3073

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-tokio Area: The main tokio crate C-feature-request Category: A feature request. M-tracing Tracing support in Tokio
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants