* subscriber: traverse SpanStack on pop
In cases where spans are not popped in FILO (first-in-last-out) order,
`pop` would return `None`. This would cause issues in `Registry` where
spans that are exited out of order would not be closed properly.
Fixes#495
* PR comments
* Import super deps explicitly
* Use ClosingLayer in test
* s/pub(crate) mod tests/mod tests
* subscriber: compilation errors w/ nodefault + ansi
when compiling with -no-default-features --features "ansi", the
following compilation error would come up:
```
error[E0599]: no method named `with_env_filter` found for type `fmt::SubscriberBuilder` in the current scope
--> tracing-subscriber/src/fmt/mod.rs:663:10
|
146 | / pub struct SubscriberBuilder<
147 | | N = format::DefaultFields,
148 | | E = format::Format<format::Full>,
149 | | F = LevelFilter,
... |
153 | | inner: LayerBuilder<Registry, N, E, W>,
154 | | }
| |_- method `with_env_filter` not found for this
...
663 | .with_env_filter(crate::EnvFilter::from_default_env())
| ^^^^^^^^^^^^^^^ method not found in `fmt::SubscriberBuilder`
```
* subscriber: compilation errors w/ nodefault + fmt
when compiling with -no-default-features --features "fmt", the following
compilation error would come up:
```
error[E0107]: wrong number of type arguments: expected 2, found 1
--> tracing-subscriber/src/fmt/format/mod.rs:603:30
|
603 | impl<'a, N> fmt::Display for FullCtx<'a, N>
| ^^^^^^^^^^^^^^ expected 2 type arguments
```
* subscriber: compilation errors w/ nodefault + env-filter + fmt
when compiling with -no-default-features --features "env-filter fmt", the
following compilation error would come up:
```
error[E0277]: the trait bound `for<'lookup> <S as registry::LookupSpan<'_>>::Data: registry::LookupSpan<'lookup>` is not satisfied
--> tracing-subscriber/src/fmt/format/mod.rs:304:44
|
279 | ) -> fmt::Result {
| - help: consider further restricting the associated type: `where for<'lookup> <S as registry::LookupSpan<'_>>::Data: registry::LookupSpan<'lookup>`
...
304 | write!(writer, "{} {}", fmt_level, fmt_ctx)?;
| ^^^^^^^ the trait `for<'lookup> registry::LookupSpan<'lookup>` is not implemented for `<S as registry::LookupSpan<'_>>::Data`
|
= note: required because of the requirements on the impl of `std::fmt::Display` for `fmt::format::FmtCtx<'_, S, N>`
= note: required by `std::fmt::Display::fmt`
error[E0593]: closure is expected to take 1 argument, but it takes 2 arguments
--> tracing-subscriber/src/fmt/format/mod.rs:530:18
|
530 | self.ctx.visit_spans(|_, span| {
| ^^^^^^^^^^^ --------- takes 2 arguments
| |
| expected closure that takes 1 argument
```
Closes#494
This fixes the following compilation error:
```
error[E0433]: failed to resolve: use of undeclared type or module `registry`
--> tracing-subscriber/src/layer.rs:844:25
|
844 | S: for<'lookup> registry::LookupSpan<'lookup>,
| ^^^^^^^^ use of undeclared type or module `registry`
error[E0412]: cannot find type `Scope` in this scope
--> tracing-subscriber/src/layer.rs:842:28
|
842 | pub fn scope(&self) -> Scope<'_, S>
| ^^^^^ not found in this scope
error[E0425]: cannot find function, tuple struct or tuple variant `Scope` in this scope
--> tracing-subscriber/src/layer.rs:850:9
|
850 | Scope(scope)
| ^^^^^ help: a local variable with a similar name exists (notice the capitalization): `scope`
```
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 updates all the README links and badges. In particular, it:
* Changes build status badges to GitHub Actions, since we've turned off
the Azure Pipelines CI build,
* Removes Gitter links, since nobody is on Gitter these days and we
probably don't want to point new users to an empty chat room,
* Make Discord links "actually work"
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Added:
- `LookupSpans` implementation for `Layered` (#448)
- `SpanRef::from_root` to iterate over a span's parents from the root
(#460)
- `Context::scope`, to iterate over the current context from the root
(#460)
- `Context::lookup_current`, which returns a `SpanRef` to the current
span's data (#460)
Changed:
- Lifetimes on some new `Context` methods to be less restrictive (#460)
Fixed:
- `Layer::downcast_ref` returning invalid references (#454)
- Compilation failure on 32-bit platforms (#462)
- Compilation failure with ANSI formatters (#438)
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
PR #443 added a `Context::scope` function, as described in issue #427.
In the issue, the desired change was described as follows:
> - The method `FmtContext::visit_spans` should be moved to
> `layer::Context`.
> - The new `layer::Context::visit_spans` should be renamed to
> something along the lines of `parents()`, **and be made to return
> a newtype implementing `std::iter::Iterator`.**
(emphasis mine)
Unfortunately, #443 only implemented the first bullet point — the new
`layer::Context::scope` method was just a copy of the old
`visit_spans`. The branch was merged before a thorough review could
determine that the change made there was incomplete.
## Solution
This branch changes the `Context::scope` function to return an
iterator, as it was supposed to, and rewrites `visit_spans` to consume
that iterator.
Additionally, I've added some new toys:
- `SpanRef::from_root`, which returns an iterator over a span's
parents, starting from the root (rather than from the direct parent
like `SpanRef::parents`)
- `Context::lookup_current`, which returns a `SpanRef` to the current
span's data
- Easier to use lifetimes on a couple of the new `Context` methods
enabled by the "registry" feature (not a breaking change, as these
aren't yet released)
Co-authored-by: David Barsky <me@davidbarsky.com>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Currently tracing-subscriber doesn't compile on 32-bit platforms as
discussed here: https://github.com/hawkw/sharded-slab/issues/9
The underlying issue has been fixed by @hawkw. This pull simply updates
the dependency inside this project. Thanks for your work on this!
## Motivation
Latest master cannot infer types in the `fmt` function.
## Solution
Tell the compiler the result type. Funnily I couldn't reproduce this
directly from `tracing` repo, but when I have `tracing` as a dependency
following it from github, the later versions would not pass `cargo
check`
We used to be on this version
`16fee661ac1f5dd175491e611ff4c08b33c070fa`, and `cargo update` would
break the project.
## Motivation
Currently, `Layer::downcast_raw` constructs a pointer with:
```rust
&self as *const _ as *const ()
```
This is wrong. The method's receiver is already `&self`, so this code
constructs a reference _to_ the `&self` reference, and converts _that_
into a pointer. Since this is not the actual memory address of the
layer, this is invalid.
We didn't catch this because the tests for downcasting layers are
also wrong: they never actually dereference the ref created by
`downcast_ref`. Therefore, if an invalid pointer is returned, the
test can still pass, as long as _any_ pointer is returned.
## Solution
This branch changes the pointer to:
```rust
self as *const _ as *const ()
```
Now, the returned pointer is valid.
In addition, it changes the tests to try and access data through the
returned references. The new tests fail with the current master
implementation of `downcast_ref`, which is correct.
Fixes#453
Currently there are some links that 404 because they contain
a reference to a struct 'struct.Layer.html' which presumably
should be the trait 'layer/trait.Layer.html'.
Signed-off-by: ifeanyi <ify1992@yahoo.com>
## Motivation
What I wanted to achieve: lookup data from a span _outside_ of a
`Layer`/`Subscriber` implementation. (i.e. without having a
`Context<S>`)
What I was trying: get the configured subscriber with
`dispatcher::get_default(...)`, and then downcasting to a `Layered<....,
Registry>`. But I (a) cant get access to the inner `Registry` and (b)
don't have an implementation of `LookupSpan` for `Layered`.
## Solution
Since there was already a `LookupMetadata` impl, this just seemed like
an oversight. So I changed the implementation over.
Note that `LookupMetadata` gets implemented via the blanket impl on
`L: LookupSpan`.
This patch moves the current `FmtContext::visit_spans`
implementation into a new method `layer::Context::scope`, leaving
`visit_spans` itself in place in order to maintain compatibility.
Resolves#427
Signed-off-by: ifeanyi <ify1992@yahoo.com>
## Motivation
This branch fixes several bugs in the `Registry` span close logic, and
adds new tests for these issues.
## Solutions
* Spans not being removed at the end of `on_close`
There is currently a bug in the `Registry` that prevents spans from
being removed, even when all `on_close` callbacks are complete. The test
for this behavior ( `span_is_removed_from_registry`) fails to catch the
bug, since there is a bug in the test as well.
The test asserts that a span extension was dropped after the span
closes. Current, the test uses `subscriber::with_default`, and then
made the assertion _outside_ of the `with_default` block. However, this
was incorrect, as even if the `Registry` fails to drop the span, the
span extension will be dropped when the whole `Registry` itself is
dropped, at the end of the `with_default` block.
This branch fixes the test, and the bug in the close logic. I've changed
the test to use an explicit `Dispatch` to keep the registry alive until
the end of the test. This reveals that the span is _not_ being removed
as it should be.
The reason the span fails to be removed is that the `Drop`
implementation for `CloseGuard` drops the span if the value of the
`CLOSE_COUNT` cell is 0. However, the `if` statement that tests for this
compares the value returned by `Cell::get` with 0. The value returned by
`Cell::get` is the _previous_ value, not the current one after dropping
this guard; if the guard being dropped is the final guard, then the
value returned by `Cell::get` will be 1, rather than 0.
I've fixed this logic, and refactored it slightly to hopefully make it
easier to understand in the future.
Thanks to @jtescher for catching this bug!
* Only the first span being removed at the end of `on_close`
In addition, I've fixed a bug where the remove after close logic would
only work for the _first_ span to close on each thread. This is because
dropping a `CloseGuard` does not currently subtract from CLOSE_COUNT
when it is the final guard. This means that when the next span is
closed, the count will start at 1, rather than 0. I've fixed this by
ensuring that the close count is always decremented, and changed the
tests to close multiple spans.
* Spans removed on the first `try_close`
Finally, there is also an issue where the removal logic is run on
_every_ call to `try_close`, regardless of whether or not the subscriber
actually indicates that the span closes. This means that a span will be
removed from the registry even when there are one or more span handles
that reference it.
This is due to the `start_close` method being called _before_
`Subscriber::try_close` is called. When a close guard is dropped, the
span is currently _always_ removed. However, since we call `start_close`
at the beginning of the `Layered::try_close` method, we may be
decrementing a ref count _without_ closing the span, but the close guard
is unaware of this.
I've fixed this bug by updating the `CloseGuard` struct to track whether
the span is closed. It now has a bool that is set only when the
`Subscriber::try_close` call returns true.
Only creating the `CloseGuard` if `try_close` returns true may seem like
a simpler solution, but that won't work, since the call to `try_close`
may call into another `Layered` subscriber. In order to handle
situations where many layers are nested, we need to construct the
`CloseGuard` for each stack frame before calling into the next one, so
it's necessary to set whether the span is closing only after the call to
`try_close` returns.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This PR removes the deprecated items, notices and aliases in preparation
of releasing tracing-subscriber 0.2.0-alpha.1.
Signed-off-by: David Barsky me@davidbarsky.com
For Registry-backed Layers, this commit introduces a capability where
span deletion is deferred until until all Layers have processed the span
closure notification.
`fmt::Layer::on_record` was looking up extensions using
`FormattedFields<Self>>` when it should have been using
`FormattedFields<N>>`.
Signed-off-by: David Barsky me@davidbarsky.com
With #420, we introduced FmtContext and made it a required parameter on
FormatEvent's primary methods. However, we forgot to export it, making
it impossible to write custom FormatEvent implementations. This PR fixes
that oversight. Thanks to @samscott89 for noticing this!
Signed-off-by: David Barsky me@davidbarsky.com
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>
These benchmarks were originally written for assessing before/after
performance on a branch that was not merged. However, they are probably
generally useful for other fmt subscriber changes (e.g. #420).
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
I thought the boxing errors solution implemented in #400 was equivalent
to the enum solution in
f22bae5a2d,
but the current master doesn't actually work to install the global
`LogTracer`.
I can't figure out why the current cargo features don't end up turning
on [this line][1], but I confirmed with the log example in
4511325b29
that it's not currently working.
[1]: https://github.com/tokio-rs/tracing/blob/master/tracing-subscriber/src/fmt/mod.rs#L452-L453
* subscriber: use InitError enum instead of Box
the Boxing solution while using the feature tracing-log/std didn't actually seem to work
* examples: log compatibility
* fix dependencies
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* fix boxed errors
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* cargo fmt
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Currently, most crates in `tracing` are configured to deny all compiler
warnings when compiling tests. This means that if the compiler reports
any warnings, the build will fail. This can be an issue when changes are
made locally that introduce warnings (i.e. unused code is added, imports
are no longer needed, etc) and a contributor wishes to test an
incomplete state to ensure their changes are on the right path. With
warnings denied, tests will not run if the project contains any
warnings, so contributors must either fix all warnings or disable the
deny attribute. Disabling the deny attribute when making changes locally
has become a fairly common practice, but it's error-prone: sometimes,
the deny attribute is commented out and then accidentally committed.
## Solution
This branch removes all `#![deny(warnings)]` attributes, in order to
allow code with warnings to compile and be tested locally while changes
are in progress. We already have [a CI job][1] that checks for compiler
warnings by trying to compile `tracing` with `RUSTFLAGS="-Dwarnings"`.
If we make this CI job required rather than allowing it to fail, we'll
still be able to ensure that no code with warnings is merged.
Additionally, I've updated all crates to use the same consistent list of
lints to apply in the `#![warn]` attribute. Previously, some crates
warned on more lints than others, which is not great. I've fixed all the
new warnings produced by the additional lints.
* chore: consistent warnings, don't deny locally
* fix warnings from new attributes
* remove warning that no longer exists on nightly
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
Setting `RUST_LOG=target` currently enables only the `ERROR` level,
while it should enable everything.
## Solution
Change the default to `TRACE` if no level is specified
## Motivation
https://github.com/tokio-rs/tracing/pull/385 incorrectly used the
feature flag `tracing_log` when it should have been `tracing-log`. As a
result, you need to specify both in order to make `try_init` initialize
the global logger.
## Solution
Use the correct feature flag
## Motivation
A formatter for JSON output.
## Solution
Enable `json` feature from `tracing-subscriber` crate. Instantiate a new formatter with JSON output:
```rust
let subscriber = FmtSubscriber::builder()
.json()
.with_env_filter(EnvFilter::from_default_env())
.finish();
subscriber::set_global_default(subscriber)?;
```
Closes#218
## Motivation
Currently, when using `tracing-subscriber`'s `Layer` API, it is
necessary for each layer to manage its own storage for per-span data.
Since subscribers are shared concurrently, this means that `Layer`s must
also manage synchronization on this storage. This is easy to get wrong,
and even when it's implemented correctly, having every layer synchronize
separately adds a lot of overhead. Ideally, it should be possible for
state stored by the subscriber to be exposed to `Layer`s.
## Solution:
This branch *starts* on the project of a general-purpose span registry
by adding a new trait, `LookupMetadata`. Subscribers may implement this
trait to allow looking up a span's `Metadata` by ID. If a subscriber
implements this trait, the `layer::Context` type will then allow any
layers wrapping that subscriber to look up metadata by ID. The
`FmtSubscriber` implements this trait.
Future work will be able to an interface for `Subscriber`s to expose
more span data, such as parents, children, and arbitrarily-typed
extensions, to `Layer`s as well.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
The `tracing-fmt` crate crate currently uses a `NewVisitor` trait to
abstract over constructing field visitors of different types or with
different configurations:
d51d4d69d8/tracing-fmt/src/lib.rs (L192-L196)
There have been other use-cases where having this abstraction seems
valuable. For example, issue #73 is a proposal for adding utilities for
wrapping a visitor to skip a set of excluded field names. A `MakeVisitor`
abstraction would allow us to provide much more ergonomic APIs for
composing this kind of visitor behaviour.
Additionally, the current trait in `tracing-fmt` is tied pretty closely
to `tracing-fmt- specific behaviour. A generalized version of this trait
should be generic over the input type used to build the visitor.
## Solution
This PR adds a new `MakeVisitor` trait in `tracing-subscriber`.
`MakeVisitor` generalizes the `NewVisitor` trait in `tracing-fmt` to
represent constructing visitors for arbitrary targets. In addition, I've
added some additional traits representing common patterns for visitors,
such as those that format to a `fmt::Write` instance or write to an IO
stream, or those that produce output once a set of fields have been
visited. I've also added some extension traits & combinators to make
composing visitors easier, and to demonstrate that the trait in this
branch can be used for implementing this kind of wrapper.
I've also rewritten the `tracing-fmt` crate to use the new
`tracing-subscriber::MakeVisitor` trait rather than its homegrown
`fmt`-specifc version.
Closes: #240
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
## Motivation
The `tracing_subscriber` `FmtSubscriber` currently clones span IDs in
calls to `Subscriber::current_span`. However, this is incorrect --- IDs
should only be cloned when constructing an _entering span handle_; the
`tracing-core` `span::Current` type does not call `drop_span` on drop.
In `tracing`, `Span::current` already clones the ID returned by
`Subscriber::current_span`.
This means that any use of `Subscriber::current_span` or `Span::current`
with `FmtSubscriber` will result in the current span being "leaked" and
never dropped.
## Solution
This commit removes the unnecessary `clone_span`.
Thanks to @twissel for reporting the bug!
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Tokio is experimenting with Discord, and the Tokio discord server has
a Tracing channel. This PR adds Discord links to READMEs.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
### Fixed:
- Spans entered twice on the same thread sometimes being completely
exited when the more deeply-nested entry is exited (#361)
- Setting `with_ansi(false)` on `FmtSubscriber` not disabling ANSI color
formatting for timestamps (#354)
- Incorrect reference counting in `FmtSubscriber` that could cause spans
to not be closed when all references are dropped (#366)
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
The `tracing-subscriber` `FmtSubscriber` currently has a subtle bug in
span reference counting that prevents spans from ever closing. The
`clone_span` function, which is supposed to increment a span's reference
count, actually _decrements_ it. Because we detect that a span has
closed when the reference count is _equal to_ 1, we don't free these
spans with inconsistent reference counts; instead, the reference count
overflows and the span is then never closed.
This branch fixes the bug by turning the incorrect `fetch_sub` into a
`fetch_add`, like it's supposed to be.
This is difficult to write tests for, since we don't currently expose
any way for an external component to be notified that a `FmtSubscriber`
has closed a span; but I've added some additional debug assertions that
catch inconsistent states if they occur while running already existing
tests.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* subscriber: Remove ansi for time when ansi = false
When ansi feature is enabled and subscriber is created with with_ansi =
false, the time is now written without ansi codes as it should be. Added
integration tests to verify the behaviour.
I also noticed compilation errors when disabling the ansi feature due
to the deny gate (unused, missing dyn, lifetime). Those problems are
also fixed in this commit. Some structs have unused field (`ansi` in
fmt::format) so a `#[allow(unused)]` was added...
Fixes: #300
* subscriber: Remove is_ansi member when compiling without ansi feature
Using feature gates to remove the dependency on `is_ansi` field in
fmt/format.rs structs. It is a bit redundant but now the basic structures
used to format the event are not using the `is_ansi` bool anymore.
* subscriber: Move common test utility to fmt/mod.rs
The `MockWriter` and `MockMakeWriter` are used in both writer.rs and
format.rs tests. Move them to a common test module so that they
can be used anywhere else.
## 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
This overrides the default `Subscriber::current_span` impl
with one that forwards the inner subscribers implementation.
This fixes bugs where the current_span was not fetchable when
using the `FmtSubscriber`.
Signed-off-by: Lucio Franco <luciofranco14@gmail.com>
### Fixed
- `EnvFilter` ignoring directives with targets that are the same number
of characters (#333)
- `EnvFilter` failing to properly apply filter directives to events
generated from `log` records by`tracing-log` (#344)
### Changed
- Renamed `Filter` to `EnvFilter`, deprecated `Filter` (#339)
- Renamed "filter" feature flag to "env-filter", deprecated "filter" (#339)
- `FmtSubscriber` now defaults to enabling only the `INFO` level and
above when a max level filter or `EnvFilter` is not set (#336)
### Added:
- `EnvFilter::add_directive` to add new directives to filters after they
are constructed (#334)
- `fmt::Builder::with_max_level` to set a global level filter for a
`FmtSubscriber` without requiring the use of `EnvFilter` (#336)
- `Layer` implementation for `LevelFilter` (#336)
- `EnvFilter` now implements `fmt::Display` (#329)
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
