test(subscriber): add test for tasks being kept open #490
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
hds
added a commit
to tokio-rs/tokio
that referenced
this pull request
Nov 18, 2023
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
force-pushed
the
hds/subscriber-test-task-explicit-parent
branch
from
8b5dbe4
to
d3b6aa8
Compare
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
force-pushed
the
hds/subscriber-test-task-explicit-parent
branch
from
d3b6aa8
to
39b0c83
Compare
This branch modifies tokio to make the spans that instrument tasks explicit roots, instead of taking as a parent the current span context. This shows that change in tokio fixes the problem that causes the lost waker lint to fire incorrectly.
hds
added a commit
to tokio-rs/tokio
that referenced
this pull request
Nov 19, 2023
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).
The fix has been merged.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
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 contextualparent 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_attime 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 ofenriching the Tokio instrumentation (tokio-rs/tokio#5792).
This change adds functionality to the test framework within
console-subscriberso that the state of a task can be set as anexpectation. The state is calculated based on 4 values:
console_api::tasks::Stats::dropped_atconsole_api::tasks::Stats::last_wakeconsole_api::PollStats::last_poll_startedconsole_api::PollStats::last_poll_endedIt can then be tested that a task that spawns another task and then ends
actually goes to the
Completedstate, even if the spawned task isstill running. As of Tokio 1.33.0, this test fails, but the PR FIXME:TBD
fixes this and the test should pass from Tokio 1.34 onwards.