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

task: make task span explicit root #6158

Merged
merged 2 commits into from
Nov 19, 2023
Merged

task: make task span explicit root #6158

merged 2 commits into from
Nov 19, 2023

Conversation

hds
Copy link
Contributor

@hds hds commented Nov 18, 2023

Motivation

In Tokio, tasks are optionally instrumented with tracing spans to allow
analysis of the runtime behavior to be performed with tools like
tokio-console.

The span that is created for each task gets currently follows the
default tracing behavior and has a contextual parent attached to it
based on the span that is actual when tokio::spawn or similar is
called.

However, in tracing, a span will remain "alive" until all its children
spans are closed. This doesn't match how spawned tasks work. A task may
outlive the context in which is was spawned (and frequently does). This
causes tasks which spawn other - longer living - tasks to appear in
tokio-console as having lost their waker when instead they should be
shown as completed (tokio-rs/console#345). It can also cause undesired
behavior for unrelated tracing spans if a subscriber is receiving both
the other spans as well as Tokio's instrumentation.

Solution

To fix this mismatch in behavior, the task span has parent: None set
on it, making it an explicit root - it has no parent. The same was
already done for all spans representing resources in #6107. This change
is made within the scope of #5792.

Due to a defect in the currently available tracing-mock crate, it is
not possible to test this change at a tracing level
(tokio-rs/tracing#2440). Instead, a test for the console-subscriber
has been written which shows that this change fixes the defect as
observed in tokio-console (tokio-rs/console#490).

In Tokio, tasks are optionally instrumented with tracing spans to allow
analysis of the runtime behavior to be performed with tools like
tokio-console.

The span that is created for each task gets currently follows the
default tracing behavior and has a contextual parent attached to it
based on the span that is actual when `tokio::spawn` or similar is
called.

However, in tracing, a span will remain "alive" until all its children
spans are closed. This doesn't match how spawned tasks work. A task may
outlive the context in which is was spawned (and frequently does). This
causes tasks which spawn other - longer living - tasks to appear in
`tokio-console` as having lost their waker when instead they should be
shown as completed (tokio-rs/console#345). It can also cause undesired
behavior for unrelated tracing spans if a subscriber is receiving both
the other spans as well as Tokio's instrumentation.

To fix this mismatch in behavior, the task span has `parent: None` set
on it, making it an explicit root - it has no parent. The same was
already done for all spans representing resources in #6107. This change
is made within the scope of #5792.

Due to a defect in the currently available `tracing-mock` crate, it is
not possible to test this change at a tracing level
(tokio-rs/tracing#2440). Instead, a test for the `console-subscriber`
has been written which shows that this change fixes the defect as
observed in `tokio-console` (tokio-rs/console#490).
hds added a commit to tokio-rs/console that referenced this pull request Nov 18, 2023
In the Tokio instrumentation, a tracing span is created for each task
which is spawned. Since the new span is created within the context of
where `tokio::spawn()` (or similar) is called from, it gets a contextual
parent attached.

In tracing, when a span has a child span (either because the child was
created in the context of the parent, or because the parent was set
explicitly) then that span will not be closed until the child has
closed.

The result in the console subscriber is that a task which spawns another
task won't have a `dropped_at` time set until the spawned task exits,
even if the parent task exits much earlier. This causes Tokio Console to
show an incorrect lost waker warning (#345). It also affects other spans
that are entered when a task is spawned (#412).

The solution is to modify the instrumentation in Tokio so that task
spans are explicit roots (`parent: None`). This will be done as part of
enriching the Tokio instrumentation (tokio-rs/tokio#5792).

This change adds functionality to the test framework within
`console-subscriber` so that the state of a task can be set as an
expectation. The state is calculated based on 4 values:
* `console_api::tasks::Stats::dropped_at`
* `console_api::tasks::Stats::last_wake`
* `console_api::PollStats::last_poll_started`
* `console_api::PollStats::last_poll_ended`

It can then be tested that a task that spawns another task and then ends
actually goes to the `Completed` state, even if the spawned task is
still running. As of Tokio 1.34.0, this test fails, but the PR
tokio-rs/tokio#6158 fixes this and the test should pass from Tokio 1.35
onwards.
@hds hds marked this pull request as draft November 18, 2023 23:50
@hawkw hawkw self-requested a review November 19, 2023 17:18
@hawkw
Copy link
Member

hawkw commented Nov 19, 2023

@hds is there a specific reason why this PR is marked as a draft? is it waiting on anything in particular before it's ready for review?

@hds
Copy link
Contributor Author

hds commented Nov 19, 2023

@hawkw Not waiting for anything any more. Please feel free to review.

(reasons below for anyone who's interested)

The associated test in console-subscriber (poining at this branch for tokio) has a failure in it (tokio-rs/console#490). Yesterday I thought that it might have been caused by this PR or the previous one where all resource spans were made explicit roots, so I moved it to draft status.

After digging into it more today, it seems that it is just another case of the flaky tests (tokio-rs/console#473) caused by that race condition in tracing (tokio-rs/tracing#2743).

@hds hds marked this pull request as ready for review November 19, 2023 17:25
@hds hds merged commit 7a30504 into master Nov 19, 2023
71 checks passed
@hds hds deleted the hds/task-span-explicit-root branch November 19, 2023 18:21
@Darksonn Darksonn added A-tokio Area: The main tokio crate M-tracing Tracing support in Tokio labels Nov 24, 2023
kodiakhq bot pushed a commit to pdylanross/fatigue that referenced this pull request Dec 11, 2023
Bumps tokio from 1.34.0 to 1.35.0.

Release notes
Sourced from tokio's releases.

Tokio v1.35.0
1.35.0 (December 8th, 2023)
Added

net: add Apple watchOS support (#6176)

Changed

io: drop the Sized requirements from AsyncReadExt.read_buf (#6169)
runtime: make Runtime unwind safe (#6189)
runtime: reduce the lock contention in task spawn (#6001)
tokio: update nix dependency to 0.27.1 (#6190)

Fixed

chore: make --cfg docsrs work without net feature (#6166)
chore: use relaxed load for unsync_load on miri (#6179)
runtime: handle missing context on wake (#6148)
taskdump: fix taskdump cargo config example (#6150)
taskdump: skip notified tasks during taskdumps (#6194)
tracing: avoid creating resource spans with current parent, use a None parent instead (#6107)
tracing: make task span explicit root (#6158)

Documented

io: flush in AsyncWriteExt examples (#6149)
runtime: document fairness guarantees and current behavior (#6145)
task: document cancel safety of LocalSet::run_until (#6147)

#6001: tokio-rs/tokio#6001
#6107: tokio-rs/tokio#6107
#6144: tokio-rs/tokio#6144
#6145: tokio-rs/tokio#6145
#6147: tokio-rs/tokio#6147
#6148: tokio-rs/tokio#6148
#6149: tokio-rs/tokio#6149
#6150: tokio-rs/tokio#6150
#6158: tokio-rs/tokio#6158
#6166: tokio-rs/tokio#6166
#6169: tokio-rs/tokio#6169
#6176: tokio-rs/tokio#6176
#6179: tokio-rs/tokio#6179
#6189: tokio-rs/tokio#6189
#6190: tokio-rs/tokio#6190
#6194: tokio-rs/tokio#6194



Commits

92a3455 chore: prepare Tokio v1.35.0 (#6197)
1968565 chore: use relaxed load for unsync_load (#6203)
c9273f1 sync: improve safety comments for WakeList (#6200)
e05d0f8 changelog: fix missing link for 1.8.2 (#6199)
debcb22 Revert "net: add SocketAddr::as_abstract_namespace (#6144)" (#6198)
83b7397 io: drop the Sized requirements from AsyncReadExt.read_buf (#6169)
3991f9f docs: fix typo in 'tokio/src/sync/broadcast.rs' (#6182)
48c0e62 chore: use relaxed load for unsync_load on miri (#6179)
d561b58 taskdump: skip notified tasks during taskdumps (#6194)
3a4aef1 runtime: reduce the lock contention in task spawn (#6001)
Additional commits viewable in compare view




Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.


Dependabot commands and options

You can trigger Dependabot actions by commenting on this PR:

@dependabot rebase will rebase this PR
@dependabot recreate will recreate this PR, overwriting any edits that have been made to it
@dependabot merge will merge this PR after your CI passes on it
@dependabot squash and merge will squash and merge this PR after your CI passes on it
@dependabot cancel merge will cancel a previously requested merge and block automerging
@dependabot reopen will reopen this PR if it is closed
@dependabot close will close this PR and stop Dependabot recreating it. You can achieve the same result by closing it manually
@dependabot show <dependency name> ignore conditions will show all of the ignore conditions of the specified dependency
@dependabot ignore this major version will close this PR and stop Dependabot creating any more for this major version (unless you reopen the PR or upgrade to it yourself)
@dependabot ignore this minor version will close this PR and stop Dependabot creating any more for this minor version (unless you reopen the PR or upgrade to it yourself)
@dependabot ignore this dependency will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself)
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 M-tracing Tracing support in Tokio
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants