The `tracing-mock` crate provides a mock collector (and a subscriber for
use by the tests in the `tracing-subscriber` crate) which is able to
make assertions about what diagnostics are emitted.
These assertions are defined by structs that match on events, span, and
their fields and metadata. The structs that matched these objects have
been called, up until now, mocks, however this terminology may be
misleading, as the created objects don't mock anything.
There were two different names for similar functionality with `only()`
and `done()` on fields and collectors/subscribers respectively. Using a
single name for these may make it easier to onboard onto `tracing-mock`.
To reduce confusion, these structs have been split into two categories:
mocks and expectations.
Additionally, the `done()` function on the `Collector` and `Subscriber`
mocks has been replaced with `only()`. This matches the similar function
for `ExpectedField`, and may be more intuitive.
The mocks replace some component in the tracing ecosystem when a library
is under test. The expectations define the assertions we wish to make
about traces received by the mocks.
Mocks (per module):
* collector - `MockCollector`, no change
* subscriber - `MockSubscriber`, renamed from `ExpectSubscriber`
Expectations (per module):
* event - `ExpectedEvent`, renamed from `MockEvent`
* span - `ExpectedSpan`, renamed from `MockSpan`
* field - `ExpectedField` and `ExpectedFields`, renamed from `MockField`
and `Expected`. Also `ExpectedValue` renamed from `MockValue`.
* metadata - `ExpectedMetadata`, renamed from `Expected`
Refs: #539
The `tracing-subscriber` module `tests::support` included functionality
to mock a layer (via the `Layer` trait). This code depends on
some items from `tracing_mock::collector` which should otherwise not be
public.
This change moves the mocking functionality inside `tracing-mock` behind
a feature flag. Allowing the `Expect` enum and `MockHandle::new` from
`tracing_mock::collector` to be made `pub(crate)` instead of `pub`.
Since it's now used from two different modules, the `Expect` enum has
been moved to its own module.
This requires a lot of modifications to imports so that we're not doing
wildcard imports from another crate (i.e. in `tracing-subscriber`
importing wildcards from `tracing-mock`).
This PR is based on @hds' PR #2369, but modified to track renamings. I
also deleted all the doc comments temporarily because updating them was
a lot of work and I need to get a release of `tracing-subscriber` out
first.
Closes: #2359
## Motivation
Currently, when using the `Layer` impl for `Option<S: Layer<...>>`, the
`Layer::max_level_hint` returns `Some(LevelFilter::OFF)`. This was
intended to allow totally disabling output in the case where a
`Subscriber` is composed entirely of `None` `Layer`s. However, when
other `Layer`s *do* exist but return `None` from their `max_level_hint`
implementations to indicate that they don't care what the max level is,
the presence of a single `None` layer will globally disable everything,
which is not the wanted behavior.
Fixes#2265
## Solution
This branch introduces a special downcast marker that can be used to
detect when a `Layer` in a `Layered` is `None`. This allows the
`pick_level_hint` method to short-circuit when a `Layer` implementation
which is `None` returns `Some(LevelFilter::OFF)` from its
`max_level_hint` if the other half of the `Layered` is not `None`. The
tests I added should be pretty thorough!
Additionally, the downcast marker is special-cased in the `reload`
`Layer`. Normally, this `Layer` doesn't support downcasting, but it can
in the case of the special marker value.
Co-authored-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Like for `Subscriber` and `Layer`, allow per-layer `Filter`s to filter
based on event fields.
## Solution
Add `Filter::event_enabled`, plumb it through the combinator
implementations, and call it from `Filtered`.
The bit I'm the least confident about is the check in `Registry`'s
implementation, but I *think* it matches what `event` is doing and
everything seems to function correctly.
## Motivation
When using a `reload` layer, the fast-path current level check doesn't
work, as the `max_level_hint` is just `None`, which `rebuild_interest`
interprets as `TRACE`
## Solution
Pass through to the underlying layer/filter. On poisons, when already
panicking, just return `None`
## Motivation
These are incorrect: currently, when you have a `None` layer, the `None`
hint it returns causes the default `TRACE` to win, which is inaccurate.
Similarly, `Vec` should default to `OFF` if it has no `Layer`s in it
## Solution
Change the default hints to `Some(OFF)`
Co-authored-by: Eliza Weisman <eliza@buoyant.io>
This fixes a Clippy lint for explicitly calling `drop` on a value
without a `Drop` impl, and a lint for `let` bindings whose
value is `()`.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
The `reload` layer doesn't (and can't) implement downcasting correctly,
which breaks certain `Layer`s which require downcasting (such as
`tracing-opentelemetry`'s `OpenTelemetryLayer`).
## Solution
Most usages of `reload` (including mine) are just to change a `Filter`,
so this PR implements `Filter` on the `reload::Layer` type to allow
users to not need to wrap the whole `Filtered` layer. Another advantage
of this is that the common-case critical sections are shortened
Co-authored-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Allow filter layers to filter on the contents of events (see #2007).
## Solution
This branch adds a new `Subscriber::event_enabled` method, taking an
`Event` and returning `bool`. This is called before the
`Subscriber::event` method, and if it returns `false`,
`Subscriber::event` is not called.
For simple subscriber (e.g. not using `Layer`s), the `event_enabled`
method is not particulary necessary, as the subscriber can just skip the
`event` call. However, this branch also adds a new
`Layer::event_enabled` method, with the signature:
```rust
fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, S>) -> bool;
```
This is called before `Layer::on_event`, and if `event_enabled`
returns `false`, `on_event` is not called (nor is `Subscriber::event`).
This allows filter `Layer`s to filter out an `Event` based on its
fields.
Closes#2007
## Motivation
Currently, there is a potential namespace resolution issue when calling
`EnvFilter` methods that have the same name in the `Filter` and
`Layer` traits (such as `enabled` and `max_level_hint`). When both
`Filter` and `Layer` are in scope, the method resolution is
ambiguous.
See https://github.com/tokio-rs/tracing/pull/1983#issuecomment-1088984580
## Solution
This commit solves the problem by making the inherent method versions of
these methods public. When the traits are in scope, name resolution will
always select the inherent method prefer`entially, preventing the name
clash.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Depends on #2028
## Motivation
In many cases, it is desirable to have a variable number of `Layer`s
at runtime (such as when reading a logging configuration from a config
file). The current approach, where types implementing `Layer` are
composed at the type level into `Layered` layers, doesn't work well
when the number of layers varies at runtime.
## Solution
To solve this, this branch adds a `Layer` implementation for
`Vec<L> where L: Layer`. This allows variable-length lists of
layers to be added to a subscriber. Although the impl for `Vec<L>`
requires all the layers to be the same type, it can also be used in
onjunction with `Box<dyn Layer<S> + ...>` trait objects to
implement a variable-length list of layers of multiple types.
I also wrote a bunch of docs examples.
## Notes
Alternatively, we could have a separate type defined in
`tracing-subscriber` for a variable-length list of type-erased
`Layer`s. This would have one primary usability benefit, which is
that we could have a `push` operation that takes an `impl Layer`
and boxes it automatically. However, I thought the approach used
here is nicer, since it's based on composing together existing
primitives such as `Vec` and `Box`, rather than adding a whole new API.
Additionally, it allows avoiding the additional `Box`ing in the case
where the list consists of layers that are all the same type.
Closes#1708
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
... instead of `#[path = ""]` importing it everywhere.
Make sure to use a diff review tool that understands file renaming 😅
(GitHub's diff view does.)
## Motivation
Transparency: I want to use the mocking functionality in the development
of a tracing component out-of-tree.
Additionally, this reduces the use of `#[path] mod` and file
multiple-inclusion, which aren't that great of a practice.
## Solution
The tracing test support module was already well self-contained, due to
being `#[path] mod` used in multiple places. As such, extracting it to
its own crate is rather mechanical, with no surprising blockers.
We additionally move the tracing-futures support module contents into
tracing_mock, for convenience. The one function which relies on
tokio-test is made optional.
It's a reasonable result for this functionality to stay unpublished, and
only used inside the repo, but pulling it out into a directly reusable
chunk instead of abusing the module system to reuse it via
multiple-inclusion is an improvement to code structure and
modularization.
## Motivation
Filtering by span and field requires using `EnvFilter` rather than
`Targets`. Per-layer filtering requires the `Filter` trait, which
`EnvFilter` does not implement.
## Solution
Implement the `Filter` trait for `EnvFilter`. PR #1973 adds additiional
methods to the `Filter` trait, which are necessary for `EnvFilter` to
implement dynamic span filtering. Now that those methods are added, we
can provide a `Filter` impl for `EnvFilter`.
In addition, we changed the globally-scoped `thread_local!` macro to use
a `ThreadLocal` struct as a field, so that multiple `EnvFilter`s used as
per-layer filters don't share a single span scope.
Fixes#1868
Follow-up on #1973
Co-authored-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
In some cases, it can be useful to express a more complex filtering
behavior by composing multiple filters. This is especially useful when
re-using the same logic in multiple filters.
## Solution
This branch adds a new `FilterExt` extension trait with combinators for
composing filters. The current set of combinators are `And` (enables
spans/events that are enabled by *both* filters), `Or` (enables any span
or event enabled by *either* filter), and `Not` (negate the output of a
filter).
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Backports #1648 from `master`.
Depends on #1649
## Motivation
Presently, the `tracing-subscriber` crate requires the Rust standard
library and doesn't build with `#![no_std]` targets. For the most part,
this is fine, as much of `tracing-subscriber` inherently depends on
`std` APIs.
However, `tracing-subscriber` also contains some key abstractions that
are necessary for interoperability: the `Layer` and `LookupSpan`
traits. Since these traits are in `tracing-subscriber`, `no-std` users
cannot currently access them.
Some of the other utilities in this crate, such as the field visitor
combinators, may also be useful for `#![no_std]` projects.
## Solution
This branch adds "std" and "alloc" feature flags to
`tracing-subscriber`, for conditionally enabling `libstd` and
`liballoc`, respectively. The `registry`, `fmt`, `EnvFilter`, and
`reload` APIs all require libstd, and cannot be implemented without it,
but the core `Layer` and `LookupSpan` traits are now available with
`#![no_std]`.
Fixes#999
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
I'm trying to implement a `Layer` that has something very similar to
tracing-error's
[`WithContext`](66cd79f72a/tracing-error/src/layer.rs (L32))
to support erasing types and getting access to the current span's state.
To do that, I implement `Layer::downcast_raw` in [the same way that
tracing-error
does](66cd79f72a/tracing-error/src/layer.rs (L55-L63)).
This works great when the layer is not filtered. However, once I filter
the layer
```rust
let filter = tracing_subscriber::filter::Targets::new().with_default(tracing::Level::INFO);
let layer = MyLayer::new();
tracing_subscriber::registry().with(layer.with_filter(filter)).init();
```
I'm not able to get a `WithContext` instance anymore, because `Filtered`
[handles `downcast_raw`, and doesn't forward
it](66cd79f72a/tracing-subscriber/src/filter/layer_filters.rs (L379-L391))
to `MyLayer::downcast_raw`.
## Solution
If `Filtered::downcast_raw` does not know how to handle the given type,
forward it to the wrapped layer's `Layer::downcast_raw` implementation.
Fixes#1618
The `Layer::on_layer` method on `Layer` was added in PR #1523. PR #1536,
which added `Layer` implementations to `Box<dyn Layer<...> + ...>` and
`Arc<dyn Layer<...> + ...>`, merged prior to #1523. However, when
merging #1523, I didn't think to update the `Layer` impl for `Box`ed and
`Arc`ed layers to forward `on_layer` to the inner `Layer`. This means
that when a `Layer` is wrapped in an `Arc` or a `Box`, the `on_layer`
method never gets called.
When per-layer filters are in use, the `on_layer` method is necessary to
ensure the filter is registered with the inner subscriber and has a
valid ID. This bug means that when per-layer filters are wrapped in a
`Box` or `Arc`, they won't be registered, and per-layer filtering
breaks.
This PR fixes the bug by adding `on_layer` implementations to the
`Layer` impls for `Arc`ed and `Box`ed layers. I also added some tests
--- thanks to @Noah-Kennedy for the original repro that these were based
on (https://github.com/tokio-rs/tracing/issues/1563#issuecomment-922014777).
I also added a nicer debug assertion to `Filtered` for cases where
`Layer` impls don't call `on_layer`, so that this fails less confusingly
in the future.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Currently, when evaluating `register_callsite` for a stack containing
per-layer filters, the intermediate `Interest` from combining the per
layer filters' `Interest`s is stored in the thread-local `FilterState`.
When all per-layer filters have been evaluated, we reach the `Registry`,
which clears the `FilterState` and bubbles the `Interest` back up.
However, when a _global_ filter in the stack returns `Interest::never`,
we short-circuit, and don't reach the `Registry`. This means the
`Interest` state is not cleared.
This branch adds code in `Layered` to ensure the per-layer filter state
is cleared when a global filter short circuits `Interest` evaluation.
This fixes#1563.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Currently, filtering with `Layer`s is always _global_. If a `Layer`
performs filtering, it will disable a span or event for _all_ layers
that compose the current subscriber. In some cases, however, it is often
desirable for individual layers to see different spans or events than
the rest of the `Layer` stack.
Issues in other projects, such as tokio-rs/console#64 and
tokio-rs/console#76, linkerd/linkerd2-proxy#601,
influxdata/influxdb_iox#1012 and influxdata/influxdb_iox#1681,
jackwaudby/spaghetti#86, etc; as well as `tracing` feature requests like
#302, #597, and #1348, all indicate that there is significant demand for
the ability to add filters to individual `Layer`s.
Unfortunately, doing this nicely is somewhat complicated. Although a
naive implementation that simply skips events/spans in `Layer::on_event`
and `Layer::new_span` based on some filter is relatively simple, this
wouldn't really be an ideal solution, for a number of reasons. A proper
per-layer filtering implementation would satisfy the following
_desiderata_:
* If a per-layer filter disables a span, it shouldn't be present _for
the layer that filter is attached to_ when iterating over span
contexts (such as `Context::event_scope`, `SpanRef::scope`, etc), or
when looking up a span's parents.
* When _all_ per-layer filters disable a span or event, it should be
completely disabled, rather than simply skipped by those particular
layers. This means that per-layer filters should participate in
`enabled`, as well as being able to skip spans and events in
`new_span` and `on_event`.
* Per-layer filters shouldn't interfere with non-filtered `Layer`s.
If a subscriber contains layers without any filters, as well as
layers with per-layer filters, the non-filtered `Layer`s should
behave exactly as they would without any per-layer filters present.
* Similarly, per-layer filters shouldn't interfere with global
filtering. If a `Layer` in a stack is performing global filtering
(e.g. the current filtering behavior), per-layer filters should also
be effected by the global filter.
* Per-layer filters _should_ be able to participate in `Interest`
caching, _but only when doing so doesn't interfere with
non-per-layer-filtered layers_.
* Per-layer filters should be _tree-shaped_. If a `Subscriber` consists
of multiple layers that have been `Layered` together to form new
`Layer`s, and some of the `Layered` layers have per-layer filters,
those per-layer filters should effect all layers in that subtree.
Similarly, if `Layer`s in a per-layer filtered subtree have their
_own_ per-layer filters, those layers should be effected by the union
of their own filters and any per-layer filters that wrap them at
higher levels in the tree.
Meeting all these requirements means that implementing per-layer
filtering correctly is somewhat more complex than simply skipping
events and spans in a `Layer`'s `on_event` and `new_span` callbacks.
## Solution
This branch has a basic working implementation of per-layer filtering
for `tracing-subscriber` v0.2. It should be possible to add this in a
point release without a breaking change --- in particular, the new
per-layer filtering feature _doesn't_ interfere with the global
filtering behavior that layers currently have when not using the new
per-layer filtering APIs, so existing configurations should all behave
exactly as they do now.
### Implementation
The new per-layer filtering API consists of a `Filter` trait that
defines a filtering strategy and a `Filtered` type that combines a
`Filter` with a `Layer`. When `enabled` is called on a `Filtered` layer,
it checks the metadata against the `Filter` and stores whether that
filter enabled the span/event in a thread-local cell. If every per-layer
filter disables a span/event, and there are no non-per-layer-filtered
layers in use, the `Registry`'s `enabled` will return `false`.
Otherwise, when the span/event is recorded, each `Filtered` layer's
`on_event` and `new_span` method checks with the `Registry` to see
whether _it_ enabled or disabled that span/event, and skips passing it
to the wrapped layer if it was disabled. When a span is recorded, the
`Registry` which filters disabled it, so that they can skip it when
looking up spans in other callbacks.
A new `on_layer` method was added to the `Layer` trait, which allows
running a callback when adding a `Layer` to a `Subscriber`. This allows
mutating both the `Layer` and the `Subscriber`, since they are both
passed by value when layering a `Layer` onto a `Subscriber`, and a new
`register_filter` method was added to `LookupSpan`, which returns a
`FilterId` type. When a `Filtered` layer is added to a subscriber that
implements `LookupSpan`, it calls `register_filter` in its `on_layer`
hook to generate a unique ID for its filter. `FilterId` can be used to
look up whether a span or event was enabled by the `Filtered` layer.
Internally, the filter results are stored in a simple bitset to reduce
the performance overhead of adding per-layer filtering as much as
possible. The `FilterId` type is actually a bitmask that's used to set
the bit corresponding to a `Filtered` layer in that bitmap when it
disables a span or event, and check whether the bit is set when querying
if a span or event was disabled. Setting a bit in the bitset and testing
whether its set is extremely efficient --- it's just a couple of bitwise
ops. Additionally, the "filter map" that tracks which filters disabled a
span or event is just a single `u64` --- we don't need to allocate a
costly `HashSet` or similar every time we want to filter an event. This
*does* mean that we are limited to 64 unique filters per
`Registry`...however, I would be _very_ surprised if anyone _ever_
builds a subscriber with 64 layers, let alone 64 separate per-layer
filters.
Additionally, the `Context` and `SpanRef` types now also potentially
carry `FilterId`s, so that they can filter span lookups and span
traversals for `Filtered` layers. When `Filtered` layers are nested
using the `Layered`, the `Context` _combines_ the filter ID of the inner
and outer layers so that spans can be skipped if they were disabled by
either.
Finally, an implementation of the `Filter` trait was added for
`LevelFilter`, and new `FilterFn` and `DynFilterFn` structs were added
to produce a `Filter` implementation from a function pointer or closure.
### Notes
Some other miscellaneous factors to consider when reviewing this change
include:
* I did a bit of unrelated refactoring in the `layer` module. Since we
were adding more code to the `Layer` module (the `Filter` trait), the
`layer.rs` file got significantly longer and was becoming somewhat
hard to navigate. Therefore, I split out the `Context` and `Layered`
types into their own files. Most of the code in those files is the
same as it was before, although some of it was changed in order to
support per-layer filtering. Apologies in advance to reviewers for
this...
* In order to test this change, I added some new test-support code in
`tracing-subscriber`. The `tracing` test support code provides a
`Subscriber` implementation that can be configured to expect a
particular set of spans and events, and assert that they occurred as
expected. In order to test per-layer filtering, I added a new `Layer`
implementation that does the same thing, but implements `Layer`
rather than `Subscriber`. This allows testing per-layer filter
behavior in the same way we test global filter behavior. Reviewers
should feel free to just skim the test the test support changes, or
skip reviewing them entirely.
## Future Work
There is a bunch of additional stuff we can do once this change lands.
In order to limit the size of this PR, I didn't make these changes yet,
but once this merges, we will want to consider some important follow
up changes:
* [ ] Currently, _only_ `tracing-subscriber`'s `Registry` is capable of
serving as a root subscriber for per-layer filters. This is in
order to avoid stabilizing a lot of the per-layer filtering
design as public API without taking the time to ensure there are
no serious issues. In the future, we will want to add new APIs to
allow users to implement their own root `Subscriber`s that can
host layers with per-layer filtering.
* [ ] The `EnvFilter` type doesn't implement the `Filter` trait and thus
cannot currently be used as a per-layer filter. We should add an
implementation of `Filter` for `EnvFilter`.
* [ ] The new `FilterFn` and `DynFilterFn` types could conceivably _also_
be used as global filters. We could consider adding `Layer`
implementations to allow them to be used for global filtering.
* [ ] We could consider adding new `Filter` implementations for performing
common filtering predicates. For example, "only enable spans/events
with a particular target or a set of targets", "only enable spans",
"only enable events", etc. Then, we could add a combinator API to
combine these predicates to build new filters.
* [ ] It would be nice if the `Interest` system could be used to cache
the result of multiple individual per-layer filter evaluations, so
that we don't need to always use `enabled` when there are several
per-layer filters that disagree on whether or not they want a
given span/event. There are a lot of unused bits in `Interest`
that could potentially be used for this purpose. However, this
would require new API changes in `tracing-core`, and is therefore
out of scope for this PR.
Closes#302Closes#597Closes#1348
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Currently we can't run
```bash
cargo test -p tracing-subscriber --no-default-features
```
successfully, because there are a bunch of tests for feature flagged
APIs that are always enabled.
## Solution
This commit adds feature flags to the modules and/or individual test
cases that test feature-flagged APIs.
There are still a few doctests that use feature-flagged APIs, and will
fail with `--no-default-features`. These are primarily the examples for
various `Layer::context` methods that rely on `LookupSpan`, and use the
`Registry` type, as it's the only subscriber that *implements*
`LookupSpan`. We could consider changing these examples, either by
removing the actual use of the layers in them, or by changing them to
use a mocked-out version of the registry. However, I think it's nicer to
show how the API would be used in real life. Perhaps we should just run
```bash
cargo test -p tracing-subscriber --no-default-features--tests --lib
```
to ignore doctests when testing without default features.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This branch changes the `field_filter_events` and `field_filter_spans`
tests in `tracing-subscriber` to be ignored by default, as they often
fail spuriously on CI.
The tests can still be run using
```shell
$ RUSTFLAGS="--cfg flaky_tests" cargo test
```
or similar.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
PRs #1247, #1248, and #1251 improve `tracing`'s behavior for the `log`
crate's `log_enabled!` macro when a max-level hint is set. However, this
*doesn't* get us correct behavior when a particular target is not
enabled but the level is permitted by the max-level filter. In this
case, `log_enabled!` will still return `true` when using `LogTracer`,
because it doesn't currently call `Subscriber::enabled` on the current
subscriber in its `Log::enabled` method. Instead, `Subscriber::enabled`
is only checked when actually recording an event.
This means that when a target is disabled by a target-specific filter
but it's below the max level, `log::log_enabled!` will erroneously
return `true`. This also means that skipping disabled `log` records in
similar cases will construct the `log::Record` struct even when it isn't
necessary to do so.
This PR improves this behavior by adding a call to `Subscriber::enabled`
in `LogTracer`'s `Log::enabled` method. I've also added to the existing
tests for filtering `log` records to ensure that we also handle the
`log_enabled!` macro correctly.
While I was here, I noticed that the `Log::log` method for `LogTracer`
is somewhat inefficient --- it gets the current dispatcher *three*
times, and checks `enabled` twice. Currently, we check if the event
would be enabled, and then call the`format_trace` function, which *also*
checks if the event is enabled, and then dispatches it if it is. This is
not great. :/ I fixed this by moving the check-and-dispatch inside of a
single `dispatcher::get_default` block, and removing the duplicate
check.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
The `FmtCollector` type is missing a `Collect::max_level_hint
method that forwards the inner stack's max level hint.
This fixes that, and adds tests.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Fixes part of #898 where creating multiple registries made them fight
over the thread_local-stored span stacks.
## Solution
Use the `thread_local` crate which has a tighter scope.
I believe @hawkw has a test that fails without this PR.
This removes the test `field_filter_events` in
`tracing-subscriber/tests/filter.rs` as it appears to be a duplicate of
`field_filter_events` in `tracing-subscriber/tests/field_filter.rs` (see
discussion at
https://github.com/tokio-rs/tracing/pull/711#issuecomment-626365124).
* subscriber: add less-verbose configuration APIs
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* even nicer easymode
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* wip## Motivation
Users have said fairly frequently that configuring new subscribers in an
application is unnecessarily verbose and confusing. We should try to
make this nicer, especially as it's a common "on ramp" for new `tracing`
users.
## Solution
This branch adds new APIs, inspired by `tonic` and `warp`, that should
make setting up a subscriber a little less verbose. This includes:
- Many modules in `tracing-subscriber` now expose free functions
that construct default instances of various types. This makes
configuring subscribers using these types more concise, a la `warp`.
- An extension trait for adding `.set_default`, `.init`, and `.try_init`
methods to subscribers. This generalizes the similar functions on
`fmt`'s `SubscriberBuilder` to work with other subscribers.
All the old APIs are still left as they were previously. The new APIs
just provide shorthand for them.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Recent changes to `tracing-subscriber` (#580 and #583) introduced some
regressions in filter directive selection. In particular, directive
selection appears to depend on the _order_ in which directives were
specified in a env filter string, or on the order in which they were
added using `add_directive`, rather than on specificity.
This regression is due to the change that switched the storage of filter
directives in `DirectiveSet`s from a `BTreeSet` to a `Vec`. Previously,
the `DirectiveSet::add` and `DirectiveSet::extend` methods both relied
on the inherent ordering of `BTreeSet`s. After changing to a `Vec`, the
`DirectiveSet::add` method was changed to use a binary search to find
the correct position for each directive, and use `Vec::insert` to add
the directive at that position. This is correct behavior. However, the
`Extend` (and therefore also `FromIterator`) implementations _did not
use_ `add_directive` --- instead, they simply called `extend` on the
underlying data structure. This was fine previously, when we could rely
on the sorted nature of `BTreeSet`s, but now, it means that when a
directive set is created from an iterator (such as when parsing a string
with multiple filter directives!), the ordering of the directive set is
based on the iterator's ordering, rather than sorted.
We didn't catch this bug because all of our tests happen to put the
least specific directive first. When the change to using a `Vec` broke
all the existing tests, I was able to "fix" them simply by adding a
`.rev()` call to the iterator, based on the incorrect assumption that we
were always using the sorted insertion order, and that the test failures
were simply due to the binary search inserting in the opposite order as
`BTreeSet`. Adding the `.rev()` call caused issue #591, where a
`DirectiveSet` built by calls to `add_directive` (which _does_ obey the
correct sorting) was not selecting the right filters, since we were
reversing the ordering and picking the least specific directive first.
## Solution
I've changed the `DirectiveSet::extend` method to call `self.add` for
each directive in the iterator. Now, they are inserted at the correct
position. I've also removed the call to `.rev()` so that we iterate
over the correctly sorted `DirectiveSet` in most-specific-first order.
I've added new tests to reproduce both issue #591 and issue #623, and
confirmed that they both fail prior to this change.
Fixes#591Fixes#623
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This PR fixes all reported clippy lints. In most cases I have made the
suggested changes. In a few cases (e.g., `blacklisted_name` and
`cognitive_complexity`) I've just silenced the warning.
I can make stylistic changes or discard some of the lint fixes if
preferred.
This branch introduces:
- A registry build atop of https://github.com/hawkw/sharded-slab. Layers
are expected to consume this registry through the traits `SpanData`,
`LookupSpan`, and `LookupMetadata`. Layer-specific data, such as
formatted spans and events, are stored in the `Extensions` typemap. Data
is writable via the `ExtensionsMut` view struct of the typemap. This
enables layers to read and write data that they are specifically
interested in.
- The `tracing_subscriber::fmt::Subscriber` has been re-implemented in
terms of `tracing_subscriber::registry::Registry` and
`tracing_subscriber::fmt::Layer`.
- The event/field formatters have been modified (in a non-backwards
compatible way) to accept a `tracing_subscriber::fmt::FmtContext`. A
similar structure existed in `tracing_subscriber::fmt::Subscriber`, but
it was not publicly exposed.
Resolves#135Resolves#157Resolves#391
Signed-off-by: David Barsky <me@davidbarsky.com>
Coauthored-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Entering twice in the same span causes the span to be lost after the
second span got droped, see #358
## Solution
Duplicate spans are tracked in the `CONTEXT` thread local stack and
ignored when finding the current span id. Spans are always pushed on the
`CONTEXT` stack. This way, when a span is dropped, its ref count
reflects the content of the thread local
Fixes#358
## Motivation
Currently, the `tracing-subscriber` `EnvFilter` does not properly enable
events that originate from the `tracing-log` `LogTracer` adapter. This
is because those events are supposed to be filtered only by `enabled`,
and will not generate proper `register_callsite` metadata. `EnvFilter`'s
`enabled` method will assume that an event was not enabled statically,
since `enabled` wouldn't have been called if the callsite was given the
`Always` interest. However, this doesn't take `tracing-log` into
account.
## Solution
I've changed `EnvFilter` to always check against static filters in
`enabled` if the dynamic filters don't enable a given metadata. This
fixes the filtering of `tracing-log` events. I've also added tests that
fail against the current master.
This fixes the regression reported by @samscott89.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This branch renames `Filter` to `EnvFilter` and deprecates the previous
name, as suggested in https://github.com/tokio-rs/tracing/pull/336#pullrequestreview-286356811.
This should make the difference between an `EnvFilter` and a
`LevelFilter` clearer.
The `filter` feature has also been deprecated in favor of `env-filter`.
Co-Authored-By: Benjamin Saunders <ben.e.saunders@gmail.com>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
`tracing-subscriber` currently relies on `PartialOrd` and `Ord`
implementations for the `Directive` and `StaticDirective` types. These
are used for determining the order in which the directives that apply to
a span/event are iterated over when determining whether that span or
event is enabled, so that the most specific directives are checked
first.
Originally, the directives were stored in `Vec`s, and the `PartialOrd`
implementations were used to call [`Vec::sort_unstable`][1] on those
`Vec`s. We would then iterate over the sorted `Vec`. However, in order
to avoid having to re-sort the `Vec` every time a new directive is
inserted (as part of a potential future feature), I decided to store the
directives in [`BTreeSet`][2]s rather than `Vec`s.
Using `BTreeSet` introduces some problems. `Vec::sort_unstable` does not
require a total ordering, so the `PartialOrd` impls were based only on
comparing the length of the targets of the directive and on other
properties such as whether a span name is specified. If the directives
were the same "shape" and their targets were of the same length, then
the `PartialOrd` impls would consider them "equal". When we used
`sort_unstable`, this was fine. A `BTreeSet`, however, is a _set_ — if
two items are considered equal, the second is considered a duplicate of
the first and will not be present in the set.
@Ralith reported a bug where a filter string like
`common=trace,server=trace` would set the level for the `common` target
to `trace`, but not set the level for the `server` target. I was
mystified by this behavior — similar filters worked fine for me — until
I realized that "common" and "server" have the same number of
characters. The issue was that the two directives were considered
"equal" by the `PartialOrd` impl, and the resultant `BTreeSet` only
contained the first one.
[1]: https://doc.rust-lang.org/std/vec/struct.Vec.html#method.sort_unstable
[2]: https://doc.rust-lang.org/std/collections/struct.BTreeSet.html
## Solution
This branch fixes the bug by rewriting the `PartialOrd` impls for
`Directive` and `StaticDirective` to fall back to other forms of
ordering (such as comparing targets lexicographically) when the metrics
the previous impls used (e.g. target length) are the same.
Additionally, I've added some new tests for cases where two directives
are equal on one or more ordering metrics, and some debug assertions
that the `PartialOrd` impls behave correctly.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This adds a test that when a field value is recorded after a span is
created, and the new value changes the filter level for the span, the
filter updates accordingly.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This branch moves the field filter tests to their own test file,
separate from the tests for target filters which include directives that
match all callsites. This should fix the occasional flakiness in the
field-filtering tests when the tests are executed concurrently in a
particular order.
I've run the tests in a loop for about 4 minutes on my machine, and I
haven't seen any flakiness so far.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Currently, `tracing-fmt` provides an implementation of `env_logger`-like
filtering directives. However, there are two issues:
1. The implementation is specific to `tracing-fmt` and does not work
with other subscribers.
2. Filtering dynamically based on field values is not supported.
Now that the `Layer` type has been added to `tracing-subscriber` (see
#136), we can implement filtering generically, as a `Layer` that can
wrap other `Subscriber`s to provide a particular filtering strategy.
## Solution
This branch re-implements the `env_logger` style filtering in
`tracing-fmt` as a `tracing-subscriber::Layer`. The new `Layer` type
implements dynamic filtering on span fields, in addition to the
functionality of the `tracing-fmt` implementation. I've also added a
wrapper type to support runtime reloading of a `Layer`, similarly to
the `Reload` type in `tracing-fmt::filter`, but more general.
Finally, I've added some tests and an interactive demo for the new
filtering. The example runs a simple web service with a load generator,
and allows users to explore the `tracing-fmt` output from the example
service by dynamically reloading the filter settings.
## Notes
This is admittedly a pretty large branch, but I think it makes the
most sense to merge everything together, since the example requires
both the filter implementation *and* the reload layer. I've tried to
make sure the most complex bits of the filtering code has comments
describing the implementation, but please let me know if anything
is unclear.
Also, there is a lot of room for potential performance improvements
in the current filter implementation. I've left comments on some code
that I think could probably be made more efficient. Ideally, though,
any future optimization work ought to be guided by benchmarks as well.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
