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

log: make span enter/exit targets always TRACE #833

Merged
merged 1 commit into from Jul 21, 2020

Conversation

hawkw
Copy link
Member

@hawkw hawkw commented Jul 21, 2020

Motivation

Currently, tracing's log feature emits log records for creating,
entering, exiting, and dropping a Span at the log equivalent of that
span's tracing level. If the span has any fields, the span creation
logs are sent to the same target that the span would have, since the
fields provide high-value information that users enabling that target
will probably want to see. However, the other events for entering,
exiting, and dropping a span do not include fields, and are much more
verbose, so they are sent to a special tracing::span target. This
allows them to be filtered independently, and only enabled when needed.

However, some log users have noted that when using blanket log
filters, like setting the level to info globally, the more verbose
activity logs will still be enabled for spans whose level matches. This
can be annoying.

Solution

Therefore, this branch changes the span activity and lifecycle logs to
always have the Trace log level, even when the span that generated
them has a less-verbose level. When fields are recorded, the emitted log
records are sent to the span's target instead, since users probably want
this information if they have enabled the span's level for its target.

Additionally, I've added a sub-target of tracing::span for the
enter/exit logs in particular (tracing::span::active). This allows
them to be filtered independently of the less frequent creation/drop
logs.

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

Currently, `tracing`'s `log` feature emits log records for creating,
entering, exiting, and dropping a `Span` at the `log` equivalent of that
span's `tracing` level. If the span has any fields, the span creation
logs are sent to the same target that the span would have, since the
fields provide high-value information that users enabling that target
will probably want to see. However, the other events for entering,
exiting, and dropping a span do not include fields, and are much more
verbose, so they are sent to a special `tracing::span` target. This
allows them to be filtered independently, and only enabled when needed.

However, some `log` users have noted that when using _blanket_ `log`
filters, like setting the level to `info` globally, the more verbose
activity logs will still be enabled for spans whose level matches. This
can be annoying.

Therefore, this branch changes the span activity and lifecycle logs to
_always_ have the `Trace` `log` level, even when the span that generated
them has a less-verbose level. When fields are recorded, the emitted log
records are sent to the span's target instead, since users probably want
this information if they have enabled the span's level for its target.

Additionally, I've added a sub-target of `tracing::span` for the
enter/exit logs in particular (`tracing::span::active`). This allows
them to be filtered independently of the less frequent creation/drop
logs.

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
@hawkw hawkw requested a review from a team as a code owner July 21, 2020 19:05
@hawkw hawkw merged commit 6e85bf5 into master Jul 21, 2020
hawkw added a commit that referenced this pull request Jul 22, 2020
Changed

- **log**: Moved verbose span enter/exit log records to
  "tracing::span::active" target, allowing them to be filtered
  separately (#833)
- **log**: All span lifecycle log records without fields now have the
  `Trace` log filter, to guard against `log` users enabling them by
  default with blanket level filtering (#833)

Fixed

- **log**/**macros**: Fixed missing implicit imports of the
  `tracing::field::debug` and `tracing::field::display` functions inside
  the macros when the "log" feature is enabled (#835)
hawkw added a commit that referenced this pull request Jul 22, 2020
### Changed

- **log**: Moved verbose span enter/exit log records to
  "tracing::span::active" target, allowing them to be filtered
  separately (#833)
- **log**: All span lifecycle log records without fields now have the
  `Trace` log filter, to guard against `log` users enabling them by
  default with blanket level filtering (#833)

### Fixed

- **log**/**macros**: Fixed missing implicit imports of the
  `tracing::field::debug` and `tracing::field::display` functions inside
  the macros when the "log" feature is enabled (#835)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

1 participant