itsscb/tracing
1
0
Fork 0
mirror of https://github.com/tokio-rs/tracing.git synced 2026-04-18 15:44:56 +00:00
Code Issues Packages Projects Releases Wiki Activity

subscriber: Introduce Registry; Refactor fmt::Subscriber in terms of Registry + Layers (#420)

Browse Source 
This branch introduces: 

- A registry build atop of https://github.com/hawkw/sharded-slab. Layers
  are expected to consume this registry through the traits `SpanData`,
  `LookupSpan`, and `LookupMetadata`. Layer-specific data, such as
  formatted spans and events, are stored in the `Extensions` typemap. Data
  is writable via the `ExtensionsMut` view struct of the typemap. This
  enables layers to read and write data that they are specifically
  interested in.

- The `tracing_subscriber::fmt::Subscriber` has been re-implemented in
  terms of `tracing_subscriber::registry::Registry` and
  `tracing_subscriber::fmt::Layer`.

- The event/field formatters have been modified (in a non-backwards
  compatible way) to accept a `tracing_subscriber::fmt::FmtContext`. A
  similar structure existed in `tracing_subscriber::fmt::Subscriber`, but
  it was not publicly exposed.

Resolves #135 Resolves #157 Resolves #391

Signed-off-by: David Barsky <me@davidbarsky.com>
Coauthored-by: Eliza Weisman <eliza@buoyant.io>
This commit is contained in:
David Barsky
2019-11-13 19:47:37 -05:00
committed by GitHub
parent 16fee661ac
commit 919a628a04
17 changed files with 1767 additions and 1121 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
examples/Cargo.toml
View File

@@ -10,7 +10,7 @@ edition = "2018"
tracing = "0.1"
tracing-core = "0.1"
tracing-tower = { version = "0.1.0", path = "../tracing-tower" }
tracing-subscriber = { version = "0.1", path = "../tracing-subscriber" }
tracing-subscriber = { version = "0.1", path = "../tracing-subscriber", features = ["json", "chrono"] }
tracing-futures = { version = "0.1.0", path = "../tracing-futures" }
tracing-attributes = "0.1.2"
tracing-log = { path = "../tracing-log", version = "0.1.1", features = ["env_logger"] }

10
tracing-subscriber/Cargo.toml
View File

@@ -21,9 +21,9 @@ keywords = ["logging", "tracing", "metrics", "subscriber"]
default = ["env-filter", "smallvec", "fmt", "ansi", "chrono", "tracing-log"]
env-filter = ["matchers", "regex", "lazy_static"]
fmt = ["owning_ref"]
fmt = ["registry"]
ansi = ["fmt", "ansi_term"]
registry_unstable = []
registry = ["sharded-slab"]
json = ["tracing-serde", "serde", "serde_json"]
# Alias for `env-filter`; renamed in version 0.1.2, and will be removed in 0.2.
@@ -41,7 +41,6 @@ lazy_static = { optional = true, version = "1" }
# fmt
tracing-log = { path = "../tracing-log", version = "0.1", optional = true, default-features = false, features = ["log-tracer", "std"] }
ansi_term = { version = "0.11", optional = true }
owning_ref = { version = "0.4.0", optional = true }
chrono = { version = "0.4", optional = true }
# only required by the json feature
@@ -50,7 +49,10 @@ serde = { version = "1.0", optional = true }
tracing-serde = { path = "../tracing-serde", optional = true }
# opt-in deps
parking_lot = { version = ">= 0.7, < 0.10", features = ["owning_ref"], optional = true }
parking_lot = { version = ">= 0.7, < 0.10", optional = true }
# registry
sharded-slab = { version = "0.0.6", optional = true }
[dev-dependencies]
tracing = "0.1"

531
tracing-subscriber/src/fmt/fmt_layer.rs Normal file
View File

@@ -0,0 +1,531 @@
use crate::{
field::RecordFields,
fmt::{format, FormatEvent, FormatFields, MakeWriter},
layer::{self, Context},
registry::{LookupSpan, SpanRef},
};
use std::{any::TypeId, cell::RefCell, fmt, io, marker::PhantomData, ops::Deref};
use tracing_core::{
span::{Attributes, Id, Record},
Event, Subscriber,
};
/// A [`Layer`] that logs formatted representations of `tracing` events.
///
/// [`Layer`]: ../layer/trait.Layer.html
#[derive(Debug)]
pub struct Layer<
S,
N = format::DefaultFields,
E = format::Format<format::Full>,
W = fn() -> io::Stdout,
> {
make_writer: W,
fmt_fields: N,
fmt_event: E,
_inner: PhantomData<S>,
}
/// A builder for [`Layer`](struct.Layer.html) that logs formatted representations of `tracing`
/// events and spans.
#[derive(Debug)]
pub struct LayerBuilder<
S,
N = format::DefaultFields,
E = format::Format<format::Full>,
W = fn() -> io::Stdout,
> {
fmt_fields: N,
fmt_event: E,
make_writer: W,
_inner: PhantomData<S>,
}
impl<S> Layer<S> {
/// Returns a new [`LayerBuilder`](struct.LayerBuilder.html) for configuring a `Layer`.
pub fn builder() -> LayerBuilder<S> {
LayerBuilder::default()
}
}
// This needs to be a seperate impl block because they place different bounds on the type paramaters.
impl<S, N, E, W> LayerBuilder<S, N, E, W>
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'writer> FormatFields<'writer> + 'static,
W: MakeWriter + 'static,
{
/// Sets the [event formatter][`FormatEvent`] that the layer will use to
/// format events.
///
/// The event formatter may be any type implementing the [`FormatEvent`]
/// trait, which is implemented for all functions taking a [`FmtContext`], a
/// `&mut dyn Write`, and an [`Event`].
///
/// # Examples
///
/// Setting a type implementing [`FormatEvent`] as the formatter:
/// ```rust
/// use tracing_subscriber::fmt::{self, format};
///
/// let layer = fmt::Layer::builder()
/// .event_format(format::Format::default().compact())
/// .finish();
/// # // this is necessary for type inference.
/// # use tracing_subscriber::Layer as _;
/// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
/// ```
/// [event formatter]: ../format/trait.FormatEvent.html
/// [`FmtContext`]: ../struct.FmtContext.html
/// [`Event`]: https://docs.rs/tracing/latest/tracing/struct.Event.html
pub fn event_format<E2>(self, e: E2) -> LayerBuilder<S, N, E2, W>
where
E2: FormatEvent<S, N> + 'static,
{
LayerBuilder {
fmt_fields: self.fmt_fields,
fmt_event: e,
make_writer: self.make_writer,
_inner: self._inner,
}
}
}
// This needs to be a seperate impl block because they place different bounds on the type paramaters.
impl<S, N, E, W> LayerBuilder<S, N, E, W> {
/// Sets the [`MakeWriter`] that the [`Layer`] being built will use to write events.
///
/// # Examples
///
/// Using `stderr` rather than `stdout`:
///
/// ```rust
/// use std::io;
/// use tracing_subscriber::fmt;
///
/// let layer = fmt::Layer::builder()
/// .with_writer(io::stderr)
/// .finish();
/// # // this is necessary for type inference.
/// # use tracing_subscriber::Layer as _;
/// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
/// ```
///
/// [`MakeWriter`]: ../fmt/trait.MakeWriter.html
/// [`Layer`]: ../layer/trait.Layer.html
pub fn with_writer<W2>(self, make_writer: W2) -> LayerBuilder<S, N, E, W2>
where
W2: MakeWriter + 'static,
{
LayerBuilder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
make_writer,
_inner: self._inner,
}
}
}
impl<S, N, L, T, W> LayerBuilder<S, N, format::Format<L, T>, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
/// Use the given [`timer`] for span and event timestamps.
///
/// See [`time`] for the provided timer implementations.
///
/// Note that using the `chrono` feature flag enables the
/// additional time formatters [`ChronoUtc`] and [`ChronoLocal`].
///
/// [`time`]: ./time/index.html
/// [`timer`]: ./time/trait.FormatTime.html
/// [`ChronoUtc`]: ./time/struct.ChronoUtc.html
/// [`ChronoLocal`]: ./time/struct.ChronoLocal.html
pub fn with_timer<T2>(self, timer: T2) -> LayerBuilder<S, N, format::Format<L, T2>, W> {
LayerBuilder {
fmt_event: self.fmt_event.with_timer(timer),
fmt_fields: self.fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
/// Do not emit timestamps with spans and event.
pub fn without_time(self) -> LayerBuilder<S, N, format::Format<L, ()>, W> {
LayerBuilder {
fmt_event: self.fmt_event.without_time(),
fmt_fields: self.fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
/// Enable ANSI encoding for formatted events.
#[cfg(feature = "ansi")]
pub fn with_ansi(self, ansi: bool) -> LayerBuilder<S, N, format::Format<L, T>, W> {
LayerBuilder {
fmt_event: self.fmt_event.with_ansi(ansi),
fmt_fields: self.fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
/// Sets whether or not an event's target is displayed.
pub fn with_target(self, display_target: bool) -> LayerBuilder<S, N, format::Format<L, T>, W> {
LayerBuilder {
fmt_event: self.fmt_event.with_target(display_target),
fmt_fields: self.fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
/// Sets the layer being built to use a [less verbose formatter](../fmt/format/struct.Compact.html).
pub fn compact(self) -> LayerBuilder<S, N, format::Format<format::Compact, T>, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
LayerBuilder {
fmt_event: self.fmt_event.compact(),
fmt_fields: self.fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
/// Sets the layer being built to use a [JSON formatter](../fmt/format/struct.Json.html).
#[cfg(feature = "json")]
pub fn json(self) -> LayerBuilder<S, format::JsonFields, format::Format<format::Json, T>, W> {
LayerBuilder {
fmt_event: self.fmt_event.json(),
fmt_fields: format::JsonFields::new(),
make_writer: self.make_writer,
_inner: self._inner,
}
}
}
impl<S, N, E, W> LayerBuilder<S, N, E, W> {
/// Sets the field formatter that the layer being built will use to record
/// fields.
pub fn fmt_fields<N2>(self, fmt_fields: N2) -> LayerBuilder<S, N2, E, W>
where
N2: for<'writer> FormatFields<'writer> + 'static,
{
LayerBuilder {
fmt_event: self.fmt_event,
fmt_fields,
make_writer: self.make_writer,
_inner: self._inner,
}
}
}
impl<S, N, E, W> LayerBuilder<S, N, E, W>
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<S, N> + 'static,
W: MakeWriter + 'static,
{
/// Builds a [`Layer`] with the provided configuration.
///
/// [`Layer`]: struct.Layer.html
pub fn finish(self) -> Layer<S, N, E, W> {
Layer {
make_writer: self.make_writer,
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
_inner: self._inner,
}
}
}
impl<S> Default for Layer<S>
where
S: Subscriber + for<'a> LookupSpan<'a>,
{
fn default() -> Self {
LayerBuilder::default().finish()
}
}
impl<S> Default for LayerBuilder<S> {
fn default() -> Self {
LayerBuilder {
fmt_fields: format::DefaultFields::default(),
fmt_event: format::Format::default(),
make_writer: io::stdout,
_inner: PhantomData,
}
}
}
impl<S, N, E, W> Layer<S, N, E, W>
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<S, N> + 'static,
W: MakeWriter + 'static,
{
#[inline]
fn make_ctx<'a>(&'a self, ctx: Context<'a, S>) -> FmtContext<'a, S, N> {
FmtContext {
ctx,
fmt_fields: &self.fmt_fields,
}
}
}
/// A formatted representation of a span's fields stored in its [extensions].
///
/// Because `FormattedFields` is generic over the type of the formatter that
/// produced it, multiple versions of a span's formatted fields can be stored in
/// the [`Extensions`][extensions] type-map. This means that when multiple
/// formatters are in use, each can store its own formatted representation
/// without conflicting.
///
/// [extensions]: ../registry/extensions/index.html
#[derive(Default)]
pub struct FormattedFields<E> {
_format_event: PhantomData<fn(E)>,
/// The formatted fields of a span.
pub fields: String,
}
impl<E> fmt::Debug for FormattedFields<E> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("FormattedFields")
.field("fields", &self.fields)
.finish()
}
}
impl<E> fmt::Display for FormattedFields<E> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.fields)
}
}
impl<E> Deref for FormattedFields<E> {
type Target = String;
fn deref(&self) -> &Self::Target {
&self.fields
}
}
// === impl FmtLayer ===
impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<S, N> + 'static,
W: MakeWriter + 'static,
{
fn new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
let span = ctx.span(id).expect("Span not found, this is a bug");
let mut extensions = span.extensions_mut();
let mut buf = String::new();
if self.fmt_fields.format_fields(&mut buf, attrs).is_ok() {
let fmt_fields = FormattedFields {
fields: buf,
_format_event: PhantomData::<fn(N)>,
};
extensions.insert(fmt_fields);
}
}
fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
let span = ctx.span(id).expect("Span not found, this is a bug");
let mut extensions = span.extensions_mut();
if let Some(FormattedFields { ref mut fields, .. }) =
extensions.get_mut::<FormattedFields<Self>>()
{
let _ = self.fmt_fields.format_fields(fields, values);
} else {
let mut buf = String::new();
if self.fmt_fields.format_fields(&mut buf, values).is_ok() {
let fmt_fields = FormattedFields {
fields: buf,
_format_event: PhantomData::<fn(N)>,
};
extensions.insert(fmt_fields);
}
}
}
fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
thread_local! {
static BUF: RefCell<String> = RefCell::new(String::new());
}
BUF.with(|buf| {
let borrow = buf.try_borrow_mut();
let mut a;
let mut b;
let mut buf = match borrow {
Ok(buf) => {
a = buf;
&mut *a
}
_ => {
b = String::new();
&mut b
}
};
let ctx = self.make_ctx(ctx);
if self.fmt_event.format_event(&ctx, &mut buf, event).is_ok() {
let mut writer = self.make_writer.make_writer();
let _ = io::Write::write_all(&mut writer, buf.as_bytes());
}
buf.clear();
});
}
unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
// This `downcast_raw` impl allows downcasting a `fmt` layer to any of
// its components (event formatter, field formatter, and `MakeWriter`)
// as well as to the layer's type itself. The potential use-cases for
// this *may* be somewhat niche, though...
match () {
_ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
_ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
_ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
_ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
_ => None,
}
}
}
/// Provides the current span context to a formatter.
pub struct FmtContext<'a, S, N> {
pub(crate) ctx: Context<'a, S>,
pub(crate) fmt_fields: &'a N,
}
impl<'a, S, N> fmt::Debug for FmtContext<'a, S, N> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("FmtContext").finish()
}
}
impl<'a, S, N> FormatFields<'a> for FmtContext<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
fn format_fields<R: RecordFields>(
&self,
writer: &'a mut dyn fmt::Write,
fields: R,
) -> fmt::Result {
self.fmt_fields.format_fields(writer, fields)
}
}
impl<'a, S, N> FmtContext<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
/// Visits every span in the current context with a closure.
///
/// The provided closure will be called first with the current span,
/// and then with that span's parent, and then that span's parent,
/// and so on until a root span is reached.
pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
where
F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
{
let current_span = self.ctx.current_span();
let id = match current_span.id() {
Some(id) => id,
None => return Ok(()),
};
let span = match self.ctx.span(id) {
Some(span) => span,
None => return Ok(()),
};
#[cfg(feature = "smallvec")]
type SpanRefVec<'span, S> = smallvec::SmallVec<[SpanRef<'span, S>; 16]>;
#[cfg(not(feature = "smallvec"))]
type SpanRefVec<'span, S> = Vec<SpanRef<'span, S>>;
// an alternative way to handle this would be to the recursive approach that
// `fmt` uses that _does not_ entail any allocation in this fmt'ing
// spans path.
let parents = span.parents().collect::<SpanRefVec<'_, _>>();
let mut iter = parents.iter().rev();
// visit all the parent spans...
while let Some(parent) = iter.next() {
f(parent)?;
}
// and finally, print out the current span.
f(&span)?;
Ok(())
}
}
#[cfg(test)]
mod test {
use crate::fmt::{
self,
format::{self, Format},
layer::Layer as _,
time,
};
use crate::Registry;
use tracing_core::dispatcher::Dispatch;
#[test]
fn impls() {
let f = Format::default().with_timer(time::Uptime::default());
let fmt = fmt::Layer::builder().event_format(f).finish();
let subscriber = fmt.with_subscriber(Registry::default());
let _dispatch = Dispatch::new(subscriber);
let f = format::Format::default();
let fmt = fmt::Layer::builder().event_format(f).finish();
let subscriber = fmt.with_subscriber(Registry::default());
let _dispatch = Dispatch::new(subscriber);
let f = format::Format::default().compact();
let fmt = fmt::Layer::builder().event_format(f).finish();
let subscriber = fmt.with_subscriber(Registry::default());
let _dispatch = Dispatch::new(subscriber);
}
#[test]
fn fmt_layer_downcasts() {
let f = format::Format::default();
let fmt = fmt::Layer::builder().event_format(f).finish();
let subscriber = fmt.with_subscriber(Registry::default());
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
}
#[test]
fn fmt_layer_downcasts_to_parts() {
let f = format::Format::default();
let fmt = fmt::Layer::builder().event_format(f).finish();
let subscriber = fmt.with_subscriber(Registry::default());
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
assert!(dispatch.downcast_ref::<format::Format>().is_some())
}
#[test]
fn is_lookup_meta() {
fn assert_lookup_meta<T: crate::registry::LookupMetadata>(_: T) {}
let fmt = fmt::Layer::builder().finish();
let subscriber = fmt.with_subscriber(Registry::default());
assert_lookup_meta(subscriber)
}
}

53
tracing-subscriber/src/fmt/format/json.rs
View File

@@ -1,5 +1,10 @@
use super::{span, Format, FormatEvent, FormatFields, FormatTime};
use crate::field::MakeVisitor;
use super::{Format, FormatEvent, FormatFields, FormatTime};
use crate::{
field::MakeVisitor,
fmt::fmt_layer::FmtContext,
fmt::fmt_layer::FormattedFields,
registry::{LookupMetadata, LookupSpan},
};
use serde::ser::{SerializeMap, Serializer as _};
use serde_json::Serializer;
use std::{
@@ -9,7 +14,7 @@ use std::{
};
use tracing_core::{
field::{self, Field},
Event,
Event, Subscriber,
};
use tracing_serde::AsSerde;
@@ -22,17 +27,22 @@ use tracing_log::NormalizeEvent;
#[derive(Default, Debug, Copy, Clone, Eq, PartialEq)]
pub struct Json;
impl<N, T> FormatEvent<N> for Format<Json, T>
impl<S, N, T> FormatEvent<S, N> for Format<Json, T>
where
N: for<'writer> FormatFields<'writer>,
S: Subscriber + for<'lookup> LookupSpan<'lookup> + LookupMetadata,
N: for<'writer> FormatFields<'writer> + 'static,
T: FormatTime,
{
fn format_event(
&self,
ctx: &span::Context<'_, N>,
ctx: &FmtContext<'_, S, N>,
writer: &mut dyn fmt::Write,
event: &Event<'_>,
) -> fmt::Result {
) -> fmt::Result
where
S: Subscriber + for<'a> LookupSpan<'a> + LookupMetadata,
{
use serde_json::{json, Value};
use tracing_serde::fields::AsMap;
let mut timestamp = String::new();
self.timer.format_time(&mut timestamp)?;
@@ -51,8 +61,24 @@ where
serializer.serialize_entry("timestamp", &timestamp)?;
serializer.serialize_entry("level", &meta.level().as_serde())?;
ctx.with_current(|(_, span)| serializer.serialize_entry("span", &span))
.unwrap_or(Ok(()))?;
let id = ctx.ctx.current_span();
let id = id.id();
if let Some(id) = id {
if let Some(span) = ctx.ctx.span(id) {
let ext = span.extensions();
let data = ext
.get::<FormattedFields<N>>()
.expect("Unable to find FormattedFields in extensions; this is a bug");
// TODO: let's _not_ do this, but this resolves
// https://github.com/tokio-rs/tracing/issues/391.
// We should probably rework this to use a `serde_json::Value` or something
// similar in a JSON-specific layer, but I'd (david)
// rather have a uglier fix now rather than shipping broken JSON.
let mut fields: Value = serde_json::from_str(&data)?;
fields["name"] = json!(span.metadata().name());
serializer.serialize_entry("span", &fields).unwrap_or(());
}
}
if self.display_target {
serializer.serialize_entry("target", meta.target())?;
@@ -240,14 +266,11 @@ impl<'a> fmt::Debug for WriteAdaptor<'a> {
#[cfg(test)]
mod test {
use crate::fmt::test::MockWriter;
use crate::fmt::time::FormatTime;
use crate::fmt::{test::MockWriter, time::FormatTime};
use lazy_static::lazy_static;
use tracing::{self, subscriber::with_default};
use std::fmt;
use std::sync::Mutex;
use std::{fmt, sync::Mutex};
struct MockTime;
impl FormatTime for MockTime {
@@ -265,7 +288,7 @@ mod test {
let make_writer = || MockWriter::new(&BUF);
let expected =
"{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"name\":\"json_span\",\"fields\":\"{\\\"answer\\\":42,\\\"number\\\":3}\"},\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
"{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
test_json(make_writer, expected, &BUF);
}

152
tracing-subscriber/src/fmt/format/mod.rs
View File

@@ -1,13 +1,19 @@
//! Formatters for logging `tracing` events.
use super::span;
use super::time::{self, FormatTime, SystemTime};
use crate::field::{MakeOutput, MakeVisitor, RecordFields, VisitFmt, VisitOutput};
use crate::{
field::{MakeOutput, MakeVisitor, RecordFields, VisitFmt, VisitOutput},
fmt::fmt_layer::FmtContext,
fmt::fmt_layer::FormattedFields,
registry::LookupSpan,
};
use std::fmt::{self, Write};
use std::marker::PhantomData;
use std::{
fmt::{self, Write},
marker::PhantomData,
};
use tracing_core::{
field::{self, Field, Visit},
Event, Level,
Event, Level, Subscriber,
};
#[cfg(feature = "tracing-log")]
@@ -32,22 +38,29 @@ pub use json::*;
/// signature as `format_event`.
///
/// [`FmtSubscriber`]: ../fmt/struct.Subscriber.html
pub trait FormatEvent<N> {
pub trait FormatEvent<S, N>
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'a> FormatFields<'a> + 'static,
{
/// Write a log message for `Event` in `Context` to the given `Write`.
fn format_event(
&self,
ctx: &span::Context<'_, N>,
ctx: &FmtContext<'_, S, N>,
writer: &mut dyn fmt::Write,
event: &Event<'_>,
) -> fmt::Result;
}
impl<N> FormatEvent<N>
for fn(&span::Context<'_, N>, &mut dyn fmt::Write, &Event<'_>) -> fmt::Result
impl<S, N> FormatEvent<S, N>
for fn(ctx: &FmtContext<'_, S, N>, &mut dyn fmt::Write, &Event<'_>) -> fmt::Result
where
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'a> FormatFields<'a> + 'static,
{
fn format_event(
&self,
ctx: &span::Context<'_, N>,
ctx: &FmtContext<'_, S, N>,
writer: &mut dyn fmt::Write,
event: &Event<'_>,
) -> fmt::Result {
@@ -120,9 +133,9 @@ pub struct Full;
#[derive(Debug, Clone)]
pub struct Format<F = Full, T = SystemTime> {
format: PhantomData<F>,
timer: T,
ansi: bool,
display_target: bool,
pub(crate) timer: T,
pub(crate) ansi: bool,
pub(crate) display_target: bool,
}
impl Default for Format<Full, SystemTime> {
@@ -206,14 +219,15 @@ impl<F, T> Format<F, T> {
}
}
impl<N, T> FormatEvent<N> for Format<Full, T>
impl<S, N, T> FormatEvent<S, N> for Format<Full, T>
where
N: for<'writer> FormatFields<'writer>,
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'a> FormatFields<'a> + 'static,
T: FormatTime,
{
fn format_event(
&self,
ctx: &span::Context<'_, N>,
ctx: &FmtContext<'_, S, N>,
writer: &mut dyn fmt::Write,
event: &Event<'_>,
) -> fmt::Result {
@@ -233,7 +247,7 @@ where
{
(
FmtLevel::new(meta.level(), self.ansi),
FullCtx::new(&ctx, self.ansi),
FullCtx::new(ctx, self.ansi),
)
}
#[cfg(not(feature = "ansi"))]
@@ -258,14 +272,15 @@ where
}
}
impl<N, T> FormatEvent<N> for Format<Compact, T>
impl<S, N, T> FormatEvent<S, N> for Format<Compact, T>
where
N: for<'writer> FormatFields<'writer>,
S: Subscriber + for<'a> LookupSpan<'a>,
N: for<'a> FormatFields<'a> + 'static,
T: FormatTime,
{
fn format_event(
&self,
ctx: &span::Context<'_, N>,
ctx: &FmtContext<'_, S, N>,
writer: &mut dyn fmt::Write,
event: &Event<'_>,
) -> fmt::Result {
@@ -305,8 +320,12 @@ where
}
)?;
ctx.format_fields(writer, event)?;
ctx.with_current(|(_, span)| write!(writer, " {}", span.fields()))
.unwrap_or(Ok(()))?;
let span = ctx.ctx.current_span();
if let Some(id) = span.id() {
if let Some(span) = ctx.ctx.metadata(id) {
write!(writer, "{}", span.fields()).unwrap_or(());
}
}
writeln!(writer)
}
}
@@ -461,39 +480,50 @@ impl<'a> fmt::Debug for DefaultVisitor<'a> {
}
}
struct FmtCtx<'a, N> {
ctx: &'a span::Context<'a, N>,
struct FmtCtx<'a, S, N> {
ctx: &'a FmtContext<'a, S, N>,
#[cfg(feature = "ansi")]
ansi: bool,
}
impl<'a, N: 'a> FmtCtx<'a, N> {
impl<'a, S, N: 'a> FmtCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
#[cfg(feature = "ansi")]
pub(crate) fn new(ctx: &'a span::Context<'a, N>, ansi: bool) -> Self {
pub(crate) fn new(ctx: &'a FmtContext<'_, S, N>, ansi: bool) -> Self {
Self { ctx, ansi }
}
#[cfg(not(feature = "ansi"))]
pub(crate) fn new(ctx: &'a span::Context<'a, N>) -> Self {
pub(crate) fn new(ctx: &'a FmtContext<'_, S, N>) -> Self {
Self { ctx }
}
}
#[cfg(feature = "ansi")]
impl<'a, N> fmt::Display for FmtCtx<'a, N> {
impl<'a, S, N: 'a> fmt::Display for FmtCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
let mut seen = false;
self.ctx.visit_spans(|_, span| {
self.ctx.visit_spans(|span| {
if seen {
f.pad(":")?;
}
seen = true;
let metadata = span.metadata();
if self.ansi {
write!(f, "{}", Style::new().bold().paint(span.name()))
write!(f, "{}", Style::new().bold().paint(metadata.name()))?;
} else {
write!(f, "{}", span.name())
write!(f, "{}", metadata.name())?;
}
Ok(())
})?;
if seen {
f.pad(" ")?;
@@ -503,7 +533,12 @@ impl<'a, N> fmt::Display for FmtCtx<'a, N> {
}
#[cfg(not(feature = "ansi"))]
impl<'a, N> fmt::Display for FmtCtx<'a, N> {
impl<'a, S, N> fmt::Display for FmtCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
for<'lookup> <S as LookupSpan<'a>>::Data: LookupSpan<'lookup>,
{
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
let mut seen = false;
self.ctx.visit_spans(|_, span| {
@@ -520,26 +555,38 @@ impl<'a, N> fmt::Display for FmtCtx<'a, N> {
}
}
struct FullCtx<'a, N> {
ctx: &'a span::Context<'a, N>,
struct FullCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
ctx: &'a FmtContext<'a, S, N>,
#[cfg(feature = "ansi")]
ansi: bool,
}
impl<'a, N: 'a> FullCtx<'a, N> {
impl<'a, S, N: 'a> FullCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
#[cfg(feature = "ansi")]
pub(crate) fn new(ctx: &'a span::Context<'a, N>, ansi: bool) -> Self {
pub(crate) fn new(ctx: &'a FmtContext<'a, S, N>, ansi: bool) -> Self {
Self { ctx, ansi }
}
#[cfg(not(feature = "ansi"))]
pub(crate) fn new(ctx: &'a span::Context<'a, N>) -> Self {
pub(crate) fn new(ctx: &'a FmtContext<'a, S, N>) -> Self {
Self { ctx }
}
}
#[cfg(feature = "ansi")]
impl<'a, N> fmt::Display for FullCtx<'a, N> {
impl<'a, S, N> fmt::Display for FullCtx<'a, S, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
let mut seen = false;
let style = if self.ansi {
@@ -547,15 +594,16 @@ impl<'a, N> fmt::Display for FullCtx<'a, N> {
} else {
Style::new()
};
self.ctx.visit_spans(|_, span| {
write!(f, "{}", style.paint(span.name()))?;
self.ctx.visit_spans(|span| {
let metadata = span.metadata();
write!(f, "{}", style.paint(metadata.name()))?;
seen = true;
let fields = span.fields();
if !fields.is_empty() {
write!(f, "{}{}{}", style.paint("{"), fields, style.paint("}"))?;
}
let ext = span.extensions();
let data = &ext
.get::<FormattedFields<N>>()
.expect("Unable to find FormattedFields in extensions; this is a bug");
write!(f, "{}{}{}", style.paint("{"), data, style.paint("}"))?;
":".fmt(f)
})?;
if seen {
@@ -566,10 +614,14 @@ impl<'a, N> fmt::Display for FullCtx<'a, N> {
}
#[cfg(not(feature = "ansi"))]
impl<'a, N> fmt::Display for FullCtx<'a, N> {
impl<'a, N> fmt::Display for FullCtx<'a, N>
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
N: for<'writer> FormatFields<'writer> + 'static,
{
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
let mut seen = false;
self.ctx.visit_spans(|_, span| {
self.ctx.visit_spans(|span| {
write!(f, "{}", span.name())?;
seen = true;
@@ -699,13 +751,11 @@ impl<'a, F> fmt::Debug for FieldFnVisitor<'a, F> {
#[cfg(test)]
mod test {
use crate::fmt::test::MockWriter;
use crate::fmt::time::FormatTime;
use crate::fmt::{test::MockWriter, time::FormatTime};
use lazy_static::lazy_static;
use tracing::{self, subscriber::with_default};
use std::fmt;
use std::sync::Mutex;
use std::{fmt, sync::Mutex};
struct MockTime;
impl FormatTime for MockTime {

480
tracing-subscriber/src/fmt/mod.rs
View File

@@ -57,7 +57,7 @@
//! .finish();
//! ```
//!
//! You can find the configuration methods for [`FmtSubscriber`] in [`fmt::Builder`].
//! You can find the configuration methods for [`FmtSubscriber`] in [`fmt::SubscriberBuilder`].
//!
//! ### Filters
//!
@@ -95,26 +95,26 @@
//! [`EnvFilter`]: ../filter/struct.EnvFilter.html
//! [`env_logger`]: https://docs.rs/env_logger/
//! [`filter`]: ../filter/index.html
//! [`fmt::Builder`]: ./struct.Builder.html
//! [`fmt::SubscriberBuilder`]: ./struct.SubscriberBuilder.html
//! [`FmtSubscriber`]: ./struct.Subscriber.html
//! [`Subscriber`]:
//! https://docs.rs/tracing/latest/tracing/trait.Subscriber.html
//! [`tracing`]: https://crates.io/crates/tracing
use std::{any::TypeId, cell::RefCell, error::Error, io};
use tracing_core::{subscriber::Interest, Event, Metadata};
use std::{any::TypeId, error::Error, io};
use tracing_core::{span, subscriber::Interest, Event, Metadata};
mod fmt_layer;
pub mod format;
mod span;
pub mod time;
pub mod writer;
pub use fmt_layer::{FormattedFields, Layer, LayerBuilder};
use crate::filter::LevelFilter;
use crate::layer::{self, Layer};
use crate::layer::Layer as _;
use crate::{filter::LevelFilter, layer, registry::Registry};
#[doc(inline)]
pub use self::{
format::{FormatEvent, FormatFields},
span::Context,
writer::MakeWriter,
};
@@ -133,53 +133,46 @@ pub struct Subscriber<
/// A `Subscriber` that logs formatted representations of `tracing` events.
/// This type only logs formatted events; it does not perform any filtering.
#[derive(Debug)]
pub struct Formatter<
pub type Formatter<
N = format::DefaultFields,
E = format::Format<format::Full>,
W = fn() -> io::Stdout,
> {
fmt_fields: N,
fmt_event: E,
spans: span::Store,
settings: Settings,
make_writer: W,
}
> = layer::Layered<fmt_layer::Layer<Registry, N, E, W>, Registry>;
/// Configures and constructs `Subscriber`s.
#[derive(Debug)]
pub struct Builder<
pub struct SubscriberBuilder<
N = format::DefaultFields,
E = format::Format<format::Full>,
F = LevelFilter,
W = fn() -> io::Stdout,
> {
filter: F,
fmt_fields: N,
fmt_event: E,
settings: Settings,
make_writer: W,
inner: LayerBuilder<Registry, N, E, W>,
}
#[derive(Debug)]
struct Settings {
inherit_fields: bool,
initial_span_capacity: usize,
}
/// Configures and constructs `Subscriber`s.
#[deprecated(since = "0.2.0", note = "renamed to `SubscriberBuilder`")]
pub type Builder<
N = format::DefaultFields,
E = format::Format<format::Full>,
F = LevelFilter,
W = fn() -> io::Stdout,
> = SubscriberBuilder<N, E, F, W>;
impl Subscriber {
/// The maximum [verbosity level] that is enabled by a `Subscriber` by
/// default.
///
/// This can be overridden with the [`Builder::with_max_level`] method.
/// This can be overridden with the [`SubscriberBuilder::with_max_level`] method.
///
/// [verbosity level]: https://docs.rs/tracing-core/0.1.5/tracing_core/struct.Level.html
/// [`Builder::with_max_level`]: struct.Builder.html#method.with_max_level
/// [`SubscriberBuilder::with_max_level`]: struct.SubscriberBuilder.html#method.with_max_level
pub const DEFAULT_MAX_LEVEL: LevelFilter = LevelFilter::INFO;
/// Returns a new `Builder` for configuring a format subscriber.
pub fn builder() -> Builder {
Builder::default()
/// Returns a new `SubscriberBuilder` for configuring a format subscriber.
pub fn builder() -> SubscriberBuilder {
SubscriberBuilder::default()
}
/// Returns a new format subscriber with the default configuration.
@@ -190,18 +183,20 @@ impl Subscriber {
impl Default for Subscriber {
fn default() -> Self {
Builder::default().finish()
SubscriberBuilder::default().finish()
}
}
// === impl Subscriber ===
impl<N, E, F, W> tracing_core::Subscriber for Subscriber<N, E, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<N> + 'static,
F: Layer<Formatter<N, E, W>> + 'static,
E: FormatEvent<Registry, N> + 'static,
F: layer::Layer<Formatter<N, E, W>> + 'static,
W: MakeWriter + 'static,
layer::Layered<F, Formatter<N, E, W>>: tracing_core::Subscriber,
fmt_layer::Layer<Registry, N, E, W>: layer::Layer<Registry>,
{
#[inline]
fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest {
@@ -268,7 +263,7 @@ where
}
}
#[cfg(feature = "registry_unstable")]
#[cfg(feature = "registry")]
impl<N, E, F, W> crate::registry::LookupMetadata for Subscriber<N, E, F, W>
where
layer::Layered<F, Formatter<N, E, W>>: crate::registry::LookupMetadata,
@@ -279,165 +274,33 @@ where
}
}
// === impl Formatter ===
// ===== impl SubscriberBuilder =====
impl<N, E, W> Formatter<N, E, W>
where
N: for<'writer> FormatFields<'writer>,
{
#[inline]
fn ctx(&self) -> span::Context<'_, N> {
span::Context::new(&self.spans, &self.fmt_fields)
}
}
impl<N, E, W> tracing_core::Subscriber for Formatter<N, E, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<N> + 'static,
W: MakeWriter + 'static,
{
fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest {
Interest::always()
}
fn enabled(&self, _: &Metadata<'_>) -> bool {
true
}
#[inline]
fn new_span(&self, attrs: &span::Attributes<'_>) -> span::Id {
self.spans.new_span(attrs, &self.fmt_fields)
}
#[inline]
fn record(&self, span: &span::Id, values: &span::Record<'_>) {
self.spans.record(span, values, &self.fmt_fields)
}
fn record_follows_from(&self, _span: &span::Id, _follows: &span::Id) {
// TODO: implement this please
}
fn event(&self, event: &Event<'_>) {
thread_local! {
static BUF: RefCell<String> = RefCell::new(String::new());
}
BUF.with(|buf| {
let borrow = buf.try_borrow_mut();
let mut a;
let mut b;
let buf = match borrow {
Ok(buf) => {
a = buf;
&mut *a
}
_ => {
b = String::new();
&mut b
}
};
if self.fmt_event.format_event(&self.ctx(), buf, event).is_ok() {
let mut writer = self.make_writer.make_writer();
let _ = io::Write::write_all(&mut writer, buf.as_bytes());
}
buf.clear();
});
}
fn enter(&self, id: &span::Id) {
// TODO: add on_enter hook
self.spans.push(id);
}
fn exit(&self, id: &span::Id) {
self.spans.pop(id);
}
fn current_span(&self) -> span::Current {
if let Some(id) = self.spans.current() {
if let Some(meta) = self.spans.get(&id).map(|span| span.metadata()) {
return span::Current::new(id, meta);
}
}
span::Current::none()
}
#[inline]
fn clone_span(&self, id: &span::Id) -> span::Id {
self.spans.clone_span(id)
}
#[inline]
fn try_close(&self, id: span::Id) -> bool {
self.spans.drop_span(id)
}
unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
match () {
_ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
// _ if id == TypeId::of::<F>() => Some(&self.filter as *const F as *const ()),
_ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
_ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
_ => None,
}
}
}
#[cfg(feature = "registry_unstable")]
impl<N, E, W> crate::registry::LookupMetadata for Formatter<N, E, W> {
fn metadata(&self, id: &span::Id) -> Option<&'static Metadata<'static>> {
self.spans.get(&id).map(|span| span.metadata())
}
}
// ===== impl Builder =====
impl Default for Builder {
impl Default for SubscriberBuilder {
fn default() -> Self {
Builder {
SubscriberBuilder {
filter: Subscriber::DEFAULT_MAX_LEVEL,
fmt_fields: format::DefaultFields::default(),
fmt_event: format::Format::default(),
settings: Settings::default(),
make_writer: io::stdout,
inner: Default::default(),
}
}
}
impl<N, E, F, W> Builder<N, E, F, W>
impl<N, E, F, W> SubscriberBuilder<N, E, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<N> + 'static,
E: FormatEvent<Registry, N> + 'static,
W: MakeWriter + 'static,
F: Layer<Formatter<N, E, W>> + 'static,
F: layer::Layer<Formatter<N, E, W>> + Send + Sync + 'static,
fmt_layer::Layer<Registry, N, E, W>: layer::Layer<Registry> + Send + Sync + 'static,
{
/// Finish the builder, returning a new `FmtSubscriber`.
pub fn finish(self) -> Subscriber<N, E, F, W> {
let subscriber = Formatter {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
spans: span::Store::with_capacity(self.settings.initial_span_capacity),
settings: self.settings,
make_writer: self.make_writer,
};
let subscriber = self.inner.finish().with_subscriber(Registry::default());
Subscriber {
inner: self.filter.with_subscriber(subscriber),
}
}
}
impl<N, E, F, W> Builder<N, E, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
E: FormatEvent<N> + 'static,
W: MakeWriter + 'static,
F: Layer<Formatter<N, E, W>> + 'static,
Subscriber<N, E, F, W>: Send + Sync,
{
/// Install this Subscriber as the global default if one is
/// not already set.
///
@@ -448,14 +311,14 @@ where
/// Returns an Error if the initialization was unsuccessful, likely
/// because a global subscriber was already installed by another
/// call to `try_init`.
pub fn try_init(self) -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
#[cfg(feature = "tracing-log")]
tracing_log::LogTracer::init()?;
pub fn try_init(self) -> Result<(), impl Error + Send + Sync + 'static> {
#[cfg(feature = "tracing-log/std")]
tracing_log::LogTracer::init().map_err(Box::new)?;
tracing_core::dispatcher::set_global_default(tracing_core::dispatcher::Dispatch::new(
self.finish(),
))
.map_err(Into::into)
.map_err(Box::new)
}
/// Install this Subscriber as the global default.
@@ -472,7 +335,7 @@ where
}
}
impl<N, L, T, F, W> Builder<N, format::Format<L, T>, F, W>
impl<N, L, T, F, W> SubscriberBuilder<N, format::Format<L, T>, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
@@ -487,47 +350,73 @@ where
/// [`timer`]: ./time/trait.FormatTime.html
/// [`ChronoUtc`]: ./time/struct.ChronoUtc.html
/// [`ChronoLocal`]: ./time/struct.ChronoLocal.html
pub fn with_timer<T2>(self, timer: T2) -> Builder<N, format::Format<L, T2>, F, W> {
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event.with_timer(timer),
pub fn with_timer<T2>(self, timer: T2) -> SubscriberBuilder<N, format::Format<L, T2>, F, W> {
SubscriberBuilder {
filter: self.filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner.with_timer(timer),
}
}
/// Do not emit timestamps with log messages.
pub fn without_time(self) -> Builder<N, format::Format<L, ()>, F, W> {
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event.without_time(),
pub fn without_time(self) -> SubscriberBuilder<N, format::Format<L, ()>, F, W> {
SubscriberBuilder {
filter: self.filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner.without_time(),
}
}
/// Enable ANSI encoding for formatted events.
#[cfg(feature = "ansi")]
pub fn with_ansi(self, ansi: bool) -> Builder<N, format::Format<L, T>, F, W> {
Builder {
fmt_event: self.fmt_event.with_ansi(ansi),
..self
pub fn with_ansi(self, ansi: bool) -> SubscriberBuilder<N, format::Format<L, T>, F, W> {
SubscriberBuilder {
filter: self.filter,
inner: self.inner.with_ansi(ansi),
}
}
/// Sets whether or not an event's target is displayed.
pub fn with_target(self, display_target: bool) -> Builder<N, format::Format<L, T>, F, W> {
Builder {
fmt_event: self.fmt_event.with_target(display_target),
..self
pub fn with_target(
self,
display_target: bool,
) -> SubscriberBuilder<N, format::Format<L, T>, F, W> {
SubscriberBuilder {
filter: self.filter,
inner: self.inner.with_target(display_target),
}
}
/// Sets the subscriber being built to use a less verbose formatter.
///
/// See [`format::Compact`].
pub fn compact(self) -> SubscriberBuilder<N, format::Format<format::Compact, T>, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
SubscriberBuilder {
filter: self.filter,
inner: self.inner.compact(),
}
}
/// Sets the subscriber being built to use a JSON formatter.
///
/// See [`format::Json`]
#[cfg(feature = "json")]
pub fn json(
self,
) -> SubscriberBuilder<format::JsonFields, format::Format<format::Json, T>, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
SubscriberBuilder {
filter: self.filter,
inner: self.inner.json(),
}
}
}
#[cfg(feature = "env-filter")]
impl<N, E, W> Builder<N, E, crate::EnvFilter, W>
impl<N, E, W> SubscriberBuilder<N, E, crate::EnvFilter, W>
where
Formatter<N, E, W>: tracing_core::Subscriber + 'static,
{
@@ -535,20 +424,18 @@ where
/// runtime.
pub fn with_filter_reloading(
self,
) -> Builder<N, E, crate::reload::Layer<crate::EnvFilter, Formatter<N, E, W>>, W> {
) -> SubscriberBuilder<N, E, crate::reload::Layer<crate::EnvFilter, Formatter<N, E, W>>, W>
{
let (filter, _) = crate::reload::Layer::new(self.filter);
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
SubscriberBuilder {
filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner,
}
}
}
#[cfg(feature = "env-filter")]
impl<N, E, W> Builder<N, E, crate::reload::Layer<crate::EnvFilter, Formatter<N, E, W>>, W>
impl<N, E, W> SubscriberBuilder<N, E, crate::reload::Layer<crate::EnvFilter, Formatter<N, E, W>>, W>
where
Formatter<N, E, W>: tracing_core::Subscriber + 'static,
{
@@ -559,7 +446,7 @@ where
}
}
impl<N, E, F, W> Builder<N, E, F, W> {
impl<N, E, F, W> SubscriberBuilder<N, E, F, W> {
/// Sets the Visitor that the subscriber being built will use to record
/// fields.
///
@@ -580,16 +467,13 @@ impl<N, E, F, W> Builder<N, E, F, W> {
/// .finish();
/// # drop(subscriber)
/// ```
pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Builder<N2, E, F, W>
pub fn fmt_fields<N2>(self, fmt_fields: N2) -> SubscriberBuilder<N2, E, F, W>
where
N2: for<'writer> FormatFields<'writer> + 'static,
{
Builder {
fmt_fields: fmt_fields.into(),
fmt_event: self.fmt_event,
SubscriberBuilder {
filter: self.filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner.fmt_fields(fmt_fields),
}
}
@@ -650,20 +534,16 @@ impl<N, E, F, W> Builder<N, E, F, W> {
pub fn with_env_filter(
self,
filter: impl Into<crate::EnvFilter>,
) -> Builder<N, E, crate::EnvFilter, W>
) -> SubscriberBuilder<N, E, crate::EnvFilter, W>
where
Formatter<N, E, W>: tracing_core::Subscriber + 'static,
{
let filter = filter.into();
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
SubscriberBuilder {
filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner,
}
}
/// Sets the [`EnvFilter`] that the subscriber will use to determine if
/// a span or event is enabled.
///
@@ -678,7 +558,7 @@ impl<N, E, F, W> Builder<N, E, F, W> {
pub fn with_filter(
self,
filter: impl Into<crate::EnvFilter>,
) -> Builder<N, E, crate::EnvFilter, W>
) -> SubscriberBuilder<N, E, crate::EnvFilter, W>
where
Formatter<N, E, W>: tracing_core::Subscriber + 'static,
{
@@ -717,93 +597,51 @@ impl<N, E, F, W> Builder<N, E, F, W> {
/// [verbosity level]: https://docs.rs/tracing-core/0.1.5/tracing_core/struct.Level.html
/// [`EnvFilter`]: ../filter/struct.EnvFilter.html
/// [`with_filter`]: #method.with_filter
pub fn with_max_level(self, filter: impl Into<LevelFilter>) -> Builder<N, E, LevelFilter, W> {
pub fn with_max_level(
self,
filter: impl Into<LevelFilter>,
) -> SubscriberBuilder<N, E, LevelFilter, W> {
let filter = filter.into();
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
SubscriberBuilder {
filter,
settings: self.settings,
make_writer: self.make_writer,
}
}
/// Sets the subscriber being built to use a less verbose formatter.
///
/// See [`format::Compact`].
pub fn compact(self) -> Builder<N, format::Format<format::Compact>, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
Builder {
fmt_event: format::Format::default().compact(),
filter: self.filter,
fmt_fields: self.fmt_fields,
settings: self.settings,
make_writer: self.make_writer,
}
}
/// Sets the subscriber being built to use a JSON formatter.
///
/// See [`format::Json`]
#[cfg(feature = "json")]
pub fn json(self) -> Builder<format::JsonFields, format::Format<format::Json>, F, W>
where
N: for<'writer> FormatFields<'writer> + 'static,
{
Builder {
fmt_event: format::Format::default().json(),
filter: self.filter,
fmt_fields: format::JsonFields::default(),
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner,
}
}
/// Sets the function that the subscriber being built should use to format
/// events that occur.
pub fn on_event<E2>(self, fmt_event: E2) -> Builder<N, E2, F, W>
#[deprecated(since = "0.2.0", note = "renamed to `event_format`.")]
pub fn on_event<E2>(self, fmt_event: E2) -> SubscriberBuilder<N, E2, F, W>
where
E2: FormatEvent<N> + 'static,
E2: FormatEvent<Registry, N> + 'static,
N: for<'writer> FormatFields<'writer> + 'static,
W: MakeWriter + 'static,
{
Builder {
fmt_fields: self.fmt_fields,
fmt_event,
self.event_format(fmt_event)
}
/// Sets the function that the subscriber being built should use to format
/// events that occur.
pub fn event_format<E2>(self, fmt_event: E2) -> SubscriberBuilder<N, E2, F, W>
where
E2: FormatEvent<Registry, N> + 'static,
N: for<'writer> FormatFields<'writer> + 'static,
W: MakeWriter + 'static,
{
SubscriberBuilder {
filter: self.filter,
settings: self.settings,
make_writer: self.make_writer,
inner: self.inner.event_format(fmt_event),
}
}
/// Sets whether or not spans inherit their parents' field values (disabled
/// by default).
#[deprecated(since = "0.2.0", note = "this no longer does anything")]
pub fn inherit_fields(self, inherit_fields: bool) -> Self {
Builder {
settings: Settings {
inherit_fields,
..self.settings
},
..self
}
let _ = inherit_fields;
self
}
// TODO(eliza): should this be publicly exposed?
// /// Configures the initial capacity for the span slab used to store
// /// in-progress span data. This may be used for tuning the subscriber's
// /// allocation performance, but in general does not need to be manually configured..
// pub fn initial_span_capacity(self, initial_span_capacity: usize) -> Self {
// Builder {
// settings: Settings {
// initial_span_capacity,
// ..self.settings
// },
// ..self
// }
// }
}
impl<N, E, F, W> Builder<N, E, F, W> {
/// Sets the [`MakeWriter`] that the subscriber being built will use to write events.
///
/// # Examples
@@ -819,25 +657,13 @@ impl<N, E, F, W> Builder<N, E, F, W> {
/// ```
///
/// [`MakeWriter`]: trait.MakeWriter.html
pub fn with_writer<W2>(self, make_writer: W2) -> Builder<N, E, F, W2>
pub fn with_writer<W2>(self, make_writer: W2) -> SubscriberBuilder<N, E, F, W2>
where
W2: MakeWriter + 'static,
{
Builder {
fmt_fields: self.fmt_fields,
fmt_event: self.fmt_event,
SubscriberBuilder {
filter: self.filter,
settings: self.settings,
make_writer,
}
}
}
impl Default for Settings {
fn default() -> Self {
Self {
inherit_fields: false,
initial_span_capacity: 32,
inner: self.inner.with_writer(make_writer),
}
}
}
@@ -859,7 +685,7 @@ impl Default for Settings {
/// https://docs.rs/tracing-log/0.1.0/tracing_log/struct.LogTracer.html
/// [`RUST_LOG` environment variable]:
/// ../filter/struct.EnvFilter.html#associatedconstant.DEFAULT_ENV
pub fn try_init() -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
pub fn try_init() -> Result<(), impl Error + Send + Sync + 'static> {
Subscriber::builder()
.with_env_filter(crate::EnvFilter::from_default_env())
.try_init()
@@ -883,11 +709,19 @@ pub fn init() {
#[cfg(test)]
mod test {
use super::writer::MakeWriter;
use super::*;
use crate::fmt::Subscriber;
use std::io;
use std::sync::{Mutex, MutexGuard, TryLockError};
use crate::{
filter::LevelFilter,
fmt::{
format::{self, Format},
time,
writer::MakeWriter,
Subscriber,
},
};
use std::{
io,
sync::{Mutex, MutexGuard, TryLockError},
};
use tracing_core::dispatcher::Dispatch;
pub(crate) struct MockWriter<'a> {
@@ -941,29 +775,29 @@ mod test {
#[test]
fn impls() {
let f = format::Format::default().with_timer(time::Uptime::default());
let subscriber = Subscriber::builder().on_event(f).finish();
let f = Format::default().with_timer(time::Uptime::default());
let subscriber = Subscriber::builder().event_format(f).finish();
let _dispatch = Dispatch::new(subscriber);
let f = format::Format::default();
let subscriber = Subscriber::builder().on_event(f).finish();
let subscriber = Subscriber::builder().event_format(f).finish();
let _dispatch = Dispatch::new(subscriber);
let f = format::Format::default().compact();
let subscriber = Subscriber::builder().on_event(f).finish();
let subscriber = Subscriber::builder().event_format(f).finish();
let _dispatch = Dispatch::new(subscriber);
}
#[test]
fn subscriber_downcasts() {
let subscriber = Subscriber::new();
let subscriber = Subscriber::builder().finish();
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<Subscriber>().is_some());
}
#[test]
fn subscriber_downcasts_to_parts() {
let subscriber = Subscriber::builder().finish();
let subscriber = Subscriber::new();
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
assert!(dispatch.downcast_ref::<LevelFilter>().is_some());
@@ -971,9 +805,9 @@ mod test {
}
#[test]
#[cfg(feature = "registry_unstable")]
fn is_lookup_meta() {
fn assert_lookup_meta<T: crate::registry::LookupMetadata>(_: T) {}
assert_lookup_meta(Subscriber::builder().finish())
let subscriber = Subscriber::new();
assert_lookup_meta(subscriber)
}
}

643
tracing-subscriber/src/fmt/span.rs
View File

@@ -1,643 +0,0 @@
use std::{
cell::RefCell,
fmt, mem, str,
sync::atomic::{self, AtomicUsize, Ordering},
};
use crate::sync::{RwLock, RwLockReadGuard, RwLockWriteGuard};
use owning_ref::OwningHandle;
use std::collections::HashSet;
pub(crate) use tracing_core::span::{Attributes, Current, Id, Record};
use tracing_core::{dispatcher, Metadata};
use super::format::FormatFields;
#[cfg(feature = "json")]
use serde::{ser::SerializeStruct, Serialize, Serializer};
pub struct Span<'a> {
lock: OwningHandle<RwLockReadGuard<'a, Slab>, RwLockReadGuard<'a, Slot>>,
}
/// Represents the `Subscriber`'s view of the current span context to a
/// formatter.
#[derive(Debug)]
pub struct Context<'a, F> {
store: &'a Store,
fmt_fields: &'a F,
}
/// Stores data associated with currently-active spans.
#[derive(Debug)]
pub(crate) struct Store {
// Active span data is stored in a slab of span slots. Each slot has its own
// read-write lock to guard against concurrent modification to its data.
// Thus, we can modify any individual slot by acquiring a read lock on the
// slab, and using that lock to acquire a write lock on the slot we wish to
// modify. It is only necessary to acquire the write lock here when the
// slab itself has to be modified (i.e., to allocate more slots).
inner: RwLock<Slab>,
// The head of the slab's "free list".
next: AtomicUsize,
}
#[derive(Debug)]
pub(crate) struct Data {
parent: Option<Id>,
metadata: &'static Metadata<'static>,
ref_count: AtomicUsize,
is_empty: bool,
}
#[derive(Debug)]
struct Slab {
slab: Vec<RwLock<Slot>>,
}
#[derive(Debug)]
struct Slot {
fields: String,
span: State,
}
#[derive(Debug)]
enum State {
Full(Data),
Empty(usize),
}
struct ContextId {
id: Id,
duplicate: bool,
}
struct SpanStack {
stack: Vec<ContextId>,
ids: HashSet<Id>,
}
impl SpanStack {
fn new() -> Self {
SpanStack {
stack: vec![],
ids: HashSet::new(),
}
}
fn push(&mut self, id: Id) {
let duplicate = self.ids.contains(&id);
if !duplicate {
self.ids.insert(id.clone());
}
self.stack.push(ContextId { id, duplicate })
}
fn pop(&mut self, expected_id: &Id) -> Option<Id> {
if &self.stack.last()?.id == expected_id {
let ContextId { id, duplicate } = self.stack.pop()?;
if !duplicate {
self.ids.remove(&id);
}
Some(id)
} else {
None
}
}
#[inline]
fn current(&self) -> Option<&Id> {
self.stack
.iter()
.rev()
.find(|context_id| !context_id.duplicate)
.map(|context_id| &context_id.id)
}
}
thread_local! {
static CONTEXT: RefCell<SpanStack> = RefCell::new(SpanStack::new());
}
macro_rules! debug_panic {
($($args:tt)*) => {
#[cfg(debug_assertions)] {
if !std::thread::panicking() {
panic!($($args)*)
}
}
}
}
// ===== impl Span =====
impl<'a> Span<'a> {
pub fn name(&self) -> &'static str {
match self.lock.span {
State::Full(ref data) => data.metadata.name(),
State::Empty(_) => unreachable!(),
}
}
pub fn metadata(&self) -> &'static Metadata<'static> {
match self.lock.span {
State::Full(ref data) => data.metadata,
State::Empty(_) => unreachable!(),
}
}
pub fn fields(&self) -> &str {
self.lock.fields.as_ref()
}
pub fn parent(&self) -> Option<&Id> {
match self.lock.span {
State::Full(ref data) => data.parent.as_ref(),
State::Empty(_) => unreachable!(),
}
}
#[inline(always)]
fn with_parent<'store, F, E>(
self,
my_id: &Id,
last_id: Option<&Id>,
f: &mut F,
store: &'store Store,
) -> Result<(), E>
where
F: FnMut(&Id, Span<'_>) -> Result<(), E>,
{
if let Some(parent_id) = self.parent() {
if Some(parent_id) != last_id {
if let Some(parent) = store.get(parent_id) {
parent.with_parent(parent_id, Some(my_id), f, store)?;
} else {
debug_panic!("missing span for {:?}; this is a bug", parent_id);
}
}
}
f(my_id, self)
}
}
impl<'a> fmt::Debug for Span<'a> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("Span")
.field("name", &self.name())
.field("parent", &self.parent())
.field("metadata", self.metadata())
.field("fields", &self.fields())
.finish()
}
}
#[cfg(feature = "json")]
impl<'a> Serialize for Span<'a> {
fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
where
S: Serializer,
{
let mut serializer = serializer.serialize_struct("Span", 2)?;
serializer.serialize_field("name", self.name())?;
serializer.serialize_field("fields", self.fields())?;
serializer.end()
}
}
// ===== impl Context =====
impl<'a, F> Context<'a, F> {
/// Applies a function to each span in the current trace context.
///
/// The function is applied in order, beginning with the root of the trace,
/// and ending with the current span. If the function returns an error,
/// this will short-circuit.
///
/// If invoked from outside of a span, the function will not be applied.
///
/// Note that if we are currently unwinding, this will do nothing, rather
/// than potentially causing a double panic.
pub fn visit_spans<N, E>(&self, mut f: N) -> Result<(), E>
where
N: FnMut(&Id, Span<'_>) -> Result<(), E>,
{
CONTEXT
.try_with(|current| {
if let Some(id) = current.borrow().current() {
if let Some(span) = self.store.get(id) {
// with_parent uses the call stack to visit the span
// stack in reverse order, without having to allocate
// a buffer.
return span.with_parent(id, None, &mut f, self.store);
} else {
debug_panic!("missing span for {:?}; this is a bug", id);
}
}
Ok(())
})
.unwrap_or(Ok(()))
}
/// Executes a closure with the reference to the current span.
pub fn with_current<N, R>(&self, f: N) -> Option<R>
where
N: FnOnce((&Id, Span<'_>)) -> R,
{
// If the lock is poisoned or the thread local has already been
// destroyed, we might be in the middle of unwinding, so this
// will just do nothing rather than cause a double panic.
CONTEXT
.try_with(|current| {
if let Some(id) = current.borrow().current() {
if let Some(span) = self.store.get(&id) {
return Some(f((&id, span)));
} else {
debug_panic!("missing span for {:?}, this is a bug", id);
}
}
None
})
.ok()?
}
pub(crate) fn new(store: &'a Store, fmt_fields: &'a F) -> Self {
Self { store, fmt_fields }
}
}
impl<'ctx, 'writer, F> FormatFields<'writer> for Context<'ctx, F>
where
F: FormatFields<'writer>,
{
#[inline]
fn format_fields<R>(&self, writer: &'writer mut dyn fmt::Write, fields: R) -> fmt::Result
where
R: crate::field::RecordFields,
{
self.fmt_fields.format_fields(writer, fields)
}
}
#[inline]
fn idx_to_id(idx: usize) -> Id {
Id::from_u64(idx as u64 + 1)
}
#[inline]
fn id_to_idx(id: &Id) -> usize {
id.into_u64() as usize - 1
}
impl Store {
pub(crate) fn with_capacity(capacity: usize) -> Self {
Store {
inner: RwLock::new(Slab {
slab: Vec::with_capacity(capacity),
}),
next: AtomicUsize::new(0),
}
}
#[inline]
pub(crate) fn current(&self) -> Option<Id> {
CONTEXT
.try_with(|current| current.borrow().current().cloned())
.ok()?
}
pub(crate) fn push(&self, id: &Id) {
let _ = CONTEXT.try_with(|current| current.borrow_mut().push(self.clone_span(id)));
}
pub(crate) fn pop(&self, expected_id: &Id) {
let id = CONTEXT
.try_with(|current| current.borrow_mut().pop(expected_id))
.ok()
.and_then(|i| i);
if let Some(id) = id {
let _ = self.drop_span(id);
}
}
/// Inserts a new span with the given data and fields into the slab,
/// returning an ID for that span.
///
/// If there are empty slots in the slab previously allocated for spans
/// which have since been closed, the allocation and span ID of the most
/// recently emptied span will be reused. Otherwise, a new allocation will
/// be added to the slab.
#[inline]
pub(crate) fn new_span<F>(&self, attrs: &Attributes<'_>, fmt_fields: &F) -> Id
where
F: for<'writer> FormatFields<'writer>,
{
let mut span = Some(Data::new(attrs, self));
// The slab's free list is a modification of Treiber's lock-free stack,
// using slab indices instead of pointers, and with a provision for
// growing the slab when needed.
//
// In order to insert a new span into the slab, we "pop" the next free
// index from the stack.
loop {
// Acquire a snapshot of the head of the free list.
let head = self.next.load(Ordering::Relaxed);
{
// Try to insert the span without modifying the overall
// structure of the stack.
let this = try_lock!(self.inner.read(), else return Id::from_u64(0xDEADFACE));
// Can we insert without reallocating?
if head < this.slab.len() {
// If someone else is writing to the head slot, we need to
// acquire a new snapshot!
if let Ok(mut slot) = this.slab[head].try_write() {
// Is the slot we locked actually empty? If not, fall
// through and try to grow the slab.
if let Some(next) = slot.next() {
// Is our snapshot still valid?
if self.next.compare_and_swap(head, next, Ordering::Release) == head {
// We can finally fill the slot!
slot.fill(span.take().unwrap(), attrs, fmt_fields);
return idx_to_id(head);
}
}
}
// Our snapshot got stale, try again!
atomic::spin_loop_hint();
continue;
}
}
// We need to grow the slab, and must acquire a write lock.
if let Ok(mut this) = self.inner.try_write() {
let len = this.slab.len();
// Insert the span into a new slot.
let slot = Slot::new(span.take().unwrap(), attrs, fmt_fields);
this.slab.push(RwLock::new(slot));
// TODO: can we grow the slab in chunks to avoid having to
// realloc as often?
// Update the head pointer and return.
self.next.store(len + 1, Ordering::Release);
return idx_to_id(len);
}
atomic::spin_loop_hint();
}
}
/// Returns a `Span` to the span with the specified `id`, if one
/// currently exists.
#[inline]
pub(crate) fn get(&self, id: &Id) -> Option<Span<'_>> {
let read = try_lock!(self.inner.read(), else return None);
let lock = OwningHandle::try_new(read, |slab| {
unsafe { &*slab }.read_slot(id_to_idx(id)).ok_or(())
})
.ok()?;
Some(Span { lock })
}
/// Records that the span with the given `id` has the given `fields`.
#[inline]
pub(crate) fn record<F>(&self, id: &Id, fields: &Record<'_>, fmt_fields: &F)
where
F: for<'writer> FormatFields<'writer>,
{
let slab = try_lock!(self.inner.read(), else return);
let slot = slab.write_slot(id_to_idx(id));
if let Some(mut slot) = slot {
slot.record(fields, fmt_fields);
}
}
/// Decrements the reference count of the span with the given `id`, and
/// removes the span if it is zero.
///
/// The allocated span slot will be reused when a new span is created.
pub(crate) fn drop_span(&self, id: Id) -> bool {
let this = try_lock!(self.inner.read(), else return false);
let idx = id_to_idx(&id);
if !this
.slab
.get(idx)
.and_then(|lock| {
let span = try_lock!(lock.read(), else return None);
Some(span.drop_ref())
})
.unwrap_or_else(|| {
debug_panic!("tried to drop {:?} but it no longer exists!", id);
false
})
{
return false;
}
// Synchronize only if we are actually removing the span (stolen
// from std::Arc);
atomic::fence(Ordering::Acquire);
this.remove(&self.next, idx);
true
}
pub(crate) fn clone_span(&self, id: &Id) -> Id {
let this = try_lock!(self.inner.read(), else return id.clone());
let idx = id_to_idx(id);
if let Some(span) = this.slab.get(idx).and_then(|span| span.read().ok()) {
span.clone_ref();
} else {
debug_panic!(
"tried to clone {:?}, but no span exists with that ID. this is a bug!",
id
);
}
id.clone()
}
}
impl Data {
pub(crate) fn new(attrs: &Attributes<'_>, store: &Store) -> Self {
let parent = if attrs.is_root() {
None
} else if attrs.is_contextual() {
store.current().as_ref().map(|id| store.clone_span(id))
} else {
attrs.parent().map(|id| store.clone_span(id))
};
Self {
metadata: attrs.metadata(),
parent,
ref_count: AtomicUsize::new(1),
is_empty: true,
}
}
}
impl Drop for Data {
fn drop(&mut self) {
// We have to actually unpack the option inside the `get_default`
// closure, since it is a `FnMut`, but testing that there _is_ a value
// here lets us avoid the thread-local access if we don't need the
// dispatcher at all.
if self.parent.is_some() {
dispatcher::get_default(|subscriber| {
if let Some(parent) = self.parent.take() {
let _ = subscriber.try_close(parent);
}
})
}
}
}
impl Slot {
fn new<F>(mut data: Data, attrs: &Attributes<'_>, fmt_fields: &F) -> Self
where
F: for<'writer> FormatFields<'writer>,
{
let mut fields = String::new();
fmt_fields
.format_fields(&mut fields, attrs)
.expect("formatting to string should not fail");
if fields.is_empty() {
data.is_empty = false;
}
Self {
fields,
span: State::Full(data),
}
}
fn next(&self) -> Option<usize> {
match self.span {
State::Empty(next) => Some(next),
_ => None,
}
}
fn fill<F>(&mut self, mut data: Data, attrs: &Attributes<'_>, fmt_fields: &F) -> usize
where
F: for<'writer> FormatFields<'writer>,
{
let fields = &mut self.fields;
fmt_fields
.format_fields(fields, attrs)
.expect("formatting to string should not fail");
if fields.is_empty() {
data.is_empty = false;
}
match mem::replace(&mut self.span, State::Full(data)) {
State::Empty(next) => next,
State::Full(_) => unreachable!("tried to fill a full slot"),
}
}
fn record<F>(&mut self, fields: &Record<'_>, fmt_fields: &F)
where
F: for<'writer> FormatFields<'writer>,
{
let state = &mut self.span;
let buf = &mut self.fields;
match state {
State::Empty(_) => return,
State::Full(ref mut data) => {
fmt_fields
.format_fields(buf, fields)
.expect("formatting to string should not fail");
if buf.is_empty() {
data.is_empty = false;
}
}
}
}
fn drop_ref(&self) -> bool {
match self.span {
State::Full(ref data) => {
let refs = data.ref_count.fetch_sub(1, Ordering::Release);
debug_assert!(
if std::thread::panicking() {
// don't cause a double panic, even if the ref-count is wrong...
true
} else {
refs != std::usize::MAX
},
"reference count overflow!"
);
refs == 1
}
State::Empty(_) => false,
}
}
fn clone_ref(&self) {
match self.span {
State::Full(ref data) => {
let _refs = data.ref_count.fetch_add(1, Ordering::Release);
debug_assert!(_refs != 0, "tried to clone a span that already closed!");
}
State::Empty(_) => {
unreachable!("tried to clone a ref to a span that no longer exists, this is a bug")
}
}
}
}
impl Slab {
#[inline]
fn write_slot(&self, idx: usize) -> Option<RwLockWriteGuard<'_, Slot>> {
self.slab.get(idx).and_then(|slot| slot.write().ok())
}
#[inline]
fn read_slot(&self, idx: usize) -> Option<RwLockReadGuard<'_, Slot>> {
self.slab
.get(idx)
.and_then(|slot| slot.read().ok())
.and_then(|lock| match lock.span {
State::Empty(_) => None,
State::Full(_) => Some(lock),
})
}
/// Remove a span slot from the slab.
fn remove(&self, next: &AtomicUsize, idx: usize) -> Option<Data> {
// Again we are essentially implementing a variant of Treiber's stack
// algorithm to push the removed span's index into the free list.
loop {
// Get a snapshot of the current free-list head.
let head = next.load(Ordering::Relaxed);
// Empty the data stored at that slot.
let mut slot = try_lock!(self.slab[idx].write(), else return None);
let data = match mem::replace(&mut slot.span, State::Empty(head)) {
State::Full(data) => data,
state => {
// The slot has already been emptied; leave
// everything as it was and return `None`!
slot.span = state;
return None;
}
};
// Is our snapshot still valid?
if next.compare_and_swap(head, idx, Ordering::Release) == head {
// Empty the string but retain the allocated capacity
// for future spans.
slot.fields.clear();
return Some(data);
}
atomic::spin_loop_hint();
}
}
}

8
tracing-subscriber/src/fmt/writer.rs
View File

@@ -55,6 +55,7 @@ where
#[cfg(test)]
mod test {
use super::MakeWriter;
use crate::fmt::format::Format;
use crate::fmt::test::{MockMakeWriter, MockWriter};
use crate::fmt::Subscriber;
use lazy_static::lazy_static;
@@ -69,17 +70,18 @@ mod test {
let subscriber = {
#[cfg(feature = "ansi")]
{
let f = Format::default().without_time().with_ansi(false);
Subscriber::builder()
.event_format(f)
.with_writer(make_writer)
.without_time()
.with_ansi(false)
.finish()
}
#[cfg(not(feature = "ansi"))]
{
let f = Format::default().without_time();
Subscriber::builder()
.event_format(f)
.with_writer(make_writer)
.without_time()
.finish()
}
};

48
tracing-subscriber/src/layer.rs
View File

@@ -6,8 +6,8 @@ use tracing_core::{
Event,
};
#[cfg(feature = "registry_unstable")]
use crate::registry::LookupMetadata;
#[cfg(feature = "registry")]
use crate::registry::{self, LookupMetadata, LookupSpan};
use std::{any::TypeId, marker::PhantomData};
/// A composable handler for `tracing` events.
@@ -607,7 +607,7 @@ where
}
}
#[cfg(feature = "registry_unstable")]
#[cfg(feature = "registry")]
impl<L, S> LookupMetadata for Layered<L, S>
where
S: Subscriber + LookupMetadata,
@@ -691,7 +691,7 @@ impl<'a, S: Subscriber> Context<'a, S> {
}
}
/// Returns metadata for tne span with the given `id`, if it exists.
/// Returns metadata for the span with the given `id`, if it exists.
///
/// If this returns `None`, then no span exists for that ID (either it has
/// closed or the ID is invalid).
@@ -706,7 +706,7 @@ impl<'a, S: Subscriber> Context<'a, S> {
///
/// [`LookupMetadata`]: ../registry/trait.LookupMetadata.html
#[inline]
#[cfg(feature = "registry_unstable")]
#[cfg(feature = "registry")]
pub fn metadata(&self, id: &span::Id) -> Option<&'static Metadata<'static>>
where
S: LookupMetadata,
@@ -714,9 +714,43 @@ impl<'a, S: Subscriber> Context<'a, S> {
self.subscriber.as_ref()?.metadata(id)
}
/// Returns `true` if an active span exists for the given `Id`.
/// Returns [stored data] for the span with the given `id`, if it exists.
///
/// If this returns `None`, then no span exists for that ID (either it has
/// closed or the ID is invalid).
///
/// **Note**: This requires the wrapped subscriber to implement the
/// [`LookupSpan`] trait. `Layer` implementations that wish to use this
/// function can bound their `Subscriber` type parameter with
/// ```rust,ignore
/// where S: Subscriber + for<'span> LookupSpan<'span>,
/// ```
/// or similar.
///
/// [stored data]: ../registry/struct.SpanRef.html
/// [`LookupSpan`]: ../registry/trait.LookupSpan.html
#[inline]
#[cfg(feature = "registry_unstable")]
#[cfg(feature = "registry")]
pub fn span(&'a self, id: &span::Id) -> Option<registry::SpanRef<'a, S>>
where
S: LookupSpan<'a>,
{
self.subscriber.as_ref()?.span(id)
}
/// Returns `true` if an active span exists for the given `Id`.
///
/// **Note**: This requires the wrapped subscriber to implement the
/// [`LookupMetadata`] trait. `Layer` implementations that wish to use this
/// function can bound their `Subscriber` type parameter with
/// ```rust,ignore
/// where S: Subscriber + LookupMetadata,
/// ```
/// or similar.
///
/// [`LookupMetadata`]: ../registry/trait.LookupMetadata.html
#[inline]
#[cfg(feature = "registry")]
pub fn exists(&self, id: &span::Id) -> bool
where
S: LookupMetadata,

7
tracing-subscriber/src/lib.rs
View File

@@ -27,7 +27,7 @@
//! Enabled by default.
//! - `ansi`: Enables `fmt` support for ANSI terminal colors. Enabled by
//! default.
//! - `registry_unstable`: enables the experimental [`registry`] module.
//! - `registry`: enables the experimental [`registry`] module.
//! - `json`: Enables `fmt` support for JSON output. In JSON output, the ANSI feature does nothing.
//!
//! ### Optional Dependencies
@@ -99,7 +99,7 @@ pub mod filter;
pub mod fmt;
pub mod layer;
pub mod prelude;
#[cfg(feature = "registry_unstable")]
#[cfg(feature = "registry")]
pub mod registry;
pub mod reload;
pub(crate) mod sync;
@@ -111,6 +111,9 @@ pub use filter::{EnvFilter, Filter};
pub use layer::Layer;
#[cfg(feature = "registry")]
pub use registry::Registry;
#[cfg(feature = "fmt")]
pub use fmt::Subscriber as FmtSubscriber;

204
tracing-subscriber/src/registry/extensions.rs Normal file
View File

@@ -0,0 +1,204 @@
// taken from https://github.com/hyperium/http/blob/master/src/extensions.rs.
use crate::sync::{RwLockReadGuard, RwLockWriteGuard};
use std::{
any::{Any, TypeId},
collections::HashMap,
fmt,
hash::{BuildHasherDefault, Hasher},
};
#[allow(warnings)]
type AnyMap = HashMap<TypeId, Box<dyn Any + Send + Sync>, BuildHasherDefault<IdHasher>>;
/// With TypeIds as keys, there's no need to hash them. They are already hashes
/// themselves, coming from the compiler. The IdHasher holds the u64 of
/// the TypeId, and then returns it, instead of doing any bit fiddling.
#[derive(Default, Debug)]
struct IdHasher(u64);
impl Hasher for IdHasher {
fn write(&mut self, _: &[u8]) {
unreachable!("TypeId calls write_u64");
}
#[inline]
fn write_u64(&mut self, id: u64) {
self.0 = id;
}
#[inline]
fn finish(&self) -> u64 {
self.0
}
}
/// An immutable, read-only reference to a Span's extensions.
#[derive(Debug)]
pub struct Extensions<'a> {
inner: RwLockReadGuard<'a, ExtensionsInner>,
}
impl<'a> Extensions<'a> {
pub(crate) fn new(inner: RwLockReadGuard<'a, ExtensionsInner>) -> Self {
Self { inner }
}
/// Immutably borrows a type previously inserted into this `Extensions`.
pub fn get<T: 'static>(&self) -> Option<&T> {
self.inner.get::<T>()
}
}
/// An mutable reference to a Span's extensions.
#[derive(Debug)]
pub struct ExtensionsMut<'a> {
inner: RwLockWriteGuard<'a, ExtensionsInner>,
}
impl<'a> ExtensionsMut<'a> {
pub(crate) fn new(inner: RwLockWriteGuard<'a, ExtensionsInner>) -> Self {
Self { inner }
}
/// Insert a type into this `Extensions`.
///
/// Note that extensions are _not_
/// `Layer`-specific—they are _span_-specific. This means that
/// other layers can access and mutate extensions that
/// a different Layer recorded. For example, an application might
/// have a layer that records execution timings, alongside a layer
/// that reports spans and events to a distributed
/// tracing system that requires timestamps for spans.
/// Ideally, if one layer records a timestamp _x_, the other layer
/// should be able to reuse timestamp _x_.
///
/// Therefore, extensions should generally be newtypes, rather than common
/// types like [`String`](https://doc.rust-lang.org/std/string/struct.String.html), to avoid accidental
/// cross-`Layer` clobbering.
///
/// ## Panics
///
/// If `T` is already present in `Extensions`, then this method will panic.
pub fn insert<T: Send + Sync + 'static>(&mut self, val: T) {
assert!(self.replace(val).is_none())
}
/// Replaces an existing `T` into this extensions.
///
/// If `T` is not present, `Option::None` will be returned.
pub fn replace<T: Send + Sync + 'static>(&mut self, val: T) -> Option<T> {
self.inner.insert(val)
}
/// Get a mutable reference to a type previously inserted on this `ExtensionsMut`.
pub fn get_mut<T: 'static>(&mut self) -> Option<&mut T> {
self.inner.get_mut::<T>()
}
/// Remove a type from this `Extensions`.
///
/// If a extension of this type existed, it will be returned.
pub fn remove<T: Send + Sync + 'static>(&mut self) -> Option<T> {
self.inner.remove::<T>()
}
}
/// A type map of span extensions.
///
/// [ExtensionsInner] is used by [Data] to store and
/// span-specific data. A given [Layer] can read and write
/// data that it is interested in recording and emitting.
#[derive(Default)]
pub(crate) struct ExtensionsInner {
// If extensions are never used, no need to carry around an empty HashMap.
// That's 3 words. Instead, this is only 1 word.
map: Option<Box<AnyMap>>,
}
impl ExtensionsInner {
/// Create an empty `Extensions`.
#[inline]
pub(crate) fn new() -> ExtensionsInner {
ExtensionsInner { map: None }
}
/// Insert a type into this `Extensions`.
///
/// If a extension of this type already existed, it will
/// be returned.
pub(crate) fn insert<T: Send + Sync + 'static>(&mut self, val: T) -> Option<T> {
self.map
.get_or_insert_with(|| Box::new(HashMap::default()))
.insert(TypeId::of::<T>(), Box::new(val))
.and_then(|boxed| {
#[allow(warnings)]
{
(boxed as Box<Any + 'static>)
.downcast()
.ok()
.map(|boxed| *boxed)
}
})
}
/// Get a reference to a type previously inserted on this `Extensions`.
pub(crate) fn get<T: 'static>(&self) -> Option<&T> {
self.map
.as_ref()
.and_then(|map| map.get(&TypeId::of::<T>()))
.and_then(|boxed| (&**boxed as &(dyn Any + 'static)).downcast_ref())
}
/// Get a mutable reference to a type previously inserted on this `Extensions`.
pub(crate) fn get_mut<T: 'static>(&mut self) -> Option<&mut T> {
self.map
.as_mut()
.and_then(|map| map.get_mut(&TypeId::of::<T>()))
.and_then(|boxed| (&mut **boxed as &mut (dyn Any + 'static)).downcast_mut())
}
/// Remove a type from this `Extensions`.
///
/// If a extension of this type existed, it will be returned.
pub(crate) fn remove<T: Send + Sync + 'static>(&mut self) -> Option<T> {
self.map
.as_mut()
.and_then(|map| map.remove(&TypeId::of::<T>()))
.and_then(|boxed| {
#[allow(warnings)]
{
(boxed as Box<Any + 'static>)
.downcast()
.ok()
.map(|boxed| *boxed)
}
})
}
}
impl fmt::Debug for ExtensionsInner {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.debug_struct("Extensions").finish()
}
}
#[test]
fn test_extensions() {
#[derive(Debug, PartialEq)]
struct MyType(i32);
let mut extensions = ExtensionsInner::new();
extensions.insert(5i32);
extensions.insert(MyType(10));
assert_eq!(extensions.get(), Some(&5i32));
assert_eq!(extensions.get_mut(), Some(&mut 5i32));
assert_eq!(extensions.remove::<i32>(), Some(5i32));
assert!(extensions.get::<i32>().is_none());
assert_eq!(extensions.get::<bool>(), None);
assert_eq!(extensions.get(), Some(&MyType(10)));
}

277
tracing-subscriber/src/registry/mod.rs
View File

@@ -1,19 +1,83 @@
//! **EXPERIMENTAL**: Storage for span data shared by multiple [`Layer`]s.
//! Storage for span data shared by multiple [`Layer`]s.
//!
//! This module is experimental. Although potential breaking changes will be
//! avoided when possible, we reserve the right to make breaking changes to this
//! module until it is no longer experimental.
//! ## Using the Span Registry
//!
//! Add the `registry_unstable` feature to your `Cargo.toml` to enable
//! this module:
//! This module provides the [`Registry`] type, a [`Subscriber`] implementation
//! which tracks per-span data and exposes it to [`Layer`]s. When a `Registry`
//! is used as the base `Subscriber` of a `Layer` stack, the
//! [`layer::Context`][ctx] type will provide methods allowing `Layer`s to
//! [look up span data][lookup] stored in the registry. While [`Registry`] is a
//! reasonable default for storing spans and events, other stores that implement
//! [`LookupSpan`], [`LookupMetadata`], and [`Subscriber`] on themselves (with
//! [`SpanData`] implemented on the data _inside_ the store) can be used as a
//! drop-in replacement.
//!
//! ```toml
//! [dependencies.tracing-subscriber]
//! features = ["registry_unstable"]
//! For example, we might create a `Registry` and add multiple `Layer`s like so:
//! ```rust
//! use tracing_subscriber::{registry::Registry, Layer};
//! # use tracing_core::Subscriber;
//! # fn main() {
//! # pub struct FooLayer {}
//! # pub struct BarLayer {}
//! # impl<S: Subscriber> Layer<S> for FooLayer {}
//! # impl<S: Subscriber> Layer<S> for BarLayer {}
//! # impl FooLayer {
//! # fn new() -> Self { Self {} }
//! # }
//! # impl BarLayer {
//! # fn new() -> Self { Self { }}
//! # }
//!
//! let subscriber = FooLayer::new()
//! .and_then(BarLayer::new())
//! .with_subscriber(Registry::default());
//! # }
//! ```
//!
//! [`Layer`]: ../layer/struct.Layer.html
use tracing_core::{span::Id, Metadata};
//! If a type implementing `Layer` depends on the functionality of a `Registry`
//! implementation, it should bound its `Subscriber` type parameter with the
//! [`LookupSpan`] trait, like so:
//!
//! ```rust
//! use tracing_subscriber::{registry, Layer};
//! use tracing_core::Subscriber;
//!
//! # fn main() {
//! pub struct MyLayer {
//! // ...
//! }
//!
//! impl<S> Layer<S> for MyLayer
//! where
//! S: Subscriber + for<'a> registry::LookupSpan<'a>,
//! {
//! // ...
//! }
//! # }
//! ```
//! When this bound is added, the `Layer` implementation will be guaranteed
//! access to the [`Context`][ctx] methods, such as [`Context::span`][lookup], that
//! require the root subscriber to be a registry.
//!
//! [`Layer`]: ../struct.Layer.html
//! [`Subscriber`]:
//! https://docs.rs/tracing-core/latest/tracing_core/subscriber/trait.Subscriber.html
//! [`Registry`]: struct.Registry.html
//! [ctx]: ../layer/struct.Context.html
//! [lookup]: ../layer/struct.Context.html#method.span
//! [`LookupSpan`]: trait.LookupSpan.html
//! [`LookupMetadata`]: trait.LookupMetadata.html
//! [`SpanData`]: trait.SpanData.html
use tracing_core::{field::FieldSet, span::Id, Metadata};
/// A module containing a type map of span extensions.
mod extensions;
mod sharded;
mod stack;
pub use extensions::{Extensions, ExtensionsMut};
pub use sharded::{Data, Registry};
/// Provides access to stored span metadata.
///
/// Subscribers which store span metadata and associate it with span IDs should
@@ -45,3 +109,194 @@ pub trait LookupMetadata {
self.metadata(id).is_some()
}
}
/// Provides access to stored span data.
///
/// Subscribers which store span data and associate it with span IDs should
/// implement this trait; if they do, any [`Layer`]s wrapping them can look up
/// metadata via the [`Context`] type's [`span()`] method.
///
/// [`Layer`]: ../layer/struct.Layer.html
/// [`Context`]: ../layer/struct.Context.html
/// [`span()`]: ../layer/struct.Context.html#method.metadata
pub trait LookupSpan<'a> {
/// The type of span data stored in this registry.
type Data: SpanData<'a>;
/// Returns the [`SpanData`] for a given `Id`, if it exists.
///
/// **Note**: users of the `LookupSpan` trait should typically call the
/// [`span`] method rather than this method. The `span` method is
/// implemented by calling `span_data`, but returns a reference which is
/// capable of performing more sophisiticated queries.
///
/// [`SpanData`]: trait.SpanData.html
/// [`span`]: #method.span
fn span_data(&'a self, id: &Id) -> Option<Self::Data>;
/// Returns a [`SpanRef`] for the span with the given `Id`, if it exists.
///
/// A `SpanRef` is similar to [`SpanData`], but it allows performing
/// additional lookups against the registryr that stores the wrapped data.
///
/// In general, _users_ of the `LookupSpan` trait should use this method
/// rather than the [`span_data`] method; while _implementors_ of this trait
/// should only implement `span_data`.
///
/// [`SpanRef`]: struct.SpanRef.html
/// [`SpanData`]: trait.SpanData.html
/// [`span_data`]: #method.span_data
fn span(&'a self, id: &Id) -> Option<SpanRef<'_, Self>>
where
Self: Sized,
{
let data = self.span_data(id)?;
Some(SpanRef {
registry: self,
data,
})
}
}
/// A stored representation of data associated with a span.
pub trait SpanData<'a> {
/// Returns this span's ID.
fn id(&self) -> Id;
/// Returns a reference to the span's `Metadata`.
fn metadata(&self) -> &'static Metadata<'static>;
/// Returns a reference to the ID
fn parent(&self) -> Option<&Id>;
/// Returns a reference to this span's `Extensions`.
///
/// The extensions may be used by `Layer`s to store additional data
/// describing the span.
fn extensions(&self) -> Extensions<'_>;
/// Returns a mutable reference to this span's `Extensions`.
///
/// The extensions may be used by `Layer`s to store additional data
/// describing the span.
fn extensions_mut(&self) -> ExtensionsMut<'_>;
}
/// A reference to [span data] and the associated [registry].
///
/// This type implements all the same methods as [`SpanData`][span data], and
/// provides additional methods for querying the registry based on values from
/// the span.
///
/// [span data]: trait.SpanData.html
/// [registry]: trait.LookupSpan.html
#[derive(Debug)]
pub struct SpanRef<'a, R: LookupSpan<'a>> {
registry: &'a R,
data: R::Data,
}
/// An iterator over the parents of a span.
///
/// This is returned by the [`SpanRef::parents`] method.
///
/// [`SpanRef::parents`]: struct.SpanRef.html#method.parents
#[derive(Debug)]
pub struct Parents<'a, R> {
registry: &'a R,
next: Option<Id>,
}
impl<'a, R> SpanRef<'a, R>
where
R: LookupSpan<'a>,
{
/// Returns this span's ID.
pub fn id(&self) -> Id {
self.data.id()
}
/// Returns a static reference to the span's metadata.
pub fn metadata(&self) -> &'static Metadata<'static> {
self.data.metadata()
}
/// Returns the span's name,
pub fn name(&self) -> &'static str {
self.data.metadata().name()
}
/// Returns a list of [fields] defined by the span.
///
/// [fields]: https://docs.rs/tracing-core/latest/tracing_core/field/index.html
pub fn fields(&self) -> &FieldSet {
self.data.metadata().fields()
}
/// Returns the ID of this span's parent, or `None` if this span is the root
/// of its trace tree.
pub fn parent_id(&self) -> Option<&Id> {
self.data.parent()
}
/// Returns a `SpanRef` describing this span's parent, or `None` if this
/// span is the root of its trace tree.
pub fn parent(&self) -> Option<Self> {
let id = self.data.parent()?;
let data = self.registry.span_data(id)?;
Some(Self {
registry: self.registry,
data,
})
}
/// Returns an iterator over all parents of this span.
///
/// The iterator will first return the span's immediate parent, followed by
/// that span's parent, followed by _that_ span's parent, and so on, until a
/// it reaches a root span.
pub fn parents(&self) -> Parents<'_, R> {
Parents {
registry: self.registry,
next: self.parent().map(|parent| parent.id()),
}
}
/// Returns a reference to this span's `Extensions`.
///
/// The extensions may be used by `Layer`s to store additional data
/// describing the span.
pub fn extensions(&self) -> Extensions<'_> {
self.data.extensions()
}
/// Returns a mutable reference to this span's `Extensions`.
///
/// The extensions may be used by `Layer`s to store additional data
/// describing the span.
pub fn extensions_mut(&self) -> ExtensionsMut<'_> {
self.data.extensions_mut()
}
}
impl<'a, R> Iterator for Parents<'a, R>
where
R: LookupSpan<'a>,
{
type Item = SpanRef<'a, R>;
fn next(&mut self) -> Option<Self::Item> {
let id = self.next.take()?;
let span = self.registry.span(&id)?;
self.next = span.parent().map(|parent| parent.id());
Some(span)
}
}
impl<L> LookupMetadata for L
where
L: for<'a> LookupSpan<'a>,
{
fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>> {
self.span_data(id).map(|data| data.metadata())
}
}

272
tracing-subscriber/src/registry/sharded.rs Normal file
View File

@@ -0,0 +1,272 @@
use sharded_slab::{Guard, Slab};
use super::stack::SpanStack;
use crate::{
registry::{
extensions::{Extensions, ExtensionsInner, ExtensionsMut},
LookupSpan, SpanData,
},
sync::RwLock,
};
use std::{
cell::RefCell,
sync::atomic::{fence, AtomicUsize, Ordering},
};
use tracing_core::{
dispatcher,
span::{self, Current, Id},
Event, Interest, Metadata, Subscriber,
};
/// A shared, reusable store for spans.
///
/// A `Registry` is a [`Subscriber`] around which multiple [`Layer`]s
/// implementing various behaviors may be [added]. Unlike other types
/// implementing `Subscriber` `Registry` does not actually record traces itself:
/// instead, it collects and stores span data that is exposed to any `Layer`s
/// wrapping it through implementations of the [`LookupSpan`] and
/// [`LookupMetadata`] traits. The `Registry` is responsible for storing span
/// metadata, recording relationships between spans, and tracking which spans
/// are active and whicb are closed. In addition, it provides a mechanism
/// `Layer`s to store user-defined per-span data, called [extensions], in the
/// registry. This allows `Layer`-specific data to benefit from the `Registry`'s
/// high-performance concurrent storage.
///
/// This registry is implemented using a [lock-free sharded slab][slab], and is
/// highly optimized for concurrent access.
///
/// [slab]: https://docs.rs/crate/sharded-slab/
/// [`Subscriber`]:
/// https://docs.rs/crate/tracing-core/latest/tracing_core/subscriber/trait.Subscriber.html
/// [`Layer`]: ../trait.Layer.html
/// [added]: ../trait.Layer.html#method.with_subscriber
/// [`LookupSpan`]: trait.LookupSpan.html
/// [`LookupMetadata`]: trait.LookupMetadata.html
/// [extensions]: extensions/index.html
#[derive(Debug)]
pub struct Registry {
spans: Slab<DataInner>,
}
/// Span data stored in a [`Registry`].
///
/// The registry stores well-known data defined by tracing: span relationships,
/// metadata and reference counts. Additional user-defined data provided by
/// [`Layer`s], such as formatted fields, metrics, or distributed traces should
/// be stored in the [extensions] typemap.
///
/// [`Registry`]: struct.Registry.html
/// [`Layer`s]: ../trait.Layer.html
/// [extensions]: extensions/index.html
#[derive(Debug)]
pub struct Data<'a> {
inner: Guard<'a, DataInner>,
}
#[derive(Debug)]
struct DataInner {
metadata: &'static Metadata<'static>,
parent: Option<Id>,
ref_count: AtomicUsize,
pub(crate) extensions: RwLock<ExtensionsInner>,
}
// === impl Registry ===
impl Default for Registry {
fn default() -> Self {
Self { spans: Slab::new() }
}
}
#[inline]
fn idx_to_id(idx: usize) -> Id {
Id::from_u64(idx as u64 + 1)
}
#[inline]
fn id_to_idx(id: &Id) -> usize {
id.into_u64() as usize - 1
}
impl Registry {
fn insert(&self, s: DataInner) -> Option<usize> {
self.spans.insert(s)
}
fn get(&self, id: &Id) -> Option<Guard<'_, DataInner>> {
self.spans.get(id_to_idx(id))
}
}
thread_local! {
static CURRENT_SPANS: RefCell<SpanStack> = RefCell::new(SpanStack::new());
}
impl Subscriber for Registry {
fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest {
Interest::always()
}
fn enabled(&self, _: &Metadata<'_>) -> bool {
true
}
#[inline]
fn new_span(&self, attrs: &span::Attributes<'_>) -> span::Id {
let parent = if attrs.is_root() {
None
} else if attrs.is_contextual() {
self.current_span().id().map(|id| self.clone_span(id))
} else {
attrs.parent().map(|id| self.clone_span(id))
};
let s = DataInner {
metadata: attrs.metadata(),
parent,
ref_count: AtomicUsize::new(1),
extensions: RwLock::new(ExtensionsInner::new()),
};
let id = self.insert(s).expect("Unable to allocate another span");
idx_to_id(id)
}
/// This is intentionally not implemented, as recording fields
/// on a span is the responsibility of layers atop of this registry.
#[inline]
fn record(&self, _: &span::Id, _: &span::Record<'_>) {}
fn record_follows_from(&self, _span: &span::Id, _follows: &span::Id) {}
/// This is intentionally not implemented, as recording events
/// is the responsibility of layers atop of this registry.
fn event(&self, _: &Event<'_>) {}
fn enter(&self, id: &span::Id) {
CURRENT_SPANS.with(|spans| {
spans.borrow_mut().push(self.clone_span(id));
})
}
fn exit(&self, id: &span::Id) {
if let Some(id) = CURRENT_SPANS.with(|spans| spans.borrow_mut().pop(id)) {
dispatcher::get_default(|dispatch| dispatch.try_close(id.clone()));
}
}
fn clone_span(&self, id: &span::Id) -> span::Id {
let span = self
.get(&id)
.unwrap_or_else(|| panic!("tried to clone {:?}, but no span exists with that ID", id));
// Like `std::sync::Arc`, adds to the ref count (on clone) don't require
// a strong ordering; if we call` clone_span`, the reference count must
// always at least 1. The only synchronization necessary is between
// calls to `try_close`: we have to ensure that all threads have
// dropped their refs to the span before the span is closed.
let refs = span.ref_count.fetch_add(1, Ordering::Relaxed);
assert!(refs != 0, "tried to clone a span that already closed");
id.clone()
}
fn current_span(&self) -> Current {
CURRENT_SPANS
.with(|spans| {
let spans = spans.borrow();
let id = spans.current()?;
let span = self.get(id)?;
Some(Current::new(id.clone(), span.metadata))
})
.unwrap_or_else(Current::none)
}
/// Decrements the reference count of the span with the given `id`, and
/// removes the span if it is zero.
///
/// The allocated span slot will be reused when a new span is created.
fn try_close(&self, id: span::Id) -> bool {
let span = match self.get(&id) {
Some(span) => span,
None if std::thread::panicking() => return false,
None => panic!("tried to drop a ref to {:?}, but no such span exists!", id),
};
let refs = span.ref_count.fetch_sub(1, Ordering::Release);
if !std::thread::panicking() {
assert!(refs < std::usize::MAX, "reference count overflow!");
}
if refs > 1 {
return false;
}
// Synchronize if we are actually removing the span (stolen
// from std::Arc); this ensures that all other `try_close` calls on
// other threads happen-before we actually remove the span.
fence(Ordering::Acquire);
self.spans.remove(id_to_idx(&id));
true
}
}
impl<'a> LookupSpan<'a> for Registry {
type Data = Data<'a>;
fn span_data(&'a self, id: &Id) -> Option<Self::Data> {
let inner = self.get(id)?;
Some(Data { inner })
}
}
// === impl DataInner ===
impl Drop for DataInner {
// A span is not considered closed until all of its children have closed.
// Therefore, each span's `DataInner` holds a "reference" to the parent
// span, keeping the parent span open until all its children have closed.
// When we close a span, we must then decrement the parent's ref count
// (potentially, allowing it to close, if this child is the last reference
// to that span).
fn drop(&mut self) {
// We have to actually unpack the option inside the `get_default`
// closure, since it is a `FnMut`, but testing that there _is_ a value
// here lets us avoid the thread-local access if we don't need the
// dispatcher at all.
if self.parent.is_some() {
// Note that --- because `Layered::try_close` works by calling
// `try_close` on the inner subscriber and using the return value to
// determine whether to call the `Layer`'s `on_close` callback ---
// we must call `try_close` on the entire subscriber stack, rather
// than just on the registry. If the registry called `try_close` on
// itself directly, the layers wouldn't see the close notification.
dispatcher::get_default(|subscriber| {
if let Some(parent) = self.parent.take() {
let _ = subscriber.try_close(parent);
}
})
}
}
}
// === impl Data ===
impl<'a> SpanData<'a> for Data<'a> {
fn id(&self) -> Id {
idx_to_id(self.inner.key())
}
fn metadata(&self) -> &'static Metadata<'static> {
(*self).inner.metadata
}
fn parent(&self) -> Option<&Id> {
self.inner.parent.as_ref()
}
fn extensions(&self) -> Extensions<'_> {
Extensions::new(self.inner.extensions.read().expect("Mutex poisoned"))
}
fn extensions_mut(&self) -> ExtensionsMut<'_> {
ExtensionsMut::new(self.inner.extensions.write().expect("Mutex poisoned"))
}
}

60
tracing-subscriber/src/registry/stack.rs Normal file
View File

@@ -0,0 +1,60 @@
use std::cell::RefCell;
use std::collections::HashSet;
pub(crate) use tracing_core::span::Id;
struct ContextId {
id: Id,
duplicate: bool,
}
/// `SpanStack` tracks what spans are currently executing on a thread-local basis.
///
/// A "separate current span" for each thread is a semantic choice, as each span
/// can be executing in a different thread.
pub(crate) struct SpanStack {
stack: Vec<ContextId>,
ids: HashSet<Id>,
}
impl SpanStack {
pub(crate) fn new() -> Self {
SpanStack {
stack: vec![],
ids: HashSet::new(),
}
}
pub(crate) fn push(&mut self, id: Id) {
let duplicate = self.ids.contains(&id);
if !duplicate {
self.ids.insert(id.clone());
}
self.stack.push(ContextId { id, duplicate })
}
pub(crate) fn pop(&mut self, expected_id: &Id) -> Option<Id> {
if &self.stack.last()?.id == expected_id {
let ContextId { id, duplicate } = self.stack.pop()?;
if !duplicate {
self.ids.remove(&id);
}
Some(id)
} else {
None
}
}
#[inline]
pub(crate) fn current(&self) -> Option<&Id> {
self.stack
.iter()
.rev()
.find(|context_id| !context_id.duplicate)
.map(|context_id| &context_id.id)
}
}
thread_local! {
static CONTEXT: RefCell<SpanStack> = RefCell::new(SpanStack::new());
}

56
tracing-subscriber/src/reload.rs
View File

@@ -240,59 +240,3 @@ impl error::Error for Error {
}
}
}
#[cfg(test)]
mod test {
use super::*;
use crate::prelude::*;
use std::sync::atomic::{AtomicUsize, Ordering};
#[test]
fn reload_handle() {
static FILTER1_CALLS: AtomicUsize = AtomicUsize::new(0);
static FILTER2_CALLS: AtomicUsize = AtomicUsize::new(0);
enum EnvFilter {
One,
Two,
}
impl<S: Subscriber> crate::Layer<S> for EnvFilter {
fn register_callsite(&self, _: &Metadata<'_>) -> Interest {
Interest::sometimes()
}
fn enabled(&self, _: &Metadata<'_>, _: layer::Context<'_, S>) -> bool {
match self {
EnvFilter::One => FILTER1_CALLS.fetch_add(1, Ordering::Relaxed),
EnvFilter::Two => FILTER2_CALLS.fetch_add(1, Ordering::Relaxed),
};
true
}
}
fn event() {
tracing::trace!("my event");
}
let (layer, handle) = Layer::new(EnvFilter::One);
let subscriber =
tracing_core::dispatcher::Dispatch::new(crate::layer::tests::NopSubscriber.with(layer));
tracing_core::dispatcher::with_default(&subscriber, || {
assert_eq!(FILTER1_CALLS.load(Ordering::Relaxed), 0);
assert_eq!(FILTER2_CALLS.load(Ordering::Relaxed), 0);
event();
assert_eq!(FILTER1_CALLS.load(Ordering::Relaxed), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::Relaxed), 0);
handle.reload(EnvFilter::Two).expect("should reload");
event();
assert_eq!(FILTER1_CALLS.load(Ordering::Relaxed), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::Relaxed), 1);
})
}
}

5
tracing-subscriber/src/sync.rs
View File

@@ -48,10 +48,5 @@ mod parking_lot_impl {
pub(crate) fn write<'a>(&'a self) -> LockResult<RwLockWriteGuard<'a, T>> {
Ok(self.inner.write())
}
#[inline]
pub(crate) fn try_write<'a>(&'a self) -> TryLockResult<RwLockWriteGuard<'a, T>> {
self.inner.try_write().ok_or(TryLockError::WouldBlock)
}
}
}

80
tracing-subscriber/tests/reload.rs Normal file
View File

@@ -0,0 +1,80 @@
use std::sync::atomic::{AtomicUsize, Ordering};
use tracing_core::{
span::{Attributes, Id, Record},
subscriber::Interest,
Event, Metadata, Subscriber,
};
use tracing_subscriber::{layer, prelude::*, reload::*};
pub struct NopSubscriber;
impl Subscriber for NopSubscriber {
fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest {
Interest::never()
}
fn enabled(&self, _: &Metadata<'_>) -> bool {
false
}
fn new_span(&self, _: &Attributes<'_>) -> Id {
Id::from_u64(1)
}
fn record(&self, _: &Id, _: &Record<'_>) {}
fn record_follows_from(&self, _: &Id, _: &Id) {}
fn event(&self, _: &Event<'_>) {}
fn enter(&self, _: &Id) {}
fn exit(&self, _: &Id) {}
}
#[test]
fn reload_handle() {
static FILTER1_CALLS: AtomicUsize = AtomicUsize::new(0);
static FILTER2_CALLS: AtomicUsize = AtomicUsize::new(0);
enum Filter {
One,
Two,
}
impl<S: Subscriber> tracing_subscriber::Layer<S> for Filter {
fn register_callsite(&self, m: &Metadata<'_>) -> Interest {
println!("REGISTER: {:?}", m);
Interest::sometimes()
}
fn enabled(&self, m: &Metadata<'_>, _: layer::Context<'_, S>) -> bool {
println!("ENABLED: {:?}", m);
match self {
Filter::One => FILTER1_CALLS.fetch_add(1, Ordering::SeqCst),
Filter::Two => FILTER2_CALLS.fetch_add(1, Ordering::SeqCst),
};
true
}
}
fn event() {
tracing::trace!("my event");
}
let (layer, handle) = Layer::new(Filter::One);
let subscriber = tracing_core::dispatcher::Dispatch::new(layer.with_subscriber(NopSubscriber));
tracing_core::dispatcher::with_default(&subscriber, || {
assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 0);
assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0);
event();
assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0);
handle.reload(Filter::Two).expect("should reload");
event();
assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 1);
})
}