summaryrefslogtreecommitdiffstats
path: root/tokio-trace
diff options
context:
space:
mode:
authorEliza Weisman <eliza@buoyant.io>2019-02-19 12:15:01 -0800
committerGitHub <noreply@github.com>2019-02-19 12:15:01 -0800
commitc08e73c8d4f3353e93658aa4eb488c0080d0cab0 (patch)
treed8ccffc9e816e2f007b6aab4fb423dee68a66476 /tokio-trace
parentd1d72dc1c80baff74f586108c44c9140bc7463a5 (diff)
Introduce `tokio-trace` (#827)
<!-- Thank you for your Pull Request. Please provide a description above and review the requirements below. Bug fixes and new features should include tests. Contributors guide: https://github.com/tokio-rs/tokio/blob/master/CONTRIBUTING.md --> ## Motivation In asynchronous systems like Tokio, interpreting traditional log messages can often be quite challenging. Since individual tasks are multiplexed on the same thread, associated events and log lines are intermixed making it difficult to trace the logic flow. Currently, none of the available logging frameworks or libraries in Rust offer the ability to trace logical paths through a futures-based program. There also are complementary goals that can be accomplished with such a system. For example, metrics / instrumentation can be tracked by observing emitted events, or trace data can be exported to a distributed tracing or event processing system. In addition, it can often be useful to generate this diagnostic data in a structured manner that can be consumed programmatically. While prior art for structured logging in Rust exists, it is not currently standardized, and is not "Tokio-friendly". ## Solution This branch adds a new library to the tokio project, `tokio-trace`. `tokio-trace` expands upon logging-style diagnostics by allowing libraries and applications to record structured events with additional information about *temporality* and *causality* --- unlike a log message, a span in `tokio-trace` has a beginning and end time, may be entered and exited by the flow of execution, and may exist within a nested tree of similar spans. In addition, `tokio-trace` spans are *structured*, with the ability to record typed data as well as textual messages. The `tokio-trace-core` crate contains the core primitives for this system, which are expected to remain stable, while `tokio-trace` crate provides a more "batteries-included" API. In particular, it provides macros which are a superset of the `log` crate's `error!`, `warn!`, `info!`, `debug!`, and `trace!` macros, allowing users to begin the process of adopting `tokio-trace` by performing a drop-in replacement. ## Notes Work on this project had previously been carried out in the [tokio-trace-prototype] repository. In addition to the `tokio-trace` and `tokio-trace-core` crates, the `tokio-trace-prototype` repo also contains prototypes or sketches of adapter, compatibility, and utility crates which provide useful functionality for `tokio-trace`, but these crates are not yet ready for a release. When this branch is merged, that repository will be archived, and the remaining unstable crates will be moved to a new `tokio-trace-nursery` repository. Remaining issues on the `tokio-trace-prototype` repo will be moved to the appropriate new repo. The crates added in this branch are not _identical_ to the current head of the `tokio-trace-prototype` repo, as I did some final clean-up and docs polish in this branch prior to merging this PR. [tokio-trace-prototype]: https://github.com/hawkw/tokio-trace-prototype Closes: #561 Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Diffstat (limited to 'tokio-trace')
-rw-r--r--tokio-trace/Cargo.toml30
-rw-r--r--tokio-trace/LICENSE25
-rw-r--r--tokio-trace/README.md168
-rw-r--r--tokio-trace/benches/no_subscriber.rs44
-rw-r--r--tokio-trace/benches/subscriber.rs145
-rw-r--r--tokio-trace/examples/counters.rs138
-rw-r--r--tokio-trace/examples/sloggish/main.rs53
-rw-r--r--tokio-trace/examples/sloggish/sloggish_subscriber.rs293
-rw-r--r--tokio-trace/src/field.rs54
-rw-r--r--tokio-trace/src/lib.rs983
-rw-r--r--tokio-trace/src/span.rs495
-rw-r--r--tokio-trace/src/subscriber.rs19
-rw-r--r--tokio-trace/tests/dispatcher.rs73
-rw-r--r--tokio-trace/tests/event.rs169
-rw-r--r--tokio-trace/tests/macros.rs145
-rw-r--r--tokio-trace/tests/span.rs478
-rw-r--r--tokio-trace/tests/subscriber.rs170
-rw-r--r--tokio-trace/tests/support/event.rs92
-rw-r--r--tokio-trace/tests/support/field.rs224
-rw-r--r--tokio-trace/tests/support/metadata.rs64
-rw-r--r--tokio-trace/tests/support/mod.rs6
-rw-r--r--tokio-trace/tests/support/span.rs109
-rw-r--r--tokio-trace/tests/support/subscriber.rs337
-rw-r--r--tokio-trace/tokio-trace-core/Cargo.toml18
-rw-r--r--tokio-trace/tokio-trace-core/LICENSE25
-rw-r--r--tokio-trace/tokio-trace-core/README.md42
-rw-r--r--tokio-trace/tokio-trace-core/src/callsite.rs121
-rw-r--r--tokio-trace/tokio-trace-core/src/dispatcher.rs252
-rw-r--r--tokio-trace/tokio-trace-core/src/event.rs55
-rw-r--r--tokio-trace/tokio-trace-core/src/field.rs740
-rw-r--r--tokio-trace/tokio-trace-core/src/lib.rs177
-rw-r--r--tokio-trace/tokio-trace-core/src/metadata.rs272
-rw-r--r--tokio-trace/tokio-trace-core/src/span.rs22
-rw-r--r--tokio-trace/tokio-trace-core/src/subscriber.rs318
34 files changed, 6356 insertions, 0 deletions
diff --git a/tokio-trace/Cargo.toml b/tokio-trace/Cargo.toml
new file mode 100644
index 00000000..b66ac607
--- /dev/null
+++ b/tokio-trace/Cargo.toml
@@ -0,0 +1,30 @@
+[package]
+name = "tokio-trace"
+version = "0.0.1"
+authors = ["Eliza Weisman <eliza@buoyant.io>"]
+license = "MIT"
+repository = "https://github.com/tokio-rs/tokio"
+homepage = "https://tokio.rs"
+description = """
+A scoped, structured logging and diagnostics system.
+"""
+categories = ["development-tools::debugging", "asynchronous"]
+keywords = ["logging", "tracing"]
+
+# Not yet ready for production.
+publish = false
+
+[dependencies]
+tokio-trace-core = { path = "tokio-trace-core" }
+
+[dev-dependencies]
+ansi_term = "0.11"
+humantime = "1.1.1"
+futures = "0.1"
+log = "0.4"
+
+# These are used for the "basic" example from the tokio-trace-prototype repo,
+# which is currently not included as it used the `tokio-trace-log` crate, and
+# that crate is currently unstable.
+# env_logger = "0.5"
+# tokio-trace-log = { path = "../tokio-trace-log" }
diff --git a/tokio-trace/LICENSE b/tokio-trace/LICENSE
new file mode 100644
index 00000000..cdb28b4b
--- /dev/null
+++ b/tokio-trace/LICENSE
@@ -0,0 +1,25 @@
+Copyright (c) 2019 Tokio Contributors
+
+Permission is hereby granted, free of charge, to any
+person obtaining a copy of this software and associated
+documentation files (the "Software"), to deal in the
+Software without restriction, including without
+limitation the rights to use, copy, modify, merge,
+publish, distribute, sublicense, and/or sell copies of
+the Software, and to permit persons to whom the Software
+is furnished to do so, subject to the following
+conditions:
+
+The above copyright notice and this permission notice
+shall be included in all copies or substantial portions
+of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF
+ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED
+TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A
+PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT
+SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY
+CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
+OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR
+IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
+DEALINGS IN THE SOFTWARE.
diff --git a/tokio-trace/README.md b/tokio-trace/README.md
new file mode 100644
index 00000000..a2190514
--- /dev/null
+++ b/tokio-trace/README.md
@@ -0,0 +1,168 @@
+# tokio-trace
+
+A scoped, structured logging and diagnostics system.
+
+## Overview
+
+`tokio-trace` is a framework for instrumenting Rust programs to collect
+structured, event-based diagnostic information.
+
+In asynchronous systems like Tokio, interpreting traditional log messages can
+often be quite challenging. Since individual tasks are multiplexed on the same
+thread, associated events and log lines are intermixed making it difficult to
+trace the logic flow. `tokio-trace` expands upon logging-style diagnostics by
+allowing libraries and applications to record structured events with additional
+information about *temporality* and *causality* — unlike a log message, a span
+in `tokio-trace` has a beginning and end time, may be entered and exited by the
+flow of execution, and may exist within a nested tree of similar spans. In
+addition, `tokio-trace` spans are *structured*, with the ability to record typed
+data as well as textual messages.
+
+The `tokio-trace` crate provides the APIs necessary for instrumenting libraries
+and applications to emit trace data.
+
+## Usage
+
+First, add this to your `Cargo.toml`:
+
+```toml
+[dependencies]
+tokio-trace = { git = "https://github.com/tokio-rs/tokio" }
+```
+
+Next, add this to your crate:
+
+```rust
+#[macro_use]
+extern crate tokio_trace;
+```
+
+This crate provides macros for creating `Span`s and `Event`s, which represent
+periods of time and momentary events within the execution of a program,
+respectively.
+
+As a rule of thumb, _spans_ should be used to represent discrete units of work
+(e.g., a given request's lifetime in a server) or periods of time spent in a
+given context (e.g., time spent interacting with an instance of an external
+system, such as a database). In contrast, _events_ should be used to represent
+points in time within a span — a request returned with a given status code,
+_n_ new items were taken from a queue, and so on.
+
+`Span`s are constructed using the `span!` macro, and then _entered_
+to indicate that some code takes place within the context of that `Span`:
+
+```rust
+// Construct a new span named "my span".
+let mut span = span!("my span");
+span.enter(|| {
+ // Any trace events in this closure or code called by it will occur within
+ // the span.
+});
+// Dropping the span will close it, indicating that it has ended.
+```
+
+The `Event` type represent an event that occurs instantaneously, and is
+essentially a `Span` that cannot be entered. They are created using the `event!`
+macro:
+
+```rust
+use tokio_trace::Level;
+event!(Level::INFO, "something has happened!");
+```
+
+Users of the [`log`] crate should note that `tokio-trace` exposes a set of macros for
+creating `Event`s (`trace!`, `debug!`, `info!`, `warn!`, and `error!`) which may
+be invoked with the same syntax as the similarly-named macros from the `log`
+crate. Often, the process of converting a project to use `tokio-trace` can begin
+with a simple drop-in replacement.
+
+Let's consider the `log` crate's yak-shaving example:
+
+```rust
+#[macro_use]
+extern crate tokio_trace;
+use tokio_trace::field;
+
+pub fn shave_the_yak(yak: &mut Yak) {
+ // Create a new span for this invocation of `shave_the_yak`, annotated
+ // with the yak being shaved as a *field* on the span.
+ span!("shave_the_yak", yak = field::debug(&yak)).enter(|| {
+ // Since the span is annotated with the yak, it is part of the context
+ // for everything happening inside the span. Therefore, we don't need
+ // to add it to the message for this event, as the `log` crate does.
+ info!(target: "yak_events", "Commencing yak shaving");
+
+ loop {
+ match find_a_razor() {
+ Ok(razor) => {
+ // We can add the razor as a field rather than formatting it
+ // as part of the message, allowing subscribers to consume it
+ // in a more structured manner:
+ info!({ razor = field::display(razor) }, "Razor located");
+ yak.shave(razor);
+ break;
+ }
+ Err(err) => {
+ // However, we can also create events with formatted messages,
+ // just as we would for log records.
+ warn!("Unable to locate a razor: {}, retrying", err);
+ }
+ }
+ }
+ })
+}
+```
+
+You can find examples showing how to use this crate in the examples directory.
+
+### In libraries
+
+Libraries should link only to the `tokio-trace` crate, and use the provided
+macros to record whatever information will be useful to downstream consumers.
+
+### In executables
+
+In order to record trace events, executables have to use a `Subscriber`
+implementation compatible with `tokio-trace`. A `Subscriber` implements a way of
+collecting trace data, such as by logging it to standard output.
+
+Unlike the `log` crate, `tokio-trace` does *not* use a global `Subscriber` which
+is initialized once. Instead, it follows the `tokio` pattern of executing code
+in a context. For example:
+
+```rust
+#[macro_use]
+extern crate tokio_trace;
+
+let my_subscriber = FooSubscriber::new();
+
+tokio_trace::subscriber::with_default(subscriber, || {
+ // Any trace events generated in this closure or by functions it calls
+ // will be collected by `my_subscriber`.
+})
+```
+
+This approach allows trace data to be collected by multiple subscribers within
+different contexts in the program. Alternatively, a single subscriber may be
+constructed by the `main` function and all subsequent code executed with that
+subscriber as the default. Any trace events generated outside the context of a
+subscriber will not be collected.
+
+The executable itself may use the `tokio-trace` crate to instrument itself as
+well.
+
+The [`tokio-trace-nursery`] repository contains less stable crates designed to
+be used with the `tokio-trace` ecosystem. It includes a collection of
+`Subscriber` implementations, as well as utility and adapter crates.
+
+[`log`]: https://docs.rs/log/0.4.6/log/
+
+## License
+
+This project is licensed under the [MIT license](LICENSE).
+
+### Contribution
+
+Unless you explicitly state otherwise, any contribution intentionally submitted
+for inclusion in Tokio by you, shall be licensed as MIT, without any additional
+terms or conditions.
diff --git a/tokio-trace/benches/no_subscriber.rs b/tokio-trace/benches/no_subscriber.rs
new file mode 100644
index 00000000..84a5bc42
--- /dev/null
+++ b/tokio-trace/benches/no_subscriber.rs
@@ -0,0 +1,44 @@
+#![feature(test)]
+#[macro_use]
+extern crate tokio_trace;
+#[macro_use]
+extern crate log;
+extern crate test;
+use test::Bencher;
+
+#[bench]
+fn bench_span_no_subscriber(b: &mut Bencher) {
+ b.iter(|| {
+ span!("span");
+ });
+}
+
+#[bench]
+fn bench_log_no_logger(b: &mut Bencher) {
+ b.iter(|| {
+ log!(log::Level::Info, "log");
+ });
+}
+
+#[bench]
+fn bench_costly_field_no_subscriber(b: &mut Bencher) {
+ b.iter(|| {
+ span!(
+ "span",
+ foo = tokio_trace::field::display(format!("bar {:?}", 2))
+ );
+ });
+}
+
+#[bench]
+fn bench_no_span_no_subscriber(b: &mut Bencher) {
+ b.iter(|| {});
+}
+
+#[bench]
+fn bench_1_atomic_load(b: &mut Bencher) {
+ // This is just included as a baseline.
+ use std::sync::atomic::{AtomicUsize, Ordering};
+ let foo = AtomicUsize::new(1);
+ b.iter(|| foo.load(Ordering::Relaxed));
+}
diff --git a/tokio-trace/benches/subscriber.rs b/tokio-trace/benches/subscriber.rs
new file mode 100644
index 00000000..fd60979b
--- /dev/null
+++ b/tokio-trace/benches/subscriber.rs
@@ -0,0 +1,145 @@
+#![feature(test)]
+
+#[macro_use]
+extern crate tokio_trace;
+extern crate test;
+use test::Bencher;
+
+use std::{
+ fmt,
+ sync::{Mutex, MutexGuard},
+};
+use tokio_trace::{field, span, Event, Id, Metadata};
+
+/// A subscriber that is enabled but otherwise does nothing.
+struct EnabledSubscriber;
+
+impl tokio_trace::Subscriber for EnabledSubscriber {
+ fn new_span(&self, span: &Metadata, values: &field::ValueSet) -> Id {
+ let _ = (span, values);
+ Id::from_u64(0)
+ }
+
+ fn event(&self, event: &Event) {
+ let _ = event;
+ }
+
+ fn record(&self, span: &Id, values: &field::ValueSet) {
+ let _ = (span, values);
+ }
+
+ fn record_follows_from(&self, span: &Id, follows: &Id) {
+ let _ = (span, follows);
+ }
+
+ fn enabled(&self, metadata: &Metadata) -> bool {
+ let _ = metadata;
+ true
+ }
+
+ fn enter(&self, span: &Id) {
+ let _ = span;
+ }
+
+ fn exit(&self, span: &Id) {
+ let _ = span;
+ }
+}
+
+/// Simulates a subscriber that records span data.
+struct RecordingSubscriber(Mutex<String>);
+
+struct Recorder<'a>(MutexGuard<'a, String>);
+
+impl<'a> field::Record for Recorder<'a> {
+ fn record_debug(&mut self, _field: &field::Field, value: &fmt::Debug) {
+ use std::fmt::Write;
+ let _ = write!(&mut *self.0, "{:?}", value);
+ }
+}
+
+impl tokio_trace::Subscriber for RecordingSubscriber {
+ fn new_span(&self, _span: &Metadata, values: &field::ValueSet) -> Id {
+ let mut recorder = Recorder(self.0.lock().unwrap());
+ values.record(&mut recorder);
+ Id::from_u64(0)
+ }
+
+ fn record(&self, _span: &Id, values: &field::ValueSet) {
+ let mut recorder = Recorder(self.0.lock().unwrap());
+ values.record(&mut recorder);
+ }
+
+ fn event(&self, event: &Event) {
+ let mut recorder = Recorder(self.0.lock().unwrap());
+ event.record(&mut recorder);
+ }
+
+ fn record_follows_from(&self, span: &Id, follows: &Id) {
+ let _ = (span, follows);
+ }
+
+ fn enabled(&self, metadata: &Metadata) -> bool {
+ let _ = metadata;
+ true
+ }
+
+ fn enter(&self, span: &Id) {
+ let _ = span;
+ }
+
+ fn exit(&self, span: &Id) {
+ let _ = span;
+ }
+}
+
+const N_SPANS: usize = 100;
+
+#[bench]
+fn span_no_fields(b: &mut Bencher) {
+ tokio_trace::subscriber::with_default(EnabledSubscriber, || b.iter(|| span!("span")));
+}
+
+#[bench]
+fn span_repeatedly(b: &mut Bencher) {
+ #[inline]
+ fn mk_span(i: u64) -> tokio_trace::Span<'static> {
+ span!("span", i = i)
+ }
+
+ let n = test::black_box(N_SPANS);
+ tokio_trace::subscriber::with_default(EnabledSubscriber, || {
+ b.iter(|| (0..n).fold(mk_span(0), |_, i| mk_span(i as u64)))
+ });
+}
+
+#[bench]
+fn span_with_fields(b: &mut Bencher) {
+ tokio_trace::subscriber::with_default(EnabledSubscriber, || {
+ b.iter(|| {
+ span!(
+ "span",
+ foo = "foo",
+ bar = "bar",
+ baz = 3,
+ quuux = tokio_trace::field::debug(0.99)
+ )
+ })
+ });
+}
+
+#[bench]
+fn span_with_fields_record(b: &mut Bencher) {
+ let subscriber = RecordingSubscriber(Mutex::new(String::from("")));
+ tokio_trace::subscriber::with_default(subscriber, || {
+ b.iter(|| {
+ span!(
+ "span",
+ foo = "foo",
+ bar = "bar",
+ baz = 3,
+ quuux = tokio_trace::field::debug(0.99)
+ )
+ })
+ });
+}
diff --git a/tokio-trace/examples/counters.rs b/tokio-trace/examples/counters.rs
new file mode 100644
index 00000000..9c617c4c
--- /dev/null
+++ b/tokio-trace/examples/counters.rs
@@ -0,0 +1,138 @@
+#[macro_use]
+extern crate tokio_trace;
+
+use tokio_trace::{
+ field::{self, Field, Record},
+ span,
+ subscriber::{self, Subscriber},
+ Event, Id, Metadata,
+};
+
+use std::{
+ collections::HashMap,
+ fmt,
+ sync::{
+ atomic::{AtomicUsize, Ordering},
+ Arc, RwLock, RwLockReadGuard,
+ },
+};
+
+#[derive(Clone)]
+struct Counters(Arc<RwLock<HashMap<String, AtomicUsize>>>);
+
+struct CounterSubscriber {
+ ids: AtomicUsize,
+ counters: Counters,
+}
+
+struct Count<'a> {
+ counters: RwLockReadGuard<'a, HashMap<String, AtomicUsize>>,
+}
+
+impl<'a> Record for Count<'a> {
+ fn record_i64(&mut self, field: &Field, value: i64) {
+ if let Some(counter) = self.counters.get(field.name()) {
+ if value > 0 {
+ counter.fetch_add(value as usize, Ordering::Release);
+ } else {
+ counter.fetch_sub((value * -1) as usize, Ordering::Release);
+ }
+ };
+ }
+
+ fn record_u64(&mut self, field: &Field, value: u64) {
+ if let Some(counter) = self.counters.get(field.name()) {
+ counter.fetch_add(value as usize, Ordering::Release);
+ };
+ }
+
+ fn record_bool(&mut self, _: &Field, _: bool) {}
+ fn record_str(&mut self, _: &Field, _: &str) {}
+ fn record_debug(&mut self, _: &Field, _: &fmt::Debug) {}
+}
+
+impl CounterSubscriber {
+ fn recorder(&self) -> Count {
+ Count {
+ counters: self.counters.0.read().unwrap(),
+ }
+ }
+}
+
+impl Subscriber for CounterSubscriber {
+ fn register_callsite(&self, meta: &Metadata) -> subscriber::Interest {
+ let mut interest = subscriber::Interest::never();
+ for key in meta.fields() {
+ let name = key.name();
+ if name.contains("count") {
+ self.counters
+ .0
+ .write()
+ .unwrap()
+ .entry(name.to_owned())
+ .or_insert_with(|| AtomicUsize::new(0));
+ interest = subscriber::Interest::always();
+ }
+ }
+ interest
+ }
+
+ fn new_span(&self, _new_span: &Metadata, values: &field::ValueSet) -> Id {
+ values.record(&mut self.recorder());
+ let id = self.ids.fetch_add(1, Ordering::SeqCst);
+ Id::from_u64(id as u64)
+ }
+
+ fn record_follows_from(&self, _span: &Id, _follows: &Id) {
+ // unimplemented
+ }
+
+ fn record(&self, _: &Id, values: &field::ValueSet) {
+ values.record(&mut self.recorder())
+ }
+
+ fn event(&self, event: &Event) {
+ event.record(&mut self.recorder())
+ }
+
+ fn enabled(&self, metadata: &Metadata) -> bool {
+ metadata.fields().iter().any(|f| f.name().contains("count"))
+ }
+
+ fn enter(&self, _span: &Id) {}
+ fn exit(&self, _span: &Id) {}
+}
+
+impl Counters {
+ fn print_counters(&self) {
+ for (k, v) in self.0.read().unwrap().iter() {
+ println!("{}: {}", k, v.load(Ordering::Acquire));
+ }
+ }
+
+ fn new() -> (Self, CounterSubscriber) {
+ let counters = Counters(Arc::new(RwLock::new(HashMap::new())));
+ let subscriber = CounterSubscriber {
+ ids: AtomicUsize::new(0),
+ counters: counters.clone(),
+ };
+ (counters, subscriber)
+ }
+}
+
+fn main() {
+ let (counters, subscriber) = Counters::new();
+
+ tokio_trace::subscriber::with_default(subscriber, || {
+ let mut foo: u64 = 2;
+ span!("my_great_span", foo_count = &foo).enter(|| {
+ foo += 1;
+ info!({ yak_shaved = true, yak_count = 1 }, "hi from inside my span");
+ span!("my other span", foo_count = &foo, baz_count = 5).enter(|| {
+ warn!({ yak_shaved = false, yak_count = -1 }, "failed to shave yak");
+ });
+ });
+ });
+
+ counters.print_counters();
+}
diff --git a/tokio-trace/examples/sloggish/main.rs b/tokio-trace/examples/sloggish/main.rs
new file mode 100644
index 00000000..fb26a835
--- /dev/null
+++ b/tokio-trace/examples/sloggish/main.rs
@@ -0,0 +1,53 @@
+//! A simple example demonstrating how one might implement a custom
+//! subscriber.
+//!
+//! This subscriber implements a tree-structured logger similar to
+//! the "compact" formatter in [`slog-term`]. The demo mimicks the
+//! example output in the screenshot in the [`slog` README].
+//!
+//! Note that this logger isn't ready for actual production use.
+//! Several corners were cut to make the example simple.
+//!
+//! [`slog-term`]: https://docs.rs/slog-term/2.4.0/slog_term/
+//! [`slog` README]: https://github.com/slog-rs/slog#terminal-output-example
+#[macro_use]
+extern crate tokio_trace;
+
+use tokio_trace::field;
+
+mod sloggish_subscriber;
+use self::sloggish_subscriber::SloggishSubscriber;
+
+fn main() {
+ let subscriber = SloggishSubscriber::new(2);
+
+ tokio_trace::dispatcher::with_default(tokio_trace::Dispatch::new(subscriber), || {
+ span!("", version = &field::display(5.0)).enter(|| {
+ span!("server", host = "localhost", port = 8080).enter(|| {
+ info!("starting");
+ info!("listening");
+ let mut peer1 = span!("conn", peer_addr = "82.9.9.9", port = 42381);
+ peer1.enter(|| {
+ debug!("connected");
+ debug!({ length = 2 }, "message received");
+ });
+ let mut peer2 = span!("conn", peer_addr = "8.8.8.8", port = 18230);
+ peer2.enter(|| {
+ debug!("connected");
+ });
+ peer1.enter(|| {
+ warn!({ algo = "xor" }, "weak encryption requested");
+ debug!({ length = 8 }, "response sent");
+ debug!("disconnected");
+ });
+ peer2.enter(|| {
+ debug!({ length = 5 }, "message received");
+ debug!({ length = 8 }, "response sent");
+ debug!("disconnected");
+ });
+ warn!("internal error");
+ info!("exit");
+ })
+ });
+ });
+}
diff --git a/tokio-trace/examples/sloggish/sloggish_subscriber.rs b/tokio-trace/examples/sloggish/sloggish_subscriber.rs
new file mode 100644
index 00000000..4a93f935
--- /dev/null
+++ b/tokio-trace/examples/sloggish/sloggish_subscriber.rs
@@ -0,0 +1,293 @@
+//! A simple example demonstrating how one might implement a custom
+//! subscriber.
+//!
+//! This subscriber implements a tree-structured logger similar to
+//! the "compact" formatter in [`slog-term`]. The demo mimicks the
+//! example output in the screenshot in the [`slog` README].
+//!
+//! Note that this logger isn't ready for actual production use.
+//! Several corners were cut to make the example simple.
+//!
+//! [`slog-term`]: https://docs.rs/slog-term/2.4.0/slog_term/
+//! [`slog` README]: https://github.com/slog-rs/slog#terminal-output-example
+extern crate ansi_term;
+extern crate humantime;
+use self::ansi_term::{Color, Style};
+use super::tokio_trace::{
+ self,
+ field::{Field, Record},
+ Id, Level, Subscriber,
+};
+
+use std::{
+ cell::RefCell,
+ collections::HashMap,
+ fmt,
+ io::{self, Write},
+ sync::{
+ atomic::{AtomicUsize, Ordering},
+ Mutex,
+ },
+ thread,
+ time::SystemTime,
+};
+
+/// Tracks the currently executing span on a per-thread basis.
+#[derive(Clone)]
+pub struct CurrentSpanPerThread {
+ current: &'static thread::LocalKey<RefCell<Vec<Id>>>,
+}
+
+impl CurrentSpanPerThread {
+ pub fn new() -> Self {
+ thread_local! {
+ static CURRENT: RefCell<Vec<Id>> = RefCell::new(vec![]);
+ };
+ Self { current: &CURRENT }
+ }
+
+ /// Returns the [`Id`](::Id) of the span in which the current thread is
+ /// executing, or `None` if it is not inside of a span.
+ pub fn id(&self) -> Option<Id> {
+ self.current
+ .with(|current| current.borrow().last().cloned())
+ }
+
+ pub fn enter(&self, span: Id) {
+ self.current.with(|current| {
+ current.borrow_mut().push(span);
+ })
+ }
+
+ pub fn exit(&self) {
+ self.current.with(|current| {
+ let _ = current.borrow_mut().pop();
+ })
+ }
+}
+
+pub struct SloggishSubscriber {
+ // TODO: this can probably be unified with the "stack" that's used for
+ // printing?
+ current: CurrentSpanPerThread,
+ indent_amount: usize,
+ stderr: io::Stderr,
+ stack: Mutex<Vec<Id>>,
+ spans: Mutex<HashMap<Id, Span>>,
+ ids: AtomicUsize,
+}
+
+struct Span {
+ parent: Option<Id>,
+ kvs: Vec<(&'static str, String)>,
+}
+
+struct Event<'a> {
+ stderr: io::StderrLock<'a>,
+ comma: bool,
+}
+
+struct ColorLevel<'a>(&'a Level);
+
+impl<'a> fmt::Display for ColorLevel<'a> {
+ fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+ match self.0 {
+ &Level::TRACE => Color::Purple.paint("TRACE"),
+ &Level::DEBUG => Color::Blue.paint("DEBUG"),
+ &Level::INFO => Color::Green.paint("INFO "),
+ &Level::WARN => Color::Yellow.paint("WARN "),
+ &Level::ERROR => Color::Red.paint("ERROR"),
+ }
+ .fmt(f)
+ }
+}
+
+impl Span {
+ fn new(
+ parent: Option<Id>,
+ _meta: &tokio_trace::Metadata,
+ values: &tokio_trace::field::ValueSet,
+ ) -> Self {
+ let mut span = Self {
+ parent,
+ kvs: Vec::new(),
+ };
+ values.record(&mut span);
+ span
+ }
+}
+
+impl Record for Span {
+ fn record_debug(&mut self, field: &Field, value: &fmt::Debug) {
+ self.kvs.push((field.name(), format!("{:?}", value)))
+ }
+}
+
+impl<'a> Record for Event<'a> {
+ fn record_debug(&mut self,