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: remove user-space thread local from filters #578

Merged
merged 1 commit into from
Feb 12, 2020

Conversation

hawkw
Copy link
Member

@hawkw hawkw commented Feb 12, 2020

Motivation

Currently, tracing-subscriber's EnvFilter type uses a user-space
thread local for storing any entered spans which are relevant to
filters. This was intended to support allowing multiple EnvFilters to
coexist in the same subscriber, which was never implemented. It turns
out this has a noticeable performance impact versus a proper
thread-local.

Solution

I replaced the user-space thread local type with a proper thread-local.

Benchmark Results

(vs master, note that there was some noise in the benchmark environment,
as evidenced by the "regression" in the baseline tests)

     Running target/release/deps/filter-56ce39a1aef6b2a0
static/baseline_single_threaded
                        time:   [98.622 ns 101.54 ns 104.78 ns]
                        change: [+2.5820% +6.1667% +9.7976%] (p = 0.00 < 0.05)
                        Performance has regressed.
Found 7 outliers among 100 measurements (7.00%)
  6 (6.00%) high mild
  1 (1.00%) high severe
static/single_threaded  time:   [50.699 ns 51.776 ns 52.896 ns]
                        change: [-2.8933% -1.4141% +0.1262%] (p = 0.07 > 0.05)
                        No change in performance detected.
Found 7 outliers among 100 measurements (7.00%)
  5 (5.00%) high mild
  2 (2.00%) high severe
static/baseline_multithreaded
                        time:   [9.5372 us 9.7739 us 10.025 us]
                        change: [-22.208% -16.587% -10.758%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 6 outliers among 100 measurements (6.00%)
  3 (3.00%) high mild
  3 (3.00%) high severe
static/multithreaded    time:   [9.3605 us 9.6779 us 10.031 us]
                        change: [-31.493% -26.773% -21.761%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high mild

dynamic/baseline_single_threaded
                        time:   [165.50 ns 166.57 ns 167.68 ns]
                        change: [-10.102% -8.6136% -7.1789%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 4 outliers among 100 measurements (4.00%)
  4 (4.00%) high mild
dynamic/single_threaded time:   [539.01 ns 542.44 ns 546.11 ns]
                        change: [-41.078% -40.104% -39.195%] (p = 0.00 < 0.05)
                        Performance has improved.
dynamic/baseline_multithreaded
                        time:   [9.3314 us 9.7205 us 10.222 us]
                        change: [-45.458% -41.873% -37.948%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 9 outliers among 100 measurements (9.00%)
  4 (4.00%) high mild
  5 (5.00%) high severe
dynamic/multithreaded   time:   [10.095 us 10.295 us 10.520 us]
                        change: [-66.323% -63.666% -61.130%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 11 outliers among 100 measurements (11.00%)
  1 (1.00%) low mild
  7 (7.00%) high mild
  3 (3.00%) high severe

Signed-off-by: Eliza Weisman eliza@buoyant.io

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
@hawkw
Copy link
Member Author

hawkw commented Feb 12, 2020

The CurrentSpanPerThread thing also uses the user-space thread local. We should either update it to match, or deprecate it entirely in favour of the registry (nobody actually uses it).

@hawkw hawkw self-assigned this Feb 12, 2020
@hawkw hawkw added crate/subscriber Related to the `tracing-subscriber` crate crate/tracing Related to the `tracing` crate labels Feb 12, 2020
@hawkw hawkw merged commit 263a154 into master Feb 12, 2020
hawkw added a commit that referenced this pull request Feb 14, 2020
Changed

- **filter**: `EnvFilter` directive selection now behaves correctly
  (i.e. like `env_logger`) (#583)

Fixed

- **filter**: Fixed `EnvFilter` incorrectly allowing less-specific
  filter directives to enable events that are disabled by more-specific
  filters (#583)
- **filter**: Multiple significant `EnvFilter`  performance
  improvements, especially when filtering events generated by `log`
  records (#578, #583)
- **filter**: Replaced `BTreeMap` with `Vec` in `DirectiveSet`,
  improving iteration performance significantly with typical numbers of
  filter directives (#580)

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
hawkw added a commit that referenced this pull request Feb 14, 2020
Changed

- **filter**: `EnvFilter` directive selection now behaves correctly
  (i.e. like `env_logger`) (#583)

Fixed

- **filter**: Fixed `EnvFilter` incorrectly allowing less-specific
  filter directives to enable events that are disabled by more-specific
  filters (#583)
- **filter**: Multiple significant `EnvFilter`  performance
  improvements, especially when filtering events generated by `log`
  records (#578, #583)
- **filter**: Replaced `BTreeMap` with `Vec` in `DirectiveSet`,
  improving iteration performance significantly with typical numbers of
  filter directives (#580)

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
hawkw added a commit that referenced this pull request Feb 14, 2020
Changed

- **filter**: `EnvFilter` directive selection now behaves correctly
  (i.e. like `env_logger`) (#583)

Fixed

- **filter**: Fixed `EnvFilter` incorrectly allowing less-specific
  filter directives to enable events that are disabled by more-specific
  filters (#583)
- **filter**: Multiple significant `EnvFilter`  performance
  improvements, especially when filtering events generated by `log`
  records (#578, #583)
- **filter**: Replaced `BTreeMap` with `Vec` in `DirectiveSet`,
  improving iteration performance significantly with typical numbers of
  filter directives (#580)

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
hawkw added a commit that referenced this pull request Feb 14, 2020
Changed

- **filter**: `EnvFilter` directive selection now behaves correctly
  (i.e. like `env_logger`) (#583)

Fixed

- **filter**: Fixed `EnvFilter` incorrectly allowing less-specific
  filter directives to enable events that are disabled by more-specific
  filters (#583)
- **filter**: Multiple significant `EnvFilter`  performance
  improvements, especially when filtering events generated by `log`
  records (#578, #583)
- **filter**: Replaced `BTreeMap` with `Vec` in `DirectiveSet`,
  improving iteration performance significantly with typical numbers of
  filter directives (#580)

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
hawkw added a commit that referenced this pull request Feb 14, 2020
### Changed

- **filter**: `EnvFilter` directive selection now behaves correctly
  (i.e. like `env_logger`) (#583)

### Fixed

- **filter**: Fixed `EnvFilter` incorrectly allowing less-specific
  filter directives to enable events that are disabled by more-specific
  filters (#583)
- **filter**: Multiple significant `EnvFilter`  performance
  improvements, especially when filtering events generated by `log`
  records (#578, #583)
- **filter**: Replaced `BTreeMap` with `Vec` in `DirectiveSet`,
  improving iteration performance significantly with typical numbers of
  filter directives (#580)

A big thank-you to @samschlegel for lots of help with `EnvFilter` 
performance tuning in this release!

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
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 crate/tracing Related to the `tracing` crate
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants