core: fix incorrect max level filter calculation #908
Merged
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
Signed-off-by: Eliza Weisman <[email protected]>
Signed-off-by: Eliza Weisman <[email protected]>
Currently, when rebuilding the interest cache, the max level is calculated by tracking a max level, and comparing it with each active `Subscriber`'s max level hint, and setting the max value to the hint if the hint is higher than the current value. This is correct. However, the max level in this calculation starts at `TRACE`. This means that regardless of what any subscriber returns for its hint, after rebuilding the interest cache, the max level will *always* be `TRACE`. This is wrong. The max level calculation was started at `TRACE` rather than `OFF`, because when this code was written with it starting at `OFF`, all the tests broke, because the test subscribers don't provide hints. This was the incorrect solution to that problem, however. This caused the tests to break because we were *ignoring* all `None` hints, and not changing the current max value when a subscriber returns `None`. This means that if all subscribers returned `None` for their max level hint, the max would remain `OFF`. However, what we *should* have done is assume that if a subscriber doesn't provide a hint, it won't be filtering based on levels, and assume that the max level is `TRACE` for that subscriber. Now, the max level should be calculated correctly for subscribers that *do* provide hints, and should still be `TRACE` if a subscriber does not have a hint. Whoopsie! Signed-off-by: Eliza Weisman <[email protected]>
Signed-off-by: Eliza Weisman <[email protected]>
This fixes an issue with `EnvFilter`'s `max_level_hint` not considering that span field value filters may enable *any* span, regardless of the level enabled inside that span. This is because the field value must be recorded to be known. We may wish to change this behavior to only check spans up to the selected level, but this isn't what it does currently. This branch fixes the wrong max level hint. This bug was not caught due to an issue where hinting was too permissive, but fixing that bug uncovers this issue. Signed-off-by: Eliza Weisman <[email protected]>
This fixes an issue with `EnvFilter`'s `max_level_hint` not considering that span field value filters may enable *any* span, regardless of the level enabled inside that span. This is because the field value must be recorded to be known. We may wish to change this behavior to only check spans up to the selected level, but this isn't what it does currently. This branch fixes the wrong max level hint. This bug was not caught due to an issue where hinting was too permissive, but fixing that bug uncovers this issue. Signed-off-by: Eliza Weisman <[email protected]>
Signed-off-by: Eliza Weisman <[email protected]>
hawkw
added
crate/core
Signed-off-by: Eliza Weisman <[email protected]>
hawkw
commented
Aug 8, 2020
yaahc
approved these changes
Aug 10, 2020
Signed-off-by: Eliza Weisman <[email protected]>
hawkw
added a commit
that referenced
this pull request
Aug 10, 2020
Fixed - Incorrect calculation of global max level filter which could result in fast filtering paths not being taken (#908)
hawkw
added a commit
that referenced
this pull request
Aug 10, 2020
### Fixed - Incorrect calculation of global max level filter which could result in fast filtering paths not being taken (#908)
hawkw
added a commit
that referenced
this pull request
Aug 10, 2020
Fixed - Updated `tracing-core` to fix incorrect calculation of the global max level filter (#908) Added - **attributes**: Support for using `self` in field expressions when instrumenting `async-trait` functions (#875) - Several documentation improvements (#832, #881, #896, #897, #911, #913) Thanks to @anton-dutov, @nightmared, @mystor, and @toshokan for contributing to this release!
hawkw
added a commit
that referenced
this pull request
Aug 11, 2020
### Fixed - Updated `tracing-core` to fix incorrect calculation of the global max level filter (#908) ### Added - **attributes**: Support for using `self` in field expressions when instrumenting `async-trait` functions (#875) - Several documentation improvements (#832, #881, #896, #897, #911, #913) Thanks to @anton-dutov, @nightmared, @mystor, and @toshokan for contributing to this release! Signed-off-by: Eliza Weisman <[email protected]>
hawkw
added a commit
to linkerd/linkerd2-proxy
that referenced
this pull request
Aug 11, 2020
This branch makes the following dependency updates:
```
:; cargo update -p tracing -p tracing-core -p tracing-subscriber -p tokio-trace
Updating crates.io index
Updating git repository `https://github.com/hawkw/tokio-trace`
Updating regex v1.2.1 -> v1.3.9
Updating regex-syntax v0.6.11 -> v0.6.18
Updating thread_local v0.3.6 -> v1.0.1
Updating tracing v0.1.18 -> v0.1.19
Updating tracing-attributes v0.1.9 -> v0.1.10
Updating tracing-core v0.1.12 -> v0.1.14
Updating tracing-subscriber v0.2.10 -> v0.2.11
```
In particular, the `tracing-core` update picks up upstream change
tokio-rs/tracing#908, which fixes a bug where filtering would fail to
take the fastest fast path in many cases. This time, there's a small,
but actually noticeable, latency reduction in the proxy benchmarks.
Signed-off-by: Eliza Weisman <[email protected]>
hawkw
added a commit
to linkerd/linkerd2-proxy
that referenced
this pull request
Aug 11, 2020
This branch makes the following dependency updates:
```
:; cargo update -p tracing -p tracing-core -p tracing-subscriber -p tokio-trace
Updating crates.io index
Updating git repository `https://github.com/hawkw/tokio-trace`
Updating regex v1.2.1 -> v1.3.9
Updating regex-syntax v0.6.11 -> v0.6.18
Updating thread_local v0.3.6 -> v1.0.1
Updating tracing v0.1.18 -> v0.1.19
Updating tracing-attributes v0.1.9 -> v0.1.10
Updating tracing-core v0.1.12 -> v0.1.14
Updating tracing-subscriber v0.2.10 -> v0.2.11
```
In particular, the `tracing-core` update picks up upstream change
tokio-rs/tracing#908, which fixes a bug where filtering would fail to
take the fastest fast path in many cases. This time, there's a slight,
but actually noticeable, latency reduction in the proxy benchmarks:
Signed-off-by: Eliza Weisman <[email protected]>
Closed
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.
Motivation
Currently, when rebuilding the interest cache, the max level is
calculated by tracking a max level, and comparing it with each active
Subscriber's max level hint, and setting the max value to the hint ifthe hint is higher than the current value.
This is correct. However, the max level in this calculation starts at
TRACE. This means that regardless of what any subscriber returns forits hint, after rebuilding the interest cache, the max level will
always be
TRACE. This is wrong — it means that the fast path willnot be taken in may cases where it should be.
The max level calculation was started at
TRACErather thanOFF,because when this code was written with it starting at
OFF, all thetests broke, because the test subscribers don't provide hints. This was
the incorrect solution to that problem, however. This caused the tests
to break because we were ignoring all
Nonehints, and not changingthe current max value when a subscriber returns
None. This means thatif all subscribers returned
Nonefor their max level hint, the maxwould remain
OFF. However, what we should have done is assume thatif a subscriber doesn't provide a hint, it won't be filtering based on
levels, and assume that the max level is
TRACEfor that subscriber.Whoopsie!
Solution
Now, the max level should be calculated correctly for subscribers that
do provide hints, and should still be
TRACEif a subscriber does nothave a hint.
I've also added new tests to ensure that the global max level filter is
used when provided, by asserting that
enabledis not called with spansthat would be excluded by the max level. These tests fail on master, but
pass after this change.
Additionally, note that fixing this bug revealed a separate issue in
tracing-subscriber's implementation ofmax_level_hintforEnvFilter. When theEnvFilterincludes directives that filter onspan field values, it will enable all spans with fields with that name,
so that events within the span can be enabled up to the filtering
directive's level. This may not be the ideal behavior, but it's what
we're doing currently, and we have tests for it. Therefore, it was
necessary to change the
max_level_hintimplementation to take thisinto account by always returning
TRACEwhen there are field valuefilters.
That means that this branch requires #907 order for the
tracing-subscribertests to pass.Fixes: #906
Signed-off-by: Eliza Weisman [email protected]