Fixes#27.
Currently, every time a `Span` or `Event` is constructed, we test if the
current subscriber cares about it, by calling `Subscriber::enabled` with
the `Span`/`Event`'s metadata. If this function returns false, we don't
construct the span or send the event. However, this means that the
implementation of `enabled` has to be run every time a span or event is
created. If the filtering is expensive (such as a regular expression or
string comparison), this can have a noticeable performance cost.
This branch changes the `span!` and `event!` macros to cache the result
of previous calls to `Subscriber::enabled`, so that filters don't have
to be re-evaluated. Subscribers are given the ability to invalidate
their previously cached filter results, which they may do for various
reasons --- such as if the filter can be dynamically reconfigured at
runtime.
This introduces some potential "gotchas", such as that switching
subscribers will require complete invalidation of all filters. However,
we should be able to address this while making further changes such as
#30.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Fixes#24.
Requires #34.
Currently, spans and events both have `std::time::Instant` fields that
record a timestamp of when the span or event was created. Furthermore,
the `Subscriber::enter` and `Subscriber::exit` trait methods take an
`Instant` argument representing a timestamp of when the span was entered
or exited. As described in #24, this is a potential performance issue,
as `Instant::now` may result in an expensive syscall. Since some
subscriber implementations may not need timestamps, or may not need to
record them for _all_ possible events, we should not perform these
syscalls by default.
This branch removes the timestamps from spans and events, and from the
`Subscriber` API. If subscribers require timestamps for events or spans,
they can call `Instant::now` or `SystemTime::now`. This has the side
benefit of allowing subscriber implementations to choose what timestamp
type is appropriate for their use case.
Since event and span entry/exit notifications are broadcast to
subscribers synchronously as they occur, if a subscriber records a
timestamp itself, it should still be sufficiently accurate.
This branch requires PR #34 to be merged first, so that span
identifiers may be used for testing span equality, rather than the
timestamps.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This branch changes the semantics of that function to be "notifying the
subscriber of the creation of a new span", rather than simply
"requesting a new ID".
This introduces some new guarantees to the `new_span` API (as discussed
in
f7bc34651e (r30777026)),
but I think they can reasonably addressed as part of future changes.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This branch introduces a `span::Id` type and changes span equality to be
based on the span's `Id`. The `Id` type is used to identify the span
within the context of the process.
These span IDs are intended to be used as a source of truth for
determining whether two span handles are equal. Previously, this
was done based on the span's creation timestamp and metadata, but the
creation timestamps are slated for removal (see #24). When they are
removed, the metadata alone will not be sufficient to uniquely identify
the span, since that would mean two distinct spans created at the same
call site would be "equal".
Similarly, we cannot base span equality on their field values, for a
number of reasons:
+ Two spans with the same metadata and no fields would be equal,
even if they are distinct periods of time.
+ Similarly, two spans which happen to have the same field values, but
represent distinct periods of time would also be incorrectly equal.
+ Using field values for equality and hashing would require that
`Value`s implement `Hash` and `PartialEq`, which they cannot do when
they are represented by trait objects (as these traits are not object
safe).
+ Also, comparing the field values would require iterating across all
the fields.
Currently, the `Id` type is represented by a `u64`. However, the `Id`
type is opaque to downstream users, beyond the contract of implementing
`Clone`, `Hash`, and `PartialEq`, and being able to be _constructed_
from a `u64`, so we could swap out this implementation with something
else later fairly transparently, as long as we can construct it from a
`u64`.
`Subscriber`s are responsible for generating the IDs for each span
(through the `Subscriber::new_span_id` trait method), allowing them to
choose the span ID generation strategy that supports their use case.
Required for #24
This means that the core `tokio_trace` crate no longer has to depend on `log`; see #20.
* Move `LogSubscriber` to the tokio-trace-log crate
* Add nicer conversion traits
* Replace log::Level re-export with our own type
Fixes#10. Also required for #20.
Currently, any span created at the top level is implicitly a child of
the "root span" that is created when the program starts and lasts for
its entire lifespan. Removing the implicit root span would allow
subscribers to more easily distinguish between "separate" traces, such
as per-request traces in a server application.
See also:
+ https://github.com/hawkw/tokio-trace-prototype/issues/4#issuecomment-424165691
+ https://github.com/hawkw/tokio-trace-prototype/issues/4#issuecomment-424167537
Also, the implicit root span is an artifact of prior implementation
constraints and it is no longer required.
This branch removes the implicit root span. It also removes the
dependency on the `lazy_static` crate.
Note that this also changes the `event.parent` field to an
`Option<SpanData>` rather than just a `SpanData`.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Fixes#14, #15.
Since span creation is relatively expensive (it causes multiple
allocations, for the span itself and for any associated values), spans
which no subscribers will record should never be created.
This branch implements this feature by adding an `enabled` method to the
`Subscriber` trait, similar to the method of the same name on the `log`
crate's `Log` trait. This method is called to determine whether a
`Subscriber` is interested in a particular span or event, based on its
metadata. If no `Subscriber`s return true, the span or event is never
constructed. Metadata construction is significantly less expensive than
`Span` construction (especially since for `Span`s, it can always be
constructed statically), so the filtering is based on metadata only. To
allow spans to be filtered by name (as span names are also always
`'static`), the name field was moved to the `Meta` type as well.
In order to make the `span!` macro API function the same as it did prior
to this PR, the internals of the `Span` type were changed somewhat to
allow spans which are disabled to be created. Disabled spans will not
allocate, and entering a disabled span does nothing.
This means that code like
```rust
span!("foo").enter(|| {
// do stuff
})
```
still works, even if no subscriber expresses interest in the span.
This makes the span internals somewhat more complex, but it seemed
better than the alternative of having the `span!` macro evaluate to
`None` if the span is not enabled, as that required additional complexity
at the _call site_ rather than internally to `tokio-trace`
In addition, a `with_filter` method was added to `Subscriber`, to allow
composing subscribers from external crates with a user-defined filtering
predicate.
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* Move span names to metadata for filtering
* Add `enabled` function to `Subscriber` trait
* Only construct events that are enabled
* Only create spans if a subscriber currently cares about them
* Add `Subscriber::with_filter` for composing Subscribers with predicates
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
* Reduce `#[doc(hidden)] pub` internal API surface
These undocumented pub functions are used by the `span!` and `event!` macros. Since they are technically public API even though they are hidden and not intended for external use, they should be kept as limited as possible.
* Add docs
Fixes#4.
This branch adds a notion of "doneness" to spans and allows spans to
mark themselves as "done" when they can no longer be entered. Spans know
when they are done by tracking the number of handles which may enter the
span; this means that the `Span::enter` API function had to be changed
to take the span by-value rather than by-reference. This meant some
other stuff had to be changed.
This branch also makes it possible to get _non-entering_ handles to a
span. These data handles keep the span's data alive, but may not
re-enter the span. This allows spans to mark themselves as done while
`Subscriber`s are still hanging on to references of their data, keeping
it alive.
Admittedly, this was a bit of a yak shave, but I also threw together a
quick mocking DSL for writing tests for this functionality. That code is
still a work in progress.
* move span to its own module
* Add states to spans
* WIP automatic span closure
* Make span module compile-y
* make core crate more compile-y
* make sloggish test compile
* whoa, something resembling unit tests!
* fix issue where span states transition _after_ notifying subscriber
* make test DSL nicer
* document span completion test
* fix test support code breaking when there's multiple tests
* add test for concurrently executing multiple threads
* Spans remain "running" as long as any thread is in the span
* add test for future span completion
* instrumented futures/streams mark their spans as done when completing
* Leave sinks be (they can't finish until the sink is dropped)
* refactor, make lock-free
* remove unused
* fix post-rebase breakage
* make everything else work with doneness API changes
* more docs
* Fix typo in comment
* Make converting from Span handles to Data handles more ergonomic
* Fix missing macro import breaking doctests
* add docs for internal span implementation types
* Clarify and factor out ActiveSpan state transition logic
* fix up rename
* fix doctest on stable compiler
This branch adds `tokio-trace-log` and `tokio-trace-env-logger`
compatibility crates which can be used to bring log records emitted by
crates using the `log` library into the context of a trace.
Loggers are provided which implement the `log::Log` trait by converting
log records into events in the span that is executing when the record is
logged, and propagates them to the trace dispatcher. This conversion is
not capable of parsing unstructured log messages and converting them
into a structured format (as this would require some form of
natural-language processing to implement correctly), but allows log
records to be placed within the context of a span. This is useful as a
migration path for codebases which already use unstructured logging, and
as a way for codebases using `tokio-trace` to to connect the log records
emitted by dependencies with the tracing system without requiring
upstream code changes.
* Event metadata need not be 'static, so it can be generated from log meta
* first pass on an adapter for the log crate
* add doc to log adapter
* feature-flag env-logger compat and move it to a module
* actually, just put env-logger compat in a separate crate
feature flags are more confusing for downstream users.
* improve log compat crate docs
* remove unneeded deps from tokio-trace-log Cargo.toml
* document Event lifetime parameters
