Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Switch FmtSpan To a Combinable Bitflag #1277

Merged
merged 1 commit into from
Mar 11, 2021
Merged

Switch FmtSpan To a Combinable Bitflag #1277

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 21 additions & 6 deletions tracing-subscriber/src/fmt/fmt_subscriber.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -229,18 +229,33 @@ where
/// - `FmtSpan::NONE`: No events will be synthesized when spans are
/// created, entered, exited, or closed. Data from spans will still be
/// included as the context for formatted events. This is the default.
/// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered
/// or exited.
/// - `FmtSpan::NEW`: An event will be synthesized when spans are created.
/// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered.
/// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited.
/// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If
/// [timestamps are enabled][time] for this formatter, the generated
/// event will contain fields with the span's _busy time_ (the total
/// time for which it was entered) and _idle time_ (the total time that
/// the span existed but was not entered).
/// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered
/// or exited.
/// - `FmtSpan::FULL`: Events will be synthesized whenever a span is
/// created, entered, exited, or closed. If timestamps are enabled, the
/// close event will contain the span's busy and idle time, as
/// described above.
///
/// The options can be enabled in any combination. For instance, the following
/// will synthesize events whenever spans are created and closed:
///
/// ```rust
/// use tracing_subscriber::fmt;
/// use tracing_subscriber::fmt::format::FmtSpan;
///
/// let subscriber = fmt()
/// .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
/// .finish();
/// ```
///
/// Note that the generated events will only be part of the log output by
/// this formatter; they will not be recorded by other `Collector`s or by
/// `Subscriber`s added to this subscriber.
Expand Down Expand Up @@ -603,7 +618,7 @@ where
}

fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
let span = ctx.span(id).expect("Span not found, this is a bug");
let mut extensions = span.extensions_mut();
if let Some(timings) = extensions.get_mut::<Timings>() {
Expand All @@ -612,7 +627,7 @@ where
timings.last = now;
}

if self.fmt_span.trace_active() {
if self.fmt_span.trace_enter() {
with_event_from_span!(id, span, "message" = "enter", |event| {
drop(extensions);
drop(span);
Expand All @@ -623,7 +638,7 @@ where
}

fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
let span = ctx.span(id).expect("Span not found, this is a bug");
let mut extensions = span.extensions_mut();
if let Some(timings) = extensions.get_mut::<Timings>() {
Expand All @@ -632,7 +647,7 @@ where
timings.last = now;
}

if self.fmt_span.trace_active() {
if self.fmt_span.trace_exit() {
with_event_from_span!(id, span, "message" = "exit", |event| {
drop(extensions);
drop(span);
Expand Down
135 changes: 107 additions & 28 deletions tracing-subscriber/src/fmt/format/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1041,40 +1041,89 @@ impl<'a, F> fmt::Debug for FieldFnVisitor<'a, F> {
///
/// See also [`with_span_events`](super::CollectorBuilder::with_span_events()).
#[derive(Clone, Eq, PartialEq, Ord, PartialOrd)]
pub struct FmtSpan(FmtSpanInner);
pub struct FmtSpan(u8);

impl FmtSpan {
/// one event when span is created
pub const NEW: FmtSpan = FmtSpan(1 << 0);
/// one event per enter of a span
pub const ENTER: FmtSpan = FmtSpan(1 << 1);
/// one event per exit of a span
pub const EXIT: FmtSpan = FmtSpan(1 << 2);
/// one event when the span is dropped
pub const CLOSE: FmtSpan = FmtSpan(1 << 3);

/// spans are ignored (this is the default)
pub const NONE: FmtSpan = FmtSpan(FmtSpanInner::None);
pub const NONE: FmtSpan = FmtSpan(0);
/// one event per enter/exit of a span
pub const ACTIVE: FmtSpan = FmtSpan(FmtSpanInner::Active);
/// one event when the span is dropped
pub const CLOSE: FmtSpan = FmtSpan(FmtSpanInner::Close);
pub const ACTIVE: FmtSpan = FmtSpan(FmtSpan::ENTER.0 | FmtSpan::EXIT.0);
/// events at all points (new, enter, exit, drop)
pub const FULL: FmtSpan = FmtSpan(FmtSpanInner::Full);
pub const FULL: FmtSpan =
FmtSpan(FmtSpan::NEW.0 | FmtSpan::ENTER.0 | FmtSpan::EXIT.0 | FmtSpan::CLOSE.0);

/// Check whether or not a certain flag is set for this [`FmtSpan`]
fn contains(&self, other: FmtSpan) -> bool {
self.clone() & other.clone() == other
}
}

macro_rules! impl_fmt_span_bit_op {
($trait:ident, $func:ident, $op:tt) => {
impl std::ops::$trait for FmtSpan {
type Output = FmtSpan;

fn $func(self, rhs: Self) -> Self::Output {
FmtSpan(self.0 $op rhs.0)
}
}
};
}

macro_rules! impl_fmt_span_bit_assign_op {
($trait:ident, $func:ident, $op:tt) => {
impl std::ops::$trait for FmtSpan {
fn $func(&mut self, rhs: Self) {
*self = FmtSpan(self.0 $op rhs.0)
}
}
};
}

impl_fmt_span_bit_op!(BitAnd, bitand, &);
impl_fmt_span_bit_op!(BitOr, bitor, |);
impl_fmt_span_bit_op!(BitXor, bitxor, ^);
Comment on lines +1092 to +1094
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i'm not totally convinced we actually need an & operation, as i'm not sure how often user code will actually need to test for the presence of flags. i don't think providing it is a problem, though, so this is fine

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I wasn't positive either, but I figured if we were going to act like it was a bitflag, a user might expect that they could do it so I thought we might as well add it.


impl_fmt_span_bit_assign_op!(BitAndAssign, bitand_assign, &);
impl_fmt_span_bit_assign_op!(BitOrAssign, bitor_assign, |);
impl_fmt_span_bit_assign_op!(BitXorAssign, bitxor_assign, ^);

impl Debug for FmtSpan {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
match self.0 {
FmtSpanInner::None => f.write_str("FmtSpan::NONE"),
FmtSpanInner::Active => f.write_str("FmtSpan::ACTIVE"),
FmtSpanInner::Close => f.write_str("FmtSpan::CLOSE"),
FmtSpanInner::Full => f.write_str("FmtSpan::FULL"),
let mut wrote_flag = false;
let mut write_flags = |flag, flag_str| -> fmt::Result {
if self.contains(flag) {
if wrote_flag {
f.write_str(" | ")?;
}

f.write_str(flag_str)?;
wrote_flag = true;
}

Ok(())
};

if FmtSpan::NONE | self.clone() == FmtSpan::NONE {
f.write_str("FmtSpan::NONE")?;
} else {
write_flags(FmtSpan::NEW, "FmtSpan::NEW")?;
write_flags(FmtSpan::ENTER, "FmtSpan::ENTER")?;
write_flags(FmtSpan::EXIT, "FmtSpan::EXIT")?;
write_flags(FmtSpan::CLOSE, "FmtSpan::CLOSE")?;
}
Comment on lines +1116 to 1123
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

<3 looks great

}
}

#[derive(Copy, Clone, Debug, Eq, PartialEq, Hash, Ord, PartialOrd)]
enum FmtSpanInner {
/// spans are ignored (this is the default)
None,
/// one event per enter/exit of a span
Active,
/// one event when the span is dropped
Close,
/// events at all points (new, enter, exit, drop)
Full,
Ok(())
}
}

pub(super) struct FmtSpanConfig {
Expand All @@ -1096,13 +1145,16 @@ impl FmtSpanConfig {
}
}
pub(super) fn trace_new(&self) -> bool {
matches!(self.kind, FmtSpan::FULL)
self.kind.contains(FmtSpan::NEW)
}
pub(super) fn trace_active(&self) -> bool {
matches!(self.kind, FmtSpan::ACTIVE | FmtSpan::FULL)
pub(super) fn trace_enter(&self) -> bool {
self.kind.contains(FmtSpan::ENTER)
}
pub(super) fn trace_exit(&self) -> bool {
self.kind.contains(FmtSpan::EXIT)
}
pub(super) fn trace_close(&self) -> bool {
matches!(self.kind, FmtSpan::CLOSE | FmtSpan::FULL)
self.kind.contains(FmtSpan::CLOSE)
}
}

Expand Down Expand Up @@ -1149,7 +1201,7 @@ pub(super) mod test {
dispatch::{set_default, Dispatch},
};

use super::TimingDisplay;
use super::{FmtSpan, TimingDisplay};
use std::fmt;

pub(crate) struct MockTime;
Expand Down Expand Up @@ -1284,4 +1336,31 @@ pub(super) mod test {
assert_eq!(fmt(123456789012), "123s");
assert_eq!(fmt(1234567890123), "1235s");
}

#[test]
fn fmt_span_combinations() {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TIOLI: it could be nice to have a test that we actually do reasonable behavior with various bitflag combinations, as well, but I'm not going to block merging this on that, the code is pretty straightforward.

let f = FmtSpan::NONE;
assert_eq!(f.contains(FmtSpan::NEW), false);
assert_eq!(f.contains(FmtSpan::ENTER), false);
assert_eq!(f.contains(FmtSpan::EXIT), false);
assert_eq!(f.contains(FmtSpan::CLOSE), false);

let f = FmtSpan::ACTIVE;
assert_eq!(f.contains(FmtSpan::NEW), false);
assert_eq!(f.contains(FmtSpan::ENTER), true);
assert_eq!(f.contains(FmtSpan::EXIT), true);
assert_eq!(f.contains(FmtSpan::CLOSE), false);

let f = FmtSpan::FULL;
assert_eq!(f.contains(FmtSpan::NEW), true);
assert_eq!(f.contains(FmtSpan::ENTER), true);
assert_eq!(f.contains(FmtSpan::EXIT), true);
assert_eq!(f.contains(FmtSpan::CLOSE), true);

let f = FmtSpan::NEW | FmtSpan::CLOSE;
assert_eq!(f.contains(FmtSpan::NEW), true);
assert_eq!(f.contains(FmtSpan::ENTER), false);
assert_eq!(f.contains(FmtSpan::EXIT), false);
assert_eq!(f.contains(FmtSpan::CLOSE), true);
}
}
19 changes: 17 additions & 2 deletions tracing-subscriber/src/fmt/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -642,18 +642,33 @@ where
/// - `FmtSpan::NONE`: No events will be synthesized when spans are
/// created, entered, exited, or closed. Data from spans will still be
/// included as the context for formatted events. This is the default.
/// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered
/// or exited.
/// - `FmtSpan::NEW`: An event will be synthesized when spans are created.
/// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered.
/// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited.
/// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If
/// [timestamps are enabled][time] for this formatter, the generated
/// event will contain fields with the span's _busy time_ (the total
/// time for which it was entered) and _idle time_ (the total time that
/// the span existed but was not entered).
/// - `FmtSpan::ACTIVE`: An event will be synthesized when spans are entered
/// or exited.
/// - `FmtSpan::FULL`: Events will be synthesized whenever a span is
/// created, entered, exited, or closed. If timestamps are enabled, the
/// close event will contain the span's busy and idle time, as
/// described above.
///
/// The options can be enabled in any combination. For instance, the following
/// will synthesize events whenever spans are created and closed:
///
/// ```rust
/// use tracing_subscriber::fmt::format::FmtSpan;
/// use tracing_subscriber::fmt;
///
/// let subscriber = fmt()
/// .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
/// .finish();
/// ```
///
/// Note that the generated events will only be part of the log output by
/// this formatter; they will not be recorded by other `Collector`s or by
/// `Subscriber`s added to this subscriber.
Expand Down