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

subscriber: For registry-backed layers, delay deletion of span until all layers have processed the event #432

Merged
merged 15 commits into from
Nov 16, 2019

Conversation

davidbarsky
Copy link
Member

@davidbarsky davidbarsky commented Nov 16, 2019

This PR implements the second option ("The One With The downcast_ref") in @hawkw's comment. The benchmarks of this change, relative to the master branch, are available here.

Edit: The same benchmarks running on a significantly less noisy c3.8xlarge: https://gist.github.com/davidbarsky/111814dcc55e89580e5ee283b9900bbf.

Resolves #429

@davidbarsky davidbarsky requested a review from a team November 16, 2019 01:45
@davidbarsky davidbarsky changed the title subscriber: For registry-backed layers, delay deletition of span until all layers have processed the event subscriber: For registry-backed layers, delay deletion of span until all layers have processed the event Nov 16, 2019
@davidbarsky
Copy link
Member Author

The same benchmarks running on a significantly less noisy c3.8xlarge: https://gist.github.com/davidbarsky/111814dcc55e89580e5ee283b9900bbf.

I first ran benchmarks on the master branch and then on the david/downcast_ref-registry branch.

Copy link
Member

@hawkw hawkw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks great, and I'm glad that we were able to use the approach that doesn't involve additional unsafe code without significant performance impact. I left some notes, primarily on style and naming.

I also think it would be really good to have some tests for this behavior, since it is relatively complicated. Some things we should test:

  • a Layer that expects a span to be closed, and asserts that looking up the span is successful inside it's on_close callback
  • the same test with two or more Layers — both layers should be able to access the closed span's data during their on_close calls
  • a test that ensures that the span data is removed from the registry once all the on_close methods have completed. We could test this by having a type that sets a shared atomic boolean when it's dropped, insert that type into a span's extensions, and drop the span. After the close completes, we can assert that the boolean indicating that the extension was dropped is set.

tracing-subscriber/src/layer.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/layer.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
@hawkw
Copy link
Member

hawkw commented Nov 16, 2019

The benchmarks of this change, relative to the master branch, are available here.

On Discord, we discussed how these benchmarks might potentially be inaccurate (perhaps due to a noisy benchmarking environment). Did you have a chance to run them again in a more isolated benchmark environment? If so, it would be great to see those results as well.

@hawkw hawkw added crate/subscriber Related to the `tracing-subscriber` crate kind/feature New feature or request labels Nov 16, 2019
thombles and others added 6 commits November 16, 2019 10:35
Following the suggested fix on #365:
#365 (comment)

tracing-core's use of `spin` is feature-gated. `lazy_static` is vendored
for either feature but I've modified it to respect our feature flags.
I've also removed doc comments that no longer compile and suppressed a
couple of warnings with the lints that are now being applied.

At this point
* Including this in another project with std `lazy_static`
  works 
* Tracing unit tests pass both with and without
  `--no-default-features`

Fixes #365

* core: vendor lazy_static and spin for no_std support

* core: fmt vendored code

* core: trim down vendored spin, reduce visibility and addresss warnings

* core: limit vendored lazy_static for use only with no_std, fix warnings

* core: update paths to now-vendored no_std libs

* tracing: use spin::Once re-exported from tracing-core instead of crate

* core: remove ineffectual doc(hidden)

* core: refmt stdlib module

* core: bump to 0.1.8 to expose export of vendored spin::Once to tracing
`fmt::Layer::on_record` was looking up extensions using
`FormattedFields<Self>>` when it should have been using
`FormattedFields<N>>`.

Signed-off-by: David Barsky [email protected]
@hawkw
Copy link
Member

hawkw commented Nov 16, 2019

The same benchmarks running on a significantly less noisy c3.8xlarge: https://gist.github.com/davidbarsky/111814dcc55e89580e5ee283b9900bbf.

I first ran benchmarks on the master branch and then on the david/downcast_ref-registry branch.

Great, thank you — I must've missed this earlier. Seems like the performance difference is very slight, probably not significant enough to justify the more complex unsafe solution. We can revisit this if it turns out to have an impact.

@davidbarsky
Copy link
Member Author

@hawkw I think I've addressed all of the comments you had, including adding tests. I'd appreciate a re-review whenever you have the time!

tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
tracing-subscriber/src/registry/sharded.rs Outdated Show resolved Hide resolved
@hawkw
Copy link
Member

hawkw commented Nov 16, 2019

the test failures on nightly (https://github.com/tokio-rs/tracing/pull/432/checks?check_run_id=306313856) seem unrelated, but it would be good if they could be addressed

@davidbarsky davidbarsky merged commit 5d2ebc6 into master Nov 16, 2019
@davidbarsky
Copy link
Member Author

@hawkw Sorry—just saw your comment about nightly failures. I'll address that in a separate branch.

@davidbarsky davidbarsky deleted the david/downcast_ref-registry branch November 16, 2019 21:59
hawkw added a commit that referenced this pull request Feb 4, 2020
0.2.0 (February 4, 2020)

Breaking Changes:

- **fmt**: Renamed `Context` to `FmtContext` (#420, #425)
- **fmt**: Renamed `Builder` to `SubscriberBuilder` (#420)
- **filter**: Removed `Filter`. Use `EnvFilter` instead (#434)

Added:

- **registry**: `Registry`, a reusable span store that `Layer`s can use
  a high-performance, in-memory store. (#420, #425, #432, #433, #435)
- **registry**: Added `LookupSpan` trait, implemented by `Subscriber`s
  to expose stored span data to `Layer`s (#420)
- **fmt**: Added `fmt::Layer`, to allow composing log formatting with
  other `Layer`s (#420)
- **fmt**: Added support for JSON field and event formatting (#377,
  #415)
- **filter**: Documentation for filtering directives (#554)

Changed:

- **fmt**: Renamed `Context` to `FmtContext` (#420, #425) (BREAKING)
- **fmt**: Renamed `Builder` to `SubscriberBuilder` (#420) (BREAKING)
- **fmt**: Reimplemented `fmt::Subscriber` in terms of the `Registry`
  and `Layer`s (#420)

Removed:

- **filter**: Removed `Filter`. Use `EnvFilter` instead (#434) (BREAKING)

Fixed:

- **fmt**: Fixed memory leaks in the slab used to store per-span data
  (3c35048)
- **fmt**: `fmt::SubscriberBuilder::init` not setting up `log`
  compatibility (#489)
- **fmt**: Spans closed by a child span closing not also closing _their_
  parents (#514)
- **Layer**: Fixed `Layered` subscribers failing to downcast to their
  own type (#549)
- **Layer**: Fixed `Layer::downcast_ref` returning invalid references
  (#454)

Signed-off-by: Eliza Weisman <[email protected]>
hawkw added a commit that referenced this pull request Feb 4, 2020
# 0.2.0 (February 4, 2020)

### Breaking Changes

- **fmt**: Renamed `Context` to `FmtContext` (#420, #425)
- **fmt**: Renamed `Builder` to `SubscriberBuilder` (#420)
- **filter**: Removed `Filter`. Use `EnvFilter` instead (#434)

### Added

- **registry**: `Registry`, a `Subscriber` implementation that `Layer`s
  can use as a high-performance, in-memory span store. (#420, #425, 
  #432, #433, #435)
- **registry**: Added `LookupSpan` trait, implemented by `Subscriber`s
  to expose stored span data to `Layer`s (#420)
- **fmt**: Added `fmt::Layer`, to allow composing log formatting with
  other `Layer`s
- **fmt**: Added support for JSON field and event formatting (#377, 
  #415)
- **filter**: Documentation for filtering directives (#554)

### Changed

- **fmt**: Renamed `Context` to `FmtContext` (#420, #425) (BREAKING)
- **fmt**: Renamed `Builder` to `SubscriberBuilder` (#420) (BREAKING)
- **fmt**: Reimplemented `fmt::Subscriber` in terms of the `Registry`
  and `Layer`s (#420)

### Removed

- **filter**: Removed `Filter`. Use `EnvFilter` instead (#434) 
  (BREAKING)

### Fixed

- **fmt**: Fixed memory leaks in the slab used to store per-span data
  (3c35048)
- **fmt**: `fmt::SubscriberBuilder::init` not setting up `log` 
  compatibility (#489)
- **fmt**: Spans closed by a child span closing not also closing 
  _their_ parents (#514)
- **Layer**: Fixed `Layered` subscribers failing to downcast to their
  own type (#549)
- **Layer**: Fixed `Layer::downcast_ref` returning invalid references
  (#454)

Fixes #515
Fixes #458 

Signed-off-by: Eliza Weisman <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
crate/subscriber Related to the `tracing-subscriber` crate kind/feature New feature or request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

subscriber: Enable Layers to read a recently-closed span
3 participants