tracing: less noisy, more useful log records for spans
#613
Commits on Feb 28, 2020
-
tracing: log span lifecycle events under a separate target
## Motivation Currently, the `tracing` crate's "log" feature always logs span lifecycle (creation/enter/exit/close) events, even when the span has no fields. This can be quite noisy. Since the enter, exit, and close logs don't include the span's fields, it doesn't add that much additional context to the surrounding log records. ## Solution In order to continue recording this data while improving the signal-to-noise ratio of `tracing`-generated logs, this commit changes the log integration to log span lifecycle events under a separate target, "tracing::span". This way, log users can opt in to this data when it is desired, but logs are generally much less noisy. Span creation is still logged to the default target when the span has fields, as this often provides useful information, but is sent to the "tracing-span" target when there are no fields. Fixes #607
-
-
tracing: include span IDs in logs when available
When using `tracing` with the `log-always`, the IDs of enabled spans are available, but not included in the span lifecycle `log` records. These could be used to enable tracking individual span's lifecycles via these log records, but this is not currently possible. This commit updates the `log` integration so that when a span is enabled by a subscriber, and `log` integration is enabled, that span's `log` records will include its ID. Now, when multiple spans with the same name are in the logs, we have a rudimentary ability to correlate those span's lifecycle events, without introducing so much complexity that just using a `tracing` subscriber would be a better solution. For example, when a subscriber is assigning IDs to spans, the logs look like this: ``` ERROR log_with_trace foo=5 ERROR log_with_trace foo=42 ERROR log_with_trace foo=39 WARN log_with_trace hello world; INFO log_with_trace hello world; thingy=42 other_thingy=666 TRACE tracing::span ++ foo; span=1 TRACE tracing::span -> foo; span=1 TRACE log_with_trace hello san francisco; foo=3 bar=4 TRACE tracing::span <- foo; span=1 TRACE tracing::span -- foo; span=1 TRACE log_with_trace ++ foo; bar=3 baz=false; span=2 TRACE tracing::span -- foo; span=2 TRACE log_with_trace hello world foo=1 bar=2 ``` Signed-off-by: Eliza Weisman <eliza@buoyant.io>
-
much nicer semicolon placement
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
-
remove accidentally added file
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
-
Co-Authored-By: David Barsky <me@davidbarsky.com>
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.