Vendor dependencies for 0.3.0 release

This commit is contained in:
2025-09-27 10:29:08 -05:00
parent 0c8d39d483
commit 82ab7f317b
26803 changed files with 16134934 additions and 0 deletions

View File

@@ -0,0 +1,281 @@
use std::sync::{Arc, Mutex};
use tracing_subscriber::fmt::MakeWriter;
/// Shared test writer that collects output for verification
#[derive(Debug, Clone)]
struct TestWriter {
buf: Arc<Mutex<Vec<u8>>>,
}
impl TestWriter {
fn new() -> Self {
Self {
buf: Arc::new(Mutex::new(Vec::new())),
}
}
fn get_output(&self) -> String {
let buf = self.buf.lock().unwrap();
String::from_utf8_lossy(&buf).to_string()
}
}
impl std::io::Write for TestWriter {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
self.buf.lock().unwrap().extend_from_slice(buf);
Ok(buf.len())
}
fn flush(&mut self) -> std::io::Result<()> {
Ok(())
}
}
impl<'a> MakeWriter<'a> for TestWriter {
type Writer = TestWriter;
fn make_writer(&'a self) -> Self::Writer {
self.clone()
}
}
/// Test that basic security expectations are met - this is a smoke test
/// for the ANSI escaping functionality using public APIs only
#[test]
fn test_error_ansi_escaping() {
use std::fmt;
#[derive(Debug)]
struct MaliciousError(&'static str);
impl fmt::Display for MaliciousError {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{}", self.0)
}
}
impl std::error::Error for MaliciousError {}
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.with_writer(writer.clone())
.with_ansi(false)
.without_time()
.with_target(false)
.with_level(false)
.finish();
tracing::subscriber::with_default(subscriber, || {
let malicious_error = MaliciousError("\x1b]0;PWNED\x07\x1b[2J\x08\x0c\x7f");
// This demonstrates that errors are logged - the actual escaping
// is tested by our internal unit tests
tracing::error!(error = %malicious_error, "An error occurred");
});
let output = writer.get_output();
// Just verify that something was logged
assert!(
output.contains("An error occurred"),
"Error message should be logged"
);
}
/// Test that ANSI escape sequences in log messages are properly escaped
#[test]
fn test_message_ansi_escaping() {
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.with_writer(writer.clone())
.with_ansi(false)
.without_time()
.with_target(false)
.with_level(false)
.finish();
tracing::subscriber::with_default(subscriber, || {
let malicious_input = "\x1b]0;PWNED\x07\x1b[2J\x08\x0c\x7f";
// This should not cause ANSI injection
tracing::info!("User input: {}", malicious_input);
});
let output = writer.get_output();
// Verify ANSI sequences are escaped
assert!(
!output.contains('\x1b'),
"Message output should not contain raw ESC characters"
);
assert!(
!output.contains('\x07'),
"Message output should not contain raw BEL characters"
);
}
/// Test that JSON formatter properly escapes ANSI sequences
#[cfg(feature = "json")]
#[test]
fn test_json_ansi_escaping() {
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.json()
.with_writer(writer.clone())
.finish();
tracing::subscriber::with_default(subscriber, || {
let malicious_input = "\x1b]0;PWNED\x07\x1b[2J";
// JSON formatter should escape ANSI sequences
tracing::info!("Testing: {}", malicious_input);
tracing::info!(user_input = %malicious_input, "Field test");
});
let output = writer.get_output();
// JSON should escape ANSI sequences as Unicode escapes
assert!(
!output.contains('\x1b'),
"JSON output should not contain raw ESC characters"
);
assert!(
!output.contains('\x07'),
"JSON output should not contain raw BEL characters"
);
}
/// Test that pretty formatter properly escapes ANSI sequences
#[cfg(feature = "ansi")]
#[test]
fn test_pretty_ansi_escaping() {
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.pretty()
.with_writer(writer.clone())
.with_ansi(false)
.without_time()
.with_target(false)
.finish();
tracing::subscriber::with_default(subscriber, || {
let malicious_input = "\x1b]0;PWNED\x07\x1b[2J";
// Pretty formatter should escape ANSI sequences
tracing::info!("Testing: {}", malicious_input);
});
let output = writer.get_output();
// Verify ANSI sequences are escaped
assert!(
!output.contains('\x1b'),
"Pretty output should not contain raw ESC characters"
);
assert!(
!output.contains('\x07'),
"Pretty output should not contain raw BEL characters"
);
}
/// Comprehensive test for ANSI sanitization that prevents injection attacks
#[test]
fn ansi_sanitization_prevents_injection() {
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.with_writer(writer.clone())
.with_ansi(false)
.without_time()
.with_target(false)
.with_level(false)
.finish();
#[derive(Debug)]
struct MaliciousError {
content: String,
}
impl std::fmt::Display for MaliciousError {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
// This Display implementation contains ANSI escape sequences
write!(f, "Error: {}", self.content)
}
}
tracing::subscriber::with_default(subscriber, || {
// Test 1: Field values should remain properly escaped by Debug (baseline)
let malicious_field_value = "\x1b]0;PWNED\x07\x1b[2J";
tracing::error!(malicious_field = malicious_field_value, "Field test");
// Test 2: Message content vulnerability should be mitigated
let malicious_error = MaliciousError {
content: "\x1b]0;PWNED\x07\x1b[2J".to_string(),
};
tracing::error!("{}", malicious_error);
});
let output = writer.get_output();
// Field values should contain escaped sequences like \u{1b}
assert!(
output.contains("\\u{1b}"),
"Field values should be escaped by Debug formatting"
);
// Message content should be sanitized
assert!(
output.contains("\\x1b"),
"Message content should be sanitized"
);
assert!(
!output.contains("\x1b]0;PWNED"),
"Message content should not contain raw ANSI sequences"
);
assert!(
!output.contains("\x07"),
"Message content should not contain raw control characters"
);
}
/// Test that C1 control characters (\x80-\x9f) are also properly escaped
#[test]
fn test_c1_control_characters_escaping() {
let writer = TestWriter::new();
let subscriber = tracing_subscriber::fmt::Subscriber::builder()
.with_writer(writer.clone())
.with_ansi(false)
.without_time()
.with_target(false)
.with_level(false)
.finish();
tracing::subscriber::with_default(subscriber, || {
// Test C1 control characters that can be used in 8-bit terminal escape sequences
let c1_controls = "\u{80}\u{85}\u{90}\u{9b}\u{9c}\u{9d}\u{9e}\u{9f}"; // Various C1 controls including CSI
// This should escape C1 control characters to prevent 8-bit escape sequences
tracing::info!("C1 controls: {}", c1_controls);
});
let output = writer.get_output();
// Verify C1 control characters are escaped
assert!(
!output.contains('\u{80}'),
"Output should not contain raw C1 control characters"
);
assert!(
!output.contains('\u{9b}'),
"Output should not contain raw CSI character"
);
assert!(
!output.contains('\u{9c}'),
"Output should not contain raw ST character"
);
// Should contain Unicode escapes for C1 characters
assert!(
output.contains("\\u{80}") || output.contains("\\u{8"),
"Should contain escaped C1 characters"
);
}

View File

@@ -0,0 +1,126 @@
#![cfg(feature = "registry")]
use tracing::Level;
use tracing_mock::{
expect,
layer::{self, MockLayer},
subscriber,
};
use tracing_subscriber::{filter::LevelFilter, prelude::*};
#[test]
fn layer_filters() {
let (unfiltered, unfiltered_handle) = unfiltered("unfiltered");
let (filtered, filtered_handle) = filtered("filtered");
let _subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered.with_filter(filter()))
.set_default();
events();
unfiltered_handle.assert_finished();
filtered_handle.assert_finished();
}
#[test]
fn layered_layer_filters() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let unfiltered = unfiltered1.and_then(unfiltered2);
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let filtered = filtered1
.with_filter(filter())
.and_then(filtered2.with_filter(filter()));
let _subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered)
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn out_of_order() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let _subscriber = tracing_subscriber::registry()
.with(unfiltered1)
.with(filtered1.with_filter(filter()))
.with(unfiltered2)
.with(filtered2.with_filter(filter()))
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn mixed_layered() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1);
let layered2 = unfiltered2.and_then(filtered2.with_filter(filter()));
let _subscriber = tracing_subscriber::registry()
.with(layered1)
.with(layered2)
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
fn filter() -> LevelFilter {
LevelFilter::INFO
}
fn unfiltered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}
fn filtered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}

View File

@@ -0,0 +1,47 @@
#![cfg(all(feature = "env-filter", feature = "fmt"))]
use tracing::{self, subscriber::with_default, Span};
use tracing_subscriber::{filter::EnvFilter, FmtSubscriber};
#[test]
fn duplicate_spans() {
let subscriber = FmtSubscriber::builder()
.with_env_filter(EnvFilter::new("[root]=debug"))
.finish();
with_default(subscriber, || {
let root = tracing::debug_span!("root");
root.in_scope(|| {
// root:
assert_eq!(root, Span::current(), "Current span must be 'root'");
let leaf = tracing::debug_span!("leaf");
leaf.in_scope(|| {
// root:leaf:
assert_eq!(leaf, Span::current(), "Current span must be 'leaf'");
root.in_scope(|| {
// root:leaf:
assert_eq!(
leaf,
Span::current(),
"Current span must be 'leaf' after entering twice the 'root' span"
);
})
});
// root:
assert_eq!(
root,
Span::current(),
"Current span must be root ('leaf' exited, nested 'root' exited)"
);
root.in_scope(|| {
assert_eq!(root, Span::current(), "Current span must be root");
});
// root:
assert_eq!(
root,
Span::current(),
"Current span must still be root after exiting nested 'root'"
);
});
});
}

View File

@@ -0,0 +1,751 @@
#![cfg(feature = "env-filter")]
mod per_layer;
use tracing::{self, subscriber::with_default, Level};
use tracing_mock::{expect, layer, subscriber};
use tracing_subscriber::{
filter::{EnvFilter, LevelFilter},
prelude::*,
Registry,
};
#[test]
fn level_filter_event() {
let filter: EnvFilter = "info".parse().expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "foo", "this should also be disabled");
tracing::warn!(target: "foo", "this should be enabled");
tracing::error!("this should be enabled too");
});
finished.assert_finished();
}
#[test]
fn same_name_spans() {
let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("bar")),
)
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("baz")),
)
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace_span!("foo", bar = 1);
tracing::trace_span!("foo", baz = 1);
});
finished.assert_finished();
}
#[test]
fn level_filter_event_with_target() {
let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
});
finished.assert_finished();
}
#[test]
fn level_filter_event_with_target_and_span_global() {
let filter: EnvFilter = "info,stuff[cool_span]=debug"
.parse()
.expect("filter should parse");
let cool_span = expect::span().named("cool_span");
let (layer, handle) = layer::mock()
.enter(&cool_span)
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![cool_span.clone()]),
)
.exit(cool_span)
.enter("uncool_span")
.exit("uncool_span")
.only()
.run_with_handle();
let subscriber = Registry::default().with(filter).with(layer);
with_default(subscriber, || {
{
let _span = tracing::info_span!(target: "stuff", "cool_span").entered();
tracing::debug!("this should be enabled");
}
tracing::debug!("should also be disabled");
{
let _span = tracing::info_span!("uncool_span").entered();
tracing::debug!("this should be disabled");
}
});
handle.assert_finished();
}
#[test]
fn not_order_dependent() {
// this test reproduces tokio-rs/tracing#623
let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
});
finished.assert_finished();
}
#[test]
fn add_directive_enables_event() {
// this test reproduces tokio-rs/tracing#591
// by default, use info level
let mut filter = EnvFilter::new(LevelFilter::INFO.to_string());
// overwrite with a more specific directive
filter = filter.add_directive("hello=trace".parse().expect("directive should parse"));
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO).with_target("hello"))
.event(expect::event().at_level(Level::TRACE).with_target("hello"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::info!(target: "hello", "hello info");
tracing::trace!(target: "hello", "hello trace");
});
finished.assert_finished();
}
#[test]
fn span_name_filter_is_dynamic() {
let filter: EnvFilter = "info,[cool_span]=debug"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.enter(expect::span().named("cool_span"))
.event(expect::event().at_level(Level::DEBUG))
.enter(expect::span().named("uncool_span"))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::DEBUG))
.exit(expect::span().named("uncool_span"))
.exit(expect::span().named("cool_span"))
.enter(expect::span().named("uncool_span"))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.exit(expect::span().named("uncool_span"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
let cool_span = tracing::info_span!("cool_span");
let uncool_span = tracing::info_span!("uncool_span");
{
let _enter = cool_span.enter();
tracing::debug!("i'm a cool event");
tracing::trace!("i'm cool, but not cool enough");
let _enter2 = uncool_span.enter();
tracing::warn!("warning: extremely cool!");
tracing::debug!("i'm still cool");
}
let _enter = uncool_span.enter();
tracing::warn!("warning: not that cool");
tracing::trace!("im not cool enough");
tracing::error!("uncool error");
});
finished.assert_finished();
}
#[test]
fn method_name_resolution() {
#[allow(unused_imports)]
use tracing_subscriber::layer::{Filter, Layer};
let filter = EnvFilter::new("hello_world=info");
filter.max_level_hint();
}
#[test]
fn parse_invalid_string() {
assert!(EnvFilter::builder().parse(",!").is_err());
}
#[test]
fn parse_empty_string_no_default_directive() {
let filter = EnvFilter::builder().parse("").expect("filter should parse");
let (subscriber, finished) = subscriber::mock().only().run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::trace!("this should be disabled");
tracing::debug!("this should be disabled");
tracing::info!("this should be disabled");
tracing::warn!("this should be disabled");
tracing::error!("this should be disabled");
});
finished.assert_finished();
}
#[test]
fn parse_empty_string_with_default_directive() {
let filter = EnvFilter::builder()
.with_default_directive(LevelFilter::INFO.into())
.parse("")
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::trace!("this should be disabled");
tracing::debug!("this should be disabled");
tracing::info!("this shouldn't be disabled");
tracing::warn!("this shouldn't be disabled");
tracing::error!("this shouldn't be disabled");
});
finished.assert_finished();
}
#[test]
fn new_invalid_string() {
let filter = EnvFilter::new(",!");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::trace!("this should be disabled");
tracing::debug!("this should be disabled");
tracing::info!("this should be disabled");
tracing::warn!("this should be disabled");
tracing::error!("this shouldn't be disabled");
});
finished.assert_finished();
}
#[test]
fn new_empty_string() {
let filter = EnvFilter::new("");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::trace!("this should be disabled");
tracing::debug!("this should be disabled");
tracing::info!("this should be disabled");
tracing::warn!("this should be disabled");
tracing::error!("this shouldn't be disabled");
});
finished.assert_finished();
}
#[test]
fn more_specific_static_filter_more_verbose() {
let filter = EnvFilter::new("info,hello=debug");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("hello"))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::info!("should be enabled");
tracing::debug!("should be disabled");
tracing::debug!(target: "hello", "should be enabled");
});
finished.assert_finished();
}
#[test]
fn more_specific_static_filter_less_verbose() {
let filter = EnvFilter::new("info,hello=warn");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(
expect::event()
.at_level(Level::WARN)
.with_target("env_filter"),
)
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::info!("should be enabled");
tracing::warn!("should be enabled");
tracing::info!(target: "hello", "should be disabled");
});
finished.assert_finished();
}
#[test]
fn more_specific_dynamic_filter_more_verbose() {
let filter = EnvFilter::new("info,[{hello=4}]=debug");
let (subscriber, finished) = subscriber::mock()
.new_span(expect::span().at_level(Level::INFO))
.drop_span("enabled info")
.new_span(
expect::span()
.at_level(Level::DEBUG)
.with_fields(expect::field("hello").with_value(&4_u64)),
)
.drop_span("enabled debug")
.event(expect::event().with_fields(expect::msg("marker")))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::info_span!("enabled info");
tracing::debug_span!("disabled debug");
tracing::debug_span!("enabled debug", hello = &4_u64);
// .only() doesn't work when we don't enter/exit spans
tracing::info!("marker");
});
finished.assert_finished();
}
/// This is a negative test. This functionality should work, but doesn't.
///
/// If an improvement to `EnvFilter` fixes this test, then the `#[should_panic]`
/// can be removed and the test kept as it is. If the test requires some sort of
/// modification, then care should be taken.
///
/// Fixing this test would resolve https://github.com/tokio-rs/tracing/issues/1388
/// (and probably a few more issues as well).
#[test]
#[should_panic(
expected = "[more_specific_dynamic_filter_less_verbose] expected a new span \
at level `Level(Warn)`,\n[more_specific_dynamic_filter_less_verbose] but \
got one at level `Level(Info)` instead."
)]
fn more_specific_dynamic_filter_less_verbose() {
let filter = EnvFilter::new("info,[{hello=4}]=warn");
let (subscriber, finished) = subscriber::mock()
.new_span(expect::span().at_level(Level::INFO))
.drop_span("enabled info")
.new_span(
expect::span()
.at_level(Level::WARN)
.with_fields(expect::field("hello").with_value(&100_u64)),
)
.drop_span("enabled hello=100 warn")
.new_span(
expect::span()
.at_level(Level::WARN)
.with_fields(expect::field("hello").with_value(&4_u64)),
)
.drop_span("enabled hello=4 warn")
.event(expect::event().with_fields(expect::msg("marker")))
.only()
.run_with_handle();
let layer = subscriber.with(filter);
with_default(layer, || {
tracing::info_span!("enabled info");
tracing::warn_span!("enabled hello=100 warn", hello = &100_u64);
tracing::info_span!("disabled hello=4 info", hello = &4_u64);
tracing::warn_span!("enabled hello=4 warn", hello = &4_u64);
// .only() doesn't work when we don't enter/exit spans
tracing::info!("marker");
});
finished.assert_finished();
}
// contains the same tests as the first half of this file
// but using EnvFilter as a `Filter`, not as a `Layer`
mod per_layer_filter {
use super::*;
#[test]
fn level_filter_event() {
let filter: EnvFilter = "info".parse().expect("filter should parse");
let (layer, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "foo", "this should also be disabled");
tracing::warn!(target: "foo", "this should be enabled");
tracing::error!("this should be enabled too");
handle.assert_finished();
}
#[test]
fn same_name_spans() {
let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace"
.parse()
.expect("filter should parse");
let (layer, handle) = layer::mock()
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("bar")),
)
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("baz")),
)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace_span!("foo", bar = 1);
tracing::trace_span!("foo", baz = 1);
handle.assert_finished();
}
#[test]
fn level_filter_event_with_target() {
let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse");
let (layer, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
handle.assert_finished();
}
#[test]
fn level_filter_event_with_target_and_span() {
let filter: EnvFilter = "stuff[cool_span]=debug"
.parse()
.expect("filter should parse");
let cool_span = expect::span().named("cool_span");
let (layer, handle) = layer::mock()
.enter(cool_span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![cool_span.clone()]),
)
.exit(cool_span)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
{
let _span = tracing::info_span!(target: "stuff", "cool_span").entered();
tracing::debug!("this should be enabled");
}
tracing::debug!("should also be disabled");
{
let _span = tracing::info_span!("uncool_span").entered();
tracing::debug!("this should be disabled");
}
handle.assert_finished();
}
#[test]
fn not_order_dependent() {
// this test reproduces tokio-rs/tracing#623
let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse");
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
finished.assert_finished();
}
#[test]
fn add_directive_enables_event() {
// this test reproduces tokio-rs/tracing#591
// by default, use info level
let mut filter = EnvFilter::new(LevelFilter::INFO.to_string());
// overwrite with a more specific directive
filter = filter.add_directive("hello=trace".parse().expect("directive should parse"));
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO).with_target("hello"))
.event(expect::event().at_level(Level::TRACE).with_target("hello"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::info!(target: "hello", "hello info");
tracing::trace!(target: "hello", "hello trace");
finished.assert_finished();
}
#[test]
fn span_name_filter_is_dynamic() {
let filter: EnvFilter = "info,[cool_span]=debug"
.parse()
.expect("filter should parse");
let cool_span = expect::span().named("cool_span");
let uncool_span = expect::span().named("uncool_span");
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.enter(cool_span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![cool_span.clone()]),
)
.enter(uncool_span.clone())
.event(
expect::event()
.at_level(Level::WARN)
.in_scope(vec![uncool_span.clone()]),
)
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![uncool_span.clone()]),
)
.exit(uncool_span.clone())
.exit(cool_span)
.enter(uncool_span.clone())
.event(
expect::event()
.at_level(Level::WARN)
.in_scope(vec![uncool_span.clone()]),
)
.event(
expect::event()
.at_level(Level::ERROR)
.in_scope(vec![uncool_span.clone()]),
)
.exit(uncool_span)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
let cool_span = tracing::info_span!("cool_span");
let uncool_span = tracing::info_span!("uncool_span");
{
let _enter = cool_span.enter();
tracing::debug!("i'm a cool event");
tracing::trace!("i'm cool, but not cool enough");
let _enter2 = uncool_span.enter();
tracing::warn!("warning: extremely cool!");
tracing::debug!("i'm still cool");
}
{
let _enter = uncool_span.enter();
tracing::warn!("warning: not that cool");
tracing::trace!("im not cool enough");
tracing::error!("uncool error");
}
finished.assert_finished();
}
#[test]
fn multiple_dynamic_filters() {
// Test that multiple dynamic (span) filters only apply to the layers
// they're attached to.
let (layer1, handle1) = {
let span = expect::span().named("span1");
let filter: EnvFilter = "[span1]=debug".parse().expect("filter 1 should parse");
let (layer, handle) = layer::named("layer1")
.enter(span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![span.clone()]),
)
.exit(span)
.only()
.run_with_handle();
(layer.with_filter(filter), handle)
};
let (layer2, handle2) = {
let span = expect::span().named("span2");
let filter: EnvFilter = "[span2]=info".parse().expect("filter 2 should parse");
let (layer, handle) = layer::named("layer2")
.enter(span.clone())
.event(
expect::event()
.at_level(Level::INFO)
.in_scope(vec![span.clone()]),
)
.exit(span)
.only()
.run_with_handle();
(layer.with_filter(filter), handle)
};
let _subscriber = tracing_subscriber::registry()
.with(layer1)
.with(layer2)
.set_default();
tracing::info_span!("span1").in_scope(|| {
tracing::debug!("hello from span 1");
tracing::trace!("not enabled");
});
tracing::info_span!("span2").in_scope(|| {
tracing::info!("hello from span 2");
tracing::debug!("not enabled");
});
handle1.assert_finished();
handle2.assert_finished();
}
}

View File

@@ -0,0 +1,306 @@
//! Tests for using `EnvFilter` as a per-layer filter (rather than a global
//! `Layer` filter).
#![cfg(feature = "registry")]
use super::*;
use tracing_mock::{expect, layer};
#[test]
fn level_filter_event() {
let filter: EnvFilter = "info".parse().expect("filter should parse");
let (layer, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "foo", "this should also be disabled");
tracing::warn!(target: "foo", "this should be enabled");
tracing::error!("this should be enabled too");
handle.assert_finished();
}
#[test]
fn same_name_spans() {
let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace"
.parse()
.expect("filter should parse");
let (layer, handle) = layer::mock()
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("bar")),
)
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("baz")),
)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace_span!("foo", bar = 1);
tracing::trace_span!("foo", baz = 1);
handle.assert_finished();
}
#[test]
fn level_filter_event_with_target() {
let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse");
let (layer, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
handle.assert_finished();
}
#[test]
fn level_filter_event_with_target_and_span() {
let filter: EnvFilter = "stuff[cool_span]=debug"
.parse()
.expect("filter should parse");
let cool_span = expect::span().named("cool_span");
let (layer, handle) = layer::mock()
.enter(cool_span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![cool_span.clone()]),
)
.exit(cool_span)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
{
let _span = tracing::info_span!(target: "stuff", "cool_span").entered();
tracing::debug!("this should be enabled");
}
tracing::debug!("should also be disabled");
{
let _span = tracing::info_span!("uncool_span").entered();
tracing::debug!("this should be disabled");
}
handle.assert_finished();
}
#[test]
fn not_order_dependent() {
// this test reproduces tokio-rs/tracing#623
let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse");
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG).with_target("stuff"))
.event(expect::event().at_level(Level::WARN).with_target("stuff"))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::ERROR).with_target("stuff"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
tracing::debug!(target: "stuff", "this should be enabled");
tracing::debug!("but this shouldn't");
tracing::trace!(target: "stuff", "and neither should this");
tracing::warn!(target: "stuff", "this should be enabled");
tracing::error!("this should be enabled too");
tracing::error!(target: "stuff", "this should be enabled also");
finished.assert_finished();
}
#[test]
fn add_directive_enables_event() {
// this test reproduces tokio-rs/tracing#591
// by default, use info level
let mut filter = EnvFilter::new(LevelFilter::INFO.to_string());
// overwrite with a more specific directive
filter = filter.add_directive("hello=trace".parse().expect("directive should parse"));
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO).with_target("hello"))
.event(expect::event().at_level(Level::TRACE).with_target("hello"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::info!(target: "hello", "hello info");
tracing::trace!(target: "hello", "hello trace");
finished.assert_finished();
}
#[test]
fn span_name_filter_is_dynamic() {
let filter: EnvFilter = "info,[cool_span]=debug"
.parse()
.expect("filter should parse");
let cool_span = expect::span().named("cool_span");
let uncool_span = expect::span().named("uncool_span");
let (layer, finished) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.enter(cool_span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![cool_span.clone()]),
)
.enter(uncool_span.clone())
.event(
expect::event()
.at_level(Level::WARN)
.in_scope(vec![uncool_span.clone()]),
)
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![uncool_span.clone()]),
)
.exit(uncool_span.clone())
.exit(cool_span)
.enter(uncool_span.clone())
.event(
expect::event()
.at_level(Level::WARN)
.in_scope(vec![uncool_span.clone()]),
)
.event(
expect::event()
.at_level(Level::ERROR)
.in_scope(vec![uncool_span.clone()]),
)
.exit(uncool_span)
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
tracing::trace!("this should be disabled");
tracing::info!("this shouldn't be");
let cool_span = tracing::info_span!("cool_span");
let uncool_span = tracing::info_span!("uncool_span");
{
let _enter = cool_span.enter();
tracing::debug!("i'm a cool event");
tracing::trace!("i'm cool, but not cool enough");
let _enter2 = uncool_span.enter();
tracing::warn!("warning: extremely cool!");
tracing::debug!("i'm still cool");
}
{
let _enter = uncool_span.enter();
tracing::warn!("warning: not that cool");
tracing::trace!("im not cool enough");
tracing::error!("uncool error");
}
finished.assert_finished();
}
#[test]
fn multiple_dynamic_filters() {
// Test that multiple dynamic (span) filters only apply to the layers
// they're attached to.
let (layer1, handle1) = {
let span = expect::span().named("span1");
let filter: EnvFilter = "[span1]=debug".parse().expect("filter 1 should parse");
let (layer, handle) = layer::named("layer1")
.enter(span.clone())
.event(
expect::event()
.at_level(Level::DEBUG)
.in_scope(vec![span.clone()]),
)
.exit(span)
.only()
.run_with_handle();
(layer.with_filter(filter), handle)
};
let (layer2, handle2) = {
let span = expect::span().named("span2");
let filter: EnvFilter = "[span2]=info".parse().expect("filter 2 should parse");
let (layer, handle) = layer::named("layer2")
.enter(span.clone())
.event(
expect::event()
.at_level(Level::INFO)
.in_scope(vec![span.clone()]),
)
.exit(span)
.only()
.run_with_handle();
(layer.with_filter(filter), handle)
};
let _subscriber = tracing_subscriber::registry()
.with(layer1)
.with(layer2)
.set_default();
tracing::info_span!("span1").in_scope(|| {
tracing::debug!("hello from span 1");
tracing::trace!("not enabled");
});
tracing::info_span!("span2").in_scope(|| {
tracing::info!("hello from span 2");
tracing::debug!("not enabled");
});
handle1.assert_finished();
handle2.assert_finished();
}

View File

@@ -0,0 +1,81 @@
#![cfg(feature = "registry")]
use std::sync::{Arc, Mutex};
use tracing::{subscriber::with_default, Event, Metadata, Subscriber};
use tracing_subscriber::{layer::Context, prelude::*, registry, Layer};
struct TrackingLayer {
enabled: bool,
event_enabled_count: Arc<Mutex<usize>>,
event_enabled: bool,
on_event_count: Arc<Mutex<usize>>,
}
impl<C> Layer<C> for TrackingLayer
where
C: Subscriber + Send + Sync + 'static,
{
fn enabled(&self, _metadata: &Metadata<'_>, _ctx: Context<'_, C>) -> bool {
self.enabled
}
fn event_enabled(&self, _event: &Event<'_>, _ctx: Context<'_, C>) -> bool {
*self.event_enabled_count.lock().unwrap() += 1;
self.event_enabled
}
fn on_event(&self, _event: &Event<'_>, _ctx: Context<'_, C>) {
*self.on_event_count.lock().unwrap() += 1;
}
}
#[test]
fn event_enabled_is_only_called_once() {
let event_enabled_count = Arc::new(Mutex::default());
let count = event_enabled_count.clone();
let subscriber = registry().with(TrackingLayer {
enabled: true,
event_enabled_count,
event_enabled: true,
on_event_count: Arc::new(Mutex::default()),
});
with_default(subscriber, || {
tracing::error!("hiya!");
});
assert_eq!(1, *count.lock().unwrap());
}
#[test]
fn event_enabled_not_called_when_not_enabled() {
let event_enabled_count = Arc::new(Mutex::default());
let count = event_enabled_count.clone();
let subscriber = registry().with(TrackingLayer {
enabled: false,
event_enabled_count,
event_enabled: true,
on_event_count: Arc::new(Mutex::default()),
});
with_default(subscriber, || {
tracing::error!("hiya!");
});
assert_eq!(0, *count.lock().unwrap());
}
#[test]
fn event_disabled_does_disable_event() {
let on_event_count = Arc::new(Mutex::default());
let count = on_event_count.clone();
let subscriber = registry().with(TrackingLayer {
enabled: true,
event_enabled_count: Arc::new(Mutex::default()),
event_enabled: false,
on_event_count,
});
with_default(subscriber, || {
tracing::error!("hiya!");
});
assert_eq!(0, *count.lock().unwrap());
}

View File

@@ -0,0 +1,115 @@
#![cfg(feature = "env-filter")]
use tracing::{self, subscriber::with_default, Level};
use tracing_mock::*;
use tracing_subscriber::{filter::EnvFilter, prelude::*};
#[test]
#[cfg_attr(not(flaky_tests), ignore)]
fn field_filter_events() {
let filter: EnvFilter = "[{thing}]=debug".parse().expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(
expect::event()
.at_level(Level::INFO)
.with_fields(expect::field("thing")),
)
.event(
expect::event()
.at_level(Level::DEBUG)
.with_fields(expect::field("thing")),
)
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!(disabled = true);
tracing::info!("also disabled");
tracing::info!(thing = 1);
tracing::debug!(thing = 2);
tracing::trace!(thing = 3);
});
finished.assert_finished();
}
#[test]
#[cfg_attr(not(flaky_tests), ignore)]
fn field_filter_spans() {
let filter: EnvFilter = "[{enabled=true}]=debug"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.enter(expect::span().named("span1"))
.event(
expect::event()
.at_level(Level::INFO)
.with_fields(expect::field("something")),
)
.exit(expect::span().named("span1"))
.enter(expect::span().named("span2"))
.exit(expect::span().named("span2"))
.enter(expect::span().named("span3"))
.event(
expect::event()
.at_level(Level::DEBUG)
.with_fields(expect::field("something")),
)
.exit(expect::span().named("span3"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!("disabled");
tracing::info!("also disabled");
tracing::info_span!("span1", enabled = true).in_scope(|| {
tracing::info!(something = 1);
});
tracing::debug_span!("span2", enabled = false, foo = "hi").in_scope(|| {
tracing::warn!(something = 2);
});
tracing::trace_span!("span3", enabled = true, answer = 42).in_scope(|| {
tracing::debug!(something = 2);
});
});
finished.assert_finished();
}
#[test]
fn record_after_created() {
let filter: EnvFilter = "[{enabled=true}]=debug"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.enter(expect::span().named("span"))
.exit(expect::span().named("span"))
.record(
expect::span().named("span"),
expect::field("enabled").with_value(&true),
)
.enter(expect::span().named("span"))
.event(expect::event().at_level(Level::DEBUG))
.exit(expect::span().named("span"))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
let span = tracing::info_span!("span", enabled = false);
span.in_scope(|| {
tracing::debug!("i'm disabled!");
});
span.record("enabled", true);
span.in_scope(|| {
tracing::debug!("i'm enabled!");
});
tracing::debug!("i'm also disabled");
});
finished.assert_finished();
}

View File

@@ -0,0 +1,63 @@
#![cfg(all(feature = "env-filter", feature = "tracing-log"))]
use tracing::{self, Level};
use tracing_mock::*;
use tracing_subscriber::{filter::EnvFilter, prelude::*};
mod my_module {
pub(crate) fn test_records() {
log::trace!("this should be disabled");
log::info!("this shouldn't be");
log::debug!("this should be disabled");
log::warn!("this should be enabled");
log::warn!(target: "something else", "this shouldn't be enabled");
log::error!("this should be enabled too");
}
pub(crate) fn test_log_enabled() {
assert!(
log::log_enabled!(log::Level::Info),
"info should be enabled inside `my_module`"
);
assert!(
!log::log_enabled!(log::Level::Debug),
"debug should not be enabled inside `my_module`"
);
assert!(
log::log_enabled!(log::Level::Warn),
"warn should be enabled inside `my_module`"
);
}
}
#[test]
fn log_is_enabled() {
let filter: EnvFilter = "filter_log::my_module=info"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
// Note: we have to set the global default in order to set the `log` max
// level, which can only be set once.
subscriber.with(filter).init();
my_module::test_records();
log::info!("this is disabled");
my_module::test_log_enabled();
assert!(
!log::log_enabled!(log::Level::Info),
"info should not be enabled outside `my_module`"
);
assert!(
!log::log_enabled!(log::Level::Warn),
"warn should not be enabled outside `my_module`"
);
finished.assert_finished();
}

View File

@@ -0,0 +1,10 @@
#![cfg(feature = "fmt")]
use tracing_subscriber::filter::LevelFilter;
#[test]
fn fmt_sets_max_level_hint() {
tracing_subscriber::fmt()
.with_max_level(LevelFilter::DEBUG)
.init();
assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
}

View File

@@ -0,0 +1,134 @@
#![cfg(feature = "registry")]
use tracing::{Level, Metadata, Subscriber};
use tracing_mock::{
expect, layer,
layer::MockLayer,
subscriber::{self},
};
use tracing_subscriber::{filter::DynFilterFn, layer::Context, prelude::*};
#[test]
fn layer_filters() {
let (unfiltered, unfiltered_handle) = unfiltered("unfiltered");
let (filtered, filtered_handle) = filtered("filtered");
let subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered.with_filter(filter()));
assert_eq!(subscriber.max_level_hint(), None);
let _subscriber = subscriber.set_default();
events();
unfiltered_handle.assert_finished();
filtered_handle.assert_finished();
}
#[test]
fn layered_layer_filters() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let unfiltered = unfiltered1.and_then(unfiltered2);
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let filtered = filtered1
.with_filter(filter())
.and_then(filtered2.with_filter(filter()));
let subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered);
assert_eq!(subscriber.max_level_hint(), None);
let _subscriber = subscriber.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn out_of_order() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let subscriber = tracing_subscriber::registry()
.with(unfiltered1)
.with(filtered1.with_filter(filter()))
.with(unfiltered2)
.with(filtered2.with_filter(filter()));
assert_eq!(subscriber.max_level_hint(), None);
let _subscriber = subscriber.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn mixed_layered() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1);
let layered2 = unfiltered2.and_then(filtered2.with_filter(filter()));
let subscriber = tracing_subscriber::registry().with(layered1).with(layered2);
assert_eq!(subscriber.max_level_hint(), None);
let _subscriber = subscriber.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
fn filter<S>() -> DynFilterFn<S> {
DynFilterFn::new(
(|metadata: &Metadata<'_>, _: &tracing_subscriber::layer::Context<'_, S>| {
metadata.level() <= &Level::INFO
}) as fn(&Metadata<'_>, &Context<'_, S>) -> bool,
)
.with_max_level_hint(Level::INFO)
}
fn unfiltered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}
fn filtered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}

View File

@@ -0,0 +1,67 @@
#![cfg(feature = "registry")]
use std::{
collections::HashMap,
sync::{Arc, Mutex},
};
use tracing::{Level, Subscriber};
use tracing_mock::{expect, layer};
use tracing_subscriber::{filter, prelude::*};
#[test]
fn layer_filter_interests_are_cached() {
let seen = Arc::new(Mutex::new(HashMap::new()));
let seen2 = seen.clone();
let filter = filter::filter_fn(move |meta| {
*seen
.lock()
.unwrap()
.entry(meta.callsite())
.or_insert(0usize) += 1;
meta.level() == &Level::INFO
});
let (expect, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let subscriber = tracing_subscriber::registry().with(expect.with_filter(filter));
assert!(subscriber.max_level_hint().is_none());
let _subscriber = subscriber.set_default();
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
events();
{
let lock = seen2.lock().unwrap();
for (callsite, &count) in lock.iter() {
assert_eq!(
count, 1,
"callsite {:?} should have been seen 1 time (after first set of events)",
callsite
);
}
}
events();
{
let lock = seen2.lock().unwrap();
for (callsite, &count) in lock.iter() {
assert_eq!(
count, 1,
"callsite {:?} should have been seen 1 time (after second set of events)",
callsite
);
}
}
handle.assert_finished();
}

View File

@@ -0,0 +1,43 @@
use super::*;
use tracing_mock::layer::MockLayer;
use tracing_subscriber::{filter, prelude::*, Layer};
fn layer() -> (MockLayer, subscriber::MockHandle) {
layer::mock().only().run_with_handle()
}
fn filter<S>() -> filter::DynFilterFn<S> {
// Use dynamic filter fn to disable interest caching and max-level hints,
// allowing us to put all of these tests in the same file.
filter::dynamic_filter_fn(|_, _| false)
}
/// reproduces https://github.com/tokio-rs/tracing/issues/1563#issuecomment-921363629
#[test]
fn box_works() {
let (layer, handle) = layer();
let layer = Box::new(layer.with_filter(filter()));
let _guard = tracing_subscriber::registry().with(layer).set_default();
for i in 0..2 {
tracing::info!(i);
}
handle.assert_finished();
}
/// the same as `box_works` but with a type-erased `Box`.
#[test]
fn dyn_box_works() {
let (layer, handle) = layer();
let layer: Box<dyn Layer<_> + Send + Sync + 'static> = Box::new(layer.with_filter(filter()));
let _guard = tracing_subscriber::registry().with(layer).set_default();
for i in 0..2 {
tracing::info!(i);
}
handle.assert_finished();
}

View File

@@ -0,0 +1,42 @@
use super::*;
use tracing_subscriber::{
filter::{filter_fn, FilterExt, LevelFilter},
prelude::*,
};
#[test]
fn and() {
let (layer, handle) = layer::mock()
.event(
event::msg("a very interesting event")
.at_level(tracing::Level::INFO)
.with_target("interesting_target"),
)
.only()
.run_with_handle();
// Enables spans and events with targets starting with `interesting_target`:
let target_filter = filter::filter_fn(|meta| meta.target().starts_with("interesting_target"));
// Enables spans and events with levels `INFO` and below:
let level_filter = LevelFilter::INFO;
// Combine the two filters together, returning a filter that only enables
// spans and events that *both* filters will enable:
let filter = target_filter.and(level_filter);
let _subscriber = tracing_subscriber::registry()
.with(layer.with_filter(filter))
.set_default();
// This event will *not* be enabled:
tracing::info!("an event with an uninteresting target");
// This event *will* be enabled:
tracing::info!(target: "interesting_target", "a very interesting event");
// This event will *not* be enabled:
tracing::debug!(target: "interesting_target", "interesting debug event...");
handle.assert_finished();
}

View File

@@ -0,0 +1,68 @@
use tracing::Subscriber;
use tracing_subscriber::filter::Targets;
use tracing_subscriber::prelude::*;
use tracing_subscriber::Layer;
#[test]
fn downcast_ref_to_inner_layer_and_filter() {
// Test that a filtered layer gives downcast_ref access to
// both the layer and the filter.
struct WrappedLayer;
impl<S> Layer<S> for WrappedLayer
where
S: Subscriber,
S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
{
}
let layer = WrappedLayer;
let filter = Targets::new().with_default(tracing::Level::INFO);
let registry = tracing_subscriber::registry().with(layer.with_filter(filter));
let dispatch = tracing::dispatcher::Dispatch::new(registry);
// The filter is available
assert!(dispatch.downcast_ref::<Targets>().is_some());
// The wrapped layer is available
assert!(dispatch.downcast_ref::<WrappedLayer>().is_some());
}
#[test]
fn forward_downcast_raw_to_layer() {
// Test that a filtered layer still gives its wrapped layer a chance to
// return a custom struct from downcast_raw.
// https://github.com/tokio-rs/tracing/issues/1618
struct WrappedLayer {
with_context: WithContext,
}
struct WithContext;
impl<S> Layer<S> for WrappedLayer
where
S: Subscriber,
S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>,
{
unsafe fn downcast_raw(&self, id: std::any::TypeId) -> Option<*const ()> {
match id {
id if id == std::any::TypeId::of::<Self>() => Some(self as *const _ as *const ()),
id if id == std::any::TypeId::of::<WithContext>() => {
Some(&self.with_context as *const _ as *const ())
}
_ => None,
}
}
}
let layer = WrappedLayer {
with_context: WithContext,
};
let filter = Targets::new().with_default(tracing::Level::INFO);
let registry = tracing_subscriber::registry().with(layer.with_filter(filter));
let dispatch = tracing::dispatcher::Dispatch::new(registry);
// Types from a custom implementation of `downcast_raw` are available
assert!(dispatch.downcast_ref::<WithContext>().is_some());
}

View File

@@ -0,0 +1,153 @@
use super::*;
use tracing_mock::{expect, layer::MockLayer};
#[test]
fn filters_span_scopes() {
let (debug_layer, debug_handle) = layer::named("debug")
.enter(expect::span().at_level(Level::DEBUG))
.enter(expect::span().at_level(Level::INFO))
.enter(expect::span().at_level(Level::WARN))
.enter(expect::span().at_level(Level::ERROR))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().at_level(Level::ERROR),
expect::span().at_level(Level::WARN),
expect::span().at_level(Level::INFO),
expect::span().at_level(Level::DEBUG),
]),
)
.exit(expect::span().at_level(Level::ERROR))
.exit(expect::span().at_level(Level::WARN))
.exit(expect::span().at_level(Level::INFO))
.exit(expect::span().at_level(Level::DEBUG))
.only()
.run_with_handle();
let (info_layer, info_handle) = layer::named("info")
.enter(expect::span().at_level(Level::INFO))
.enter(expect::span().at_level(Level::WARN))
.enter(expect::span().at_level(Level::ERROR))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().at_level(Level::ERROR),
expect::span().at_level(Level::WARN),
expect::span().at_level(Level::INFO),
]),
)
.exit(expect::span().at_level(Level::ERROR))
.exit(expect::span().at_level(Level::WARN))
.exit(expect::span().at_level(Level::INFO))
.only()
.run_with_handle();
let (warn_layer, warn_handle) = layer::named("warn")
.enter(expect::span().at_level(Level::WARN))
.enter(expect::span().at_level(Level::ERROR))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().at_level(Level::ERROR),
expect::span().at_level(Level::WARN),
]),
)
.exit(expect::span().at_level(Level::ERROR))
.exit(expect::span().at_level(Level::WARN))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(debug_layer.with_filter(LevelFilter::DEBUG))
.with(info_layer.with_filter(LevelFilter::INFO))
.with(warn_layer.with_filter(LevelFilter::WARN))
.set_default();
{
let _trace = tracing::trace_span!("my_span").entered();
let _debug = tracing::debug_span!("my_span").entered();
let _info = tracing::info_span!("my_span").entered();
let _warn = tracing::warn_span!("my_span").entered();
let _error = tracing::error_span!("my_span").entered();
tracing::error!("hello world");
}
debug_handle.assert_finished();
info_handle.assert_finished();
warn_handle.assert_finished();
}
#[test]
fn filters_interleaved_span_scopes() {
fn target_layer(target: &'static str) -> (MockLayer, subscriber::MockHandle) {
layer::named(format!("target_{}", target))
.enter(expect::span().with_target(target))
.enter(expect::span().with_target(target))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().with_target(target),
expect::span().with_target(target),
]),
)
.event(
expect::event()
.with_fields(expect::msg("hello to my target"))
.in_scope(vec![
expect::span().with_target(target),
expect::span().with_target(target),
])
.with_target(target),
)
.exit(expect::span().with_target(target))
.exit(expect::span().with_target(target))
.only()
.run_with_handle()
}
let (a_layer, a_handle) = target_layer("a");
let (b_layer, b_handle) = target_layer("b");
let (all_layer, all_handle) = layer::named("all")
.enter(expect::span().with_target("b"))
.enter(expect::span().with_target("a"))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().with_target("a"),
expect::span().with_target("b"),
]),
)
.exit(expect::span().with_target("a"))
.exit(expect::span().with_target("b"))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(all_layer.with_filter(LevelFilter::INFO))
.with(a_layer.with_filter(filter::filter_fn(|meta| {
let target = meta.target();
target == "a" || target == module_path!()
})))
.with(b_layer.with_filter(filter::filter_fn(|meta| {
let target = meta.target();
target == "b" || target == module_path!()
})))
.set_default();
{
let _a1 = tracing::trace_span!(target: "a", "a/trace").entered();
let _b1 = tracing::info_span!(target: "b", "b/info").entered();
let _a2 = tracing::info_span!(target: "a", "a/info").entered();
let _b2 = tracing::trace_span!(target: "b", "b/trace").entered();
tracing::info!("hello world");
tracing::debug!(target: "a", "hello to my target");
tracing::debug!(target: "b", "hello to my target");
}
a_handle.assert_finished();
b_handle.assert_finished();
all_handle.assert_finished();
}

View File

@@ -0,0 +1,189 @@
#![cfg(feature = "registry")]
mod boxed;
mod downcast_raw;
mod filter_scopes;
mod option;
mod per_event;
mod targets;
mod trees;
mod vec;
use tracing::{level_filters::LevelFilter, Level};
use tracing_mock::{expect, layer, subscriber};
use tracing_subscriber::{filter, prelude::*, Layer};
#[test]
fn basic_layer_filters() {
let (trace_layer, trace_handle) = layer::named("trace")
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let (debug_layer, debug_handle) = layer::named("debug")
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let (info_layer, info_handle) = layer::named("info")
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(trace_layer.with_filter(LevelFilter::TRACE))
.with(debug_layer.with_filter(LevelFilter::DEBUG))
.with(info_layer.with_filter(LevelFilter::INFO))
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
trace_handle.assert_finished();
debug_handle.assert_finished();
info_handle.assert_finished();
}
#[test]
fn basic_layer_filter_spans() {
let (trace_layer, trace_handle) = layer::named("trace")
.new_span(expect::span().at_level(Level::TRACE))
.new_span(expect::span().at_level(Level::DEBUG))
.new_span(expect::span().at_level(Level::INFO))
.only()
.run_with_handle();
let (debug_layer, debug_handle) = layer::named("debug")
.new_span(expect::span().at_level(Level::DEBUG))
.new_span(expect::span().at_level(Level::INFO))
.only()
.run_with_handle();
let (info_layer, info_handle) = layer::named("info")
.new_span(expect::span().at_level(Level::INFO))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(trace_layer.with_filter(LevelFilter::TRACE))
.with(debug_layer.with_filter(LevelFilter::DEBUG))
.with(info_layer.with_filter(LevelFilter::INFO))
.set_default();
tracing::trace_span!("hello trace");
tracing::debug_span!("hello debug");
tracing::info_span!("hello info");
trace_handle.assert_finished();
debug_handle.assert_finished();
info_handle.assert_finished();
}
#[test]
fn global_filters_subscribers_still_work() {
let (expect, handle) = layer::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(expect)
.with(LevelFilter::INFO)
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
handle.assert_finished();
}
#[test]
fn global_filter_interests_are_cached() {
let (expect, handle) = layer::mock()
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(expect.with_filter(filter::filter_fn(|meta| {
assert!(
meta.level() <= &Level::INFO,
"enabled should not be called for callsites disabled by the global filter"
);
meta.level() <= &Level::WARN
})))
.with(LevelFilter::INFO)
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
handle.assert_finished();
}
#[test]
fn global_filters_affect_subscriber_filters() {
let (expect, handle) = layer::named("debug")
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(expect.with_filter(LevelFilter::DEBUG))
.with(LevelFilter::INFO)
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
handle.assert_finished();
}
#[test]
fn filter_fn() {
let (all, all_handle) = layer::named("all_targets")
.event(expect::event().with_fields(expect::msg("hello foo")))
.event(expect::event().with_fields(expect::msg("hello bar")))
.only()
.run_with_handle();
let (foo, foo_handle) = layer::named("foo_target")
.event(expect::event().with_fields(expect::msg("hello foo")))
.only()
.run_with_handle();
let (bar, bar_handle) = layer::named("bar_target")
.event(expect::event().with_fields(expect::msg("hello bar")))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(all)
.with(foo.with_filter(filter::filter_fn(|meta| meta.target().starts_with("foo"))))
.with(bar.with_filter(filter::filter_fn(|meta| meta.target().starts_with("bar"))))
.set_default();
tracing::trace!(target: "foo", "hello foo");
tracing::trace!(target: "bar", "hello bar");
foo_handle.assert_finished();
bar_handle.assert_finished();
all_handle.assert_finished();
}

View File

@@ -0,0 +1,143 @@
use super::*;
use tracing::Subscriber;
use tracing_subscriber::{
filter::{self, LevelFilter},
prelude::*,
Layer,
};
fn filter_out_everything<S>() -> filter::DynFilterFn<S> {
// Use dynamic filter fn to disable interest caching and max-level hints,
// allowing us to put all of these tests in the same file.
filter::dynamic_filter_fn(|_, _| false)
}
#[test]
fn option_some() {
let (layer, handle) = layer::mock().only().run_with_handle();
let layer = layer.with_filter(Some(filter_out_everything()));
let _guard = tracing_subscriber::registry().with(layer).set_default();
for i in 0..2 {
tracing::info!(i);
}
handle.assert_finished();
}
#[test]
fn option_none() {
let (layer, handle) = layer::mock()
.event(expect::event())
.event(expect::event())
.only()
.run_with_handle();
let layer = layer.with_filter(None::<filter::DynFilterFn<_>>);
let _guard = tracing_subscriber::registry().with(layer).set_default();
for i in 0..2 {
tracing::info!(i);
}
handle.assert_finished();
}
#[test]
fn option_mixed() {
let (layer, handle) = layer::mock()
.event(expect::event())
.only()
.run_with_handle();
let layer = layer
.with_filter(filter::dynamic_filter_fn(|meta, _ctx| {
meta.target() == "interesting"
}))
.with_filter(None::<filter::DynFilterFn<_>>);
let _guard = tracing_subscriber::registry().with(layer).set_default();
tracing::info!(target: "interesting", x="foo");
tracing::info!(target: "boring", x="bar");
handle.assert_finished();
}
/// The lack of a max level hint from a `None` filter should result in no max
/// level hint when combined with other filters/layer.
#[test]
fn none_max_level_hint() {
let (layer_some, handle_none) = layer::mock()
.event(expect::event())
.event(expect::event())
.only()
.run_with_handle();
let subscribe_none = layer_some.with_filter(None::<filter::DynFilterFn<_>>);
assert!(subscribe_none.max_level_hint().is_none());
let (layer_filter_fn, handle_filter_fn) = layer::mock()
.event(expect::event())
.only()
.run_with_handle();
let max_level = Level::INFO;
let layer_filter_fn = layer_filter_fn.with_filter(
filter::dynamic_filter_fn(move |meta, _| meta.level() <= &max_level)
.with_max_level_hint(max_level),
);
assert_eq!(layer_filter_fn.max_level_hint(), Some(LevelFilter::INFO));
let subscriber = tracing_subscriber::registry()
.with(subscribe_none)
.with(layer_filter_fn);
// The absence of a hint from the `None` filter upgrades the `INFO` hint
// from the filter fn layer.
assert!(subscriber.max_level_hint().is_none());
let _guard = subscriber.set_default();
tracing::info!(target: "interesting", x="foo");
tracing::debug!(target: "sometimes_interesting", x="bar");
handle_none.assert_finished();
handle_filter_fn.assert_finished();
}
/// The max level hint from inside a `Some(filter)` filter should be propagated
/// and combined with other filters/layers.
#[test]
fn some_max_level_hint() {
let (layer_some, handle_some) = layer::mock()
.event(expect::event())
.event(expect::event())
.only()
.run_with_handle();
let layer_some = layer_some.with_filter(Some(
filter::dynamic_filter_fn(move |meta, _| meta.level() <= &Level::DEBUG)
.with_max_level_hint(Level::DEBUG),
));
assert_eq!(layer_some.max_level_hint(), Some(LevelFilter::DEBUG));
let (layer_filter_fn, handle_filter_fn) = layer::mock()
.event(expect::event())
.only()
.run_with_handle();
let layer_filter_fn = layer_filter_fn.with_filter(
filter::dynamic_filter_fn(move |meta, _| meta.level() <= &Level::INFO)
.with_max_level_hint(Level::INFO),
);
assert_eq!(layer_filter_fn.max_level_hint(), Some(LevelFilter::INFO));
let subscriber = tracing_subscriber::registry()
.with(layer_some)
.with(layer_filter_fn);
// The `DEBUG` hint from the `Some` filter upgrades the `INFO` hint from the
// filter fn layer.
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
let _guard = subscriber.set_default();
tracing::info!(target: "interesting", x="foo");
tracing::debug!(target: "sometimes_interesting", x="bar");
handle_some.assert_finished();
handle_filter_fn.assert_finished();
}

View File

@@ -0,0 +1,61 @@
use tracing::Level;
use tracing_mock::{expect, layer};
use tracing_subscriber::{field::Visit, layer::Filter, prelude::*};
struct FilterEvent;
impl<S> Filter<S> for FilterEvent {
fn enabled(
&self,
_meta: &tracing::Metadata<'_>,
_cx: &tracing_subscriber::layer::Context<'_, S>,
) -> bool {
true
}
fn event_enabled(
&self,
event: &tracing::Event<'_>,
_cx: &tracing_subscriber::layer::Context<'_, S>,
) -> bool {
struct ShouldEnable(bool);
impl Visit for ShouldEnable {
fn record_bool(&mut self, field: &tracing_core::Field, value: bool) {
if field.name() == "enable" {
self.0 = value;
}
}
fn record_debug(
&mut self,
_field: &tracing_core::Field,
_value: &dyn core::fmt::Debug,
) {
}
}
let mut should_enable = ShouldEnable(false);
event.record(&mut should_enable);
should_enable.0
}
}
#[test]
fn per_layer_event_field_filtering() {
let (expect, handle) = layer::mock()
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let _subscriber = tracing_subscriber::registry()
.with(expect.with_filter(FilterEvent))
.set_default();
tracing::trace!(enable = true, "hello trace");
tracing::debug!("hello debug");
tracing::info!(enable = true, "hello info");
tracing::warn!(enable = false, "hello warn");
tracing::error!("hello error");
handle.assert_finished();
}

View File

@@ -0,0 +1,59 @@
use super::*;
use tracing_subscriber::{
filter::{filter_fn, Targets},
prelude::*,
};
#[test]
#[cfg_attr(not(feature = "tracing-log"), ignore)]
fn log_events() {
// Reproduces https://github.com/tokio-rs/tracing/issues/1563
mod inner {
pub(super) const MODULE_PATH: &str = module_path!();
#[tracing::instrument]
pub(super) fn logs() {
log::debug!("inner");
}
}
let filter = Targets::new()
.with_default(LevelFilter::DEBUG)
.with_target(inner::MODULE_PATH, LevelFilter::WARN);
let layer =
tracing_subscriber::layer::Identity::new().with_filter(filter_fn(move |_meta| true));
let _guard = tracing_subscriber::registry()
.with(filter)
.with(layer)
.set_default();
inner::logs();
}
#[test]
fn inner_layer_short_circuits() {
// This test ensures that when a global filter short-circuits `Interest`
// evaluation, we aren't left with a "dirty" per-layer filter state.
let (layer, handle) = layer::mock()
.event(expect::event().with_fields(expect::msg("hello world")))
.only()
.run_with_handle();
let filter = Targets::new().with_target("magic_target", LevelFilter::DEBUG);
let _guard = tracing_subscriber::registry()
// Note: we don't just use a `LevelFilter` for the global filter here,
// because it will just return a max level filter, and the chain of
// `register_callsite` calls that would trigger the bug never happens...
.with(filter::filter_fn(|meta| meta.level() <= &Level::INFO))
.with(layer.with_filter(filter))
.set_default();
tracing::debug!("skip me please!");
tracing::info!(target: "magic_target", "hello world");
handle.assert_finished();
}

View File

@@ -0,0 +1,172 @@
use super::*;
use tracing_mock::{expect, layer::MockLayer};
#[test]
fn basic_trees() {
let (with_target, with_target_handle) = layer::named("info_with_target")
.event(
expect::event()
.at_level(Level::INFO)
.with_target("my_target"),
)
.only()
.run_with_handle();
let (info, info_handle) = layer::named("info")
.event(
expect::event()
.at_level(Level::INFO)
.with_target(module_path!()),
)
.event(
expect::event()
.at_level(Level::INFO)
.with_target("my_target"),
)
.only()
.run_with_handle();
let (all, all_handle) = layer::named("all")
.event(
expect::event()
.at_level(Level::INFO)
.with_target(module_path!()),
)
.event(expect::event().at_level(Level::TRACE))
.event(
expect::event()
.at_level(Level::INFO)
.with_target("my_target"),
)
.event(
expect::event()
.at_level(Level::TRACE)
.with_target("my_target"),
)
.only()
.run_with_handle();
let info_tree = info
.and_then(
with_target.with_filter(filter::filter_fn(|meta| dbg!(meta.target()) == "my_target")),
)
.with_filter(LevelFilter::INFO);
let subscriber = tracing_subscriber::registry().with(info_tree).with(all);
let _guard = dbg!(subscriber).set_default();
tracing::info!("hello world");
tracing::trace!("hello trace");
tracing::info!(target: "my_target", "hi to my target");
tracing::trace!(target: "my_target", "hi to my target at trace");
all_handle.assert_finished();
info_handle.assert_finished();
with_target_handle.assert_finished();
}
#[test]
fn filter_span_scopes() {
fn target_layer(target: &'static str) -> (MockLayer, subscriber::MockHandle) {
layer::named(format!("target_{}", target))
.enter(expect::span().with_target(target).at_level(Level::INFO))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![expect::span()
.with_target(target)
.at_level(Level::INFO)]),
)
.exit(expect::span().with_target(target).at_level(Level::INFO))
.only()
.run_with_handle()
}
let (a_layer, a_handle) = target_layer("a");
let (b_layer, b_handle) = target_layer("b");
let (info_layer, info_handle) = layer::named("info")
.enter(expect::span().with_target("b").at_level(Level::INFO))
.enter(expect::span().with_target("a").at_level(Level::INFO))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(vec![
expect::span().with_target("a").at_level(Level::INFO),
expect::span().with_target("b").at_level(Level::INFO),
]),
)
.exit(expect::span().with_target("a").at_level(Level::INFO))
.exit(expect::span().with_target("b").at_level(Level::INFO))
.only()
.run_with_handle();
let full_scope = vec![
expect::span().with_target("b").at_level(Level::TRACE),
expect::span().with_target("a").at_level(Level::INFO),
expect::span().with_target("b").at_level(Level::INFO),
expect::span().with_target("a").at_level(Level::TRACE),
];
let (all_layer, all_handle) = layer::named("all")
.enter(expect::span().with_target("a").at_level(Level::TRACE))
.enter(expect::span().with_target("b").at_level(Level::INFO))
.enter(expect::span().with_target("a").at_level(Level::INFO))
.enter(expect::span().with_target("b").at_level(Level::TRACE))
.event(
expect::event()
.with_fields(expect::msg("hello world"))
.in_scope(full_scope.clone()),
)
.event(
expect::event()
.with_fields(expect::msg("hello to my target"))
.with_target("a")
.in_scope(full_scope.clone()),
)
.event(
expect::event()
.with_fields(expect::msg("hello to my target"))
.with_target("b")
.in_scope(full_scope),
)
.exit(expect::span().with_target("b").at_level(Level::TRACE))
.exit(expect::span().with_target("a").at_level(Level::INFO))
.exit(expect::span().with_target("b").at_level(Level::INFO))
.exit(expect::span().with_target("a").at_level(Level::TRACE))
.only()
.run_with_handle();
let a_layer = a_layer.with_filter(filter::filter_fn(|meta| {
let target = meta.target();
target == "a" || target == module_path!()
}));
let b_layer = b_layer.with_filter(filter::filter_fn(|meta| {
let target = meta.target();
target == "b" || target == module_path!()
}));
let info_tree = info_layer
.and_then(a_layer)
.and_then(b_layer)
.with_filter(LevelFilter::INFO);
let subscriber = tracing_subscriber::registry()
.with(info_tree)
.with(all_layer);
let _guard = dbg!(subscriber).set_default();
{
let _a1 = tracing::trace_span!(target: "a", "a/trace").entered();
let _b1 = tracing::info_span!(target: "b", "b/info").entered();
let _a2 = tracing::info_span!(target: "a", "a/info").entered();
let _b2 = tracing::trace_span!(target: "b", "b/trace").entered();
tracing::info!("hello world");
tracing::debug!(target: "a", "hello to my target");
tracing::debug!(target: "b", "hello to my target");
}
all_handle.assert_finished();
info_handle.assert_finished();
a_handle.assert_finished();
b_handle.assert_finished();
}

View File

@@ -0,0 +1,121 @@
use super::*;
use tracing::Subscriber;
use tracing_mock::{expect, layer::MockLayer};
#[test]
fn with_filters_unboxed() {
let (trace_layer, trace_handle) = layer::named("trace")
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let trace_layer = trace_layer.with_filter(LevelFilter::TRACE);
let (debug_layer, debug_handle) = layer::named("debug")
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let debug_layer = debug_layer.with_filter(LevelFilter::DEBUG);
let (info_layer, info_handle) = layer::named("info")
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let info_layer = info_layer.with_filter(LevelFilter::INFO);
let _subscriber = tracing_subscriber::registry()
.with(vec![trace_layer, debug_layer, info_layer])
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
trace_handle.assert_finished();
debug_handle.assert_finished();
info_handle.assert_finished();
}
#[test]
fn with_filters_boxed() {
let (unfiltered_layer, unfiltered_handle) = layer::named("unfiltered")
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let unfiltered_layer = unfiltered_layer.boxed();
let (debug_layer, debug_handle) = layer::named("debug")
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let debug_layer = debug_layer.with_filter(LevelFilter::DEBUG).boxed();
let (target_layer, target_handle) = layer::named("target")
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let target_layer = target_layer
.with_filter(filter::filter_fn(|meta| meta.target() == "my_target"))
.boxed();
let _subscriber = tracing_subscriber::registry()
.with(vec![unfiltered_layer, debug_layer, target_layer])
.set_default();
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!(target: "my_target", "hello my target");
unfiltered_handle.assert_finished();
debug_handle.assert_finished();
target_handle.assert_finished();
}
#[test]
fn mixed_max_level_hint() {
let unfiltered = layer::named("unfiltered").run().boxed();
let info = layer::named("info")
.run()
.with_filter(LevelFilter::INFO)
.boxed();
let debug = layer::named("debug")
.run()
.with_filter(LevelFilter::DEBUG)
.boxed();
let subscriber = tracing_subscriber::registry().with(vec![unfiltered, info, debug]);
assert_eq!(subscriber.max_level_hint(), None);
}
#[test]
fn all_filtered_max_level_hint() {
let warn = layer::named("warn")
.run()
.with_filter(LevelFilter::WARN)
.boxed();
let info = layer::named("info")
.run()
.with_filter(LevelFilter::INFO)
.boxed();
let debug = layer::named("debug")
.run()
.with_filter(LevelFilter::DEBUG)
.boxed();
let subscriber = tracing_subscriber::registry().with(vec![warn, info, debug]);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
}
#[test]
fn empty_vec() {
// Just a None means everything is off
let subscriber = tracing_subscriber::registry().with(Vec::<MockLayer>::new());
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF));
}

View File

@@ -0,0 +1,129 @@
#![cfg(feature = "registry")]
use std::{
collections::HashMap,
sync::{Arc, Mutex},
};
use tracing::{Level, Subscriber};
use tracing_mock::{expect, layer};
use tracing_subscriber::{filter, prelude::*};
#[test]
fn multiple_layer_filter_interests_are_cached() {
// This layer will return Interest::always for INFO and lower.
let seen_info = Arc::new(Mutex::new(HashMap::new()));
let seen_info2 = seen_info.clone();
let filter = filter::filter_fn(move |meta| {
*seen_info
.lock()
.unwrap()
.entry(*meta.level())
.or_insert(0usize) += 1;
meta.level() <= &Level::INFO
});
let seen_info = seen_info2;
let (info_layer, info_handle) = layer::named("info")
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let info_layer = info_layer.with_filter(filter);
// This layer will return Interest::always for WARN and lower.
let seen_warn = Arc::new(Mutex::new(HashMap::new()));
let seen_warn2 = seen_warn.clone();
let filter = filter::filter_fn(move |meta| {
*seen_warn
.lock()
.unwrap()
.entry(*meta.level())
.or_insert(0usize) += 1;
meta.level() <= &Level::WARN
});
let seen_warn = seen_warn2;
let (warn_layer, warn_handle) = layer::named("warn")
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let warn_layer = warn_layer.with_filter(filter);
let subscriber = tracing_subscriber::registry()
.with(warn_layer)
.with(info_layer);
assert!(subscriber.max_level_hint().is_none());
let _subscriber = subscriber.set_default();
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
events();
{
let lock = seen_info.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the INFO layer (after first set of events)",
level
);
}
let lock = seen_warn.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the WARN layer (after first set of events)",
level
);
}
}
events();
{
let lock = seen_info.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the INFO layer (after second set of events)",
level
);
}
let lock = seen_warn.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the WARN layer (after second set of events)",
level
);
}
}
info_handle.assert_finished();
warn_handle.assert_finished();
}

View File

@@ -0,0 +1,262 @@
#![cfg(feature = "registry")]
use tracing_core::{subscriber::Interest, LevelFilter, Metadata, Subscriber};
use tracing_subscriber::{layer, prelude::*};
// A basic layer that returns its inner for `max_level_hint`
#[derive(Debug)]
struct BasicLayer(Option<LevelFilter>);
impl<S: Subscriber> tracing_subscriber::Layer<S> for BasicLayer {
fn register_callsite(&self, _m: &Metadata<'_>) -> Interest {
Interest::sometimes()
}
fn enabled(&self, _m: &Metadata<'_>, _: layer::Context<'_, S>) -> bool {
true
}
fn max_level_hint(&self) -> Option<LevelFilter> {
self.0
}
}
// This test is just used to compare to the tests below
#[test]
fn just_layer() {
let subscriber = tracing_subscriber::registry().with(LevelFilter::INFO);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO));
}
#[test]
fn subscriber_and_option_some_layer() {
let subscriber = tracing_subscriber::registry()
.with(LevelFilter::INFO)
.with(Some(LevelFilter::DEBUG));
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
}
#[test]
fn subscriber_and_option_none_layer() {
// None means the other layer takes control
let subscriber = tracing_subscriber::registry()
.with(LevelFilter::ERROR)
.with(None::<LevelFilter>);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR));
}
#[test]
fn just_option_some_layer() {
// Just a None means everything is off
let subscriber = tracing_subscriber::registry().with(None::<LevelFilter>);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF));
}
/// Tests that the logic tested in `doesnt_override_none` works through the reload subscriber
#[test]
fn just_option_none_layer() {
let subscriber = tracing_subscriber::registry().with(Some(LevelFilter::ERROR));
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR));
}
// Test that the `None` max level hint only applies if its the only layer
#[test]
fn none_outside_doesnt_override_max_level() {
// None means the other layer takes control
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(None))
.with(None::<LevelFilter>);
assert_eq!(
subscriber.max_level_hint(),
None,
"\n stack: {:#?}",
subscriber
);
// The `None`-returning layer still wins
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(None))
.with(Some(LevelFilter::ERROR));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::ERROR),
"\n stack: {:#?}",
subscriber
);
// Check that we aren't doing anything truly wrong
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(Some(LevelFilter::DEBUG)))
.with(None::<LevelFilter>);
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// Test that per-subscriber filters aren't affected
// One layer is None so it "wins"
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(None))
.with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG));
assert_eq!(
subscriber.max_level_hint(),
None,
"\n stack: {:#?}",
subscriber
);
// The max-levels wins
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(Some(LevelFilter::INFO)))
.with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// Test filter on the other layer
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG))
.with(None::<LevelFilter>);
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(None).with_filter(LevelFilter::DEBUG))
.with(None::<LevelFilter>);
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// The `OFF` from `None` over overridden.
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(Some(LevelFilter::INFO)))
.with(None::<LevelFilter>);
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::INFO),
"\n stack: {:#?}",
subscriber
);
}
// Test that the `None` max level hint only applies if its the only layer
#[test]
fn none_inside_doesnt_override_max_level() {
// None means the other layer takes control
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>)
.with(BasicLayer(None));
assert_eq!(
subscriber.max_level_hint(),
None,
"\n stack: {:#?}",
subscriber
);
// The `None`-returning layer still wins
let subscriber = tracing_subscriber::registry()
.with(Some(LevelFilter::ERROR))
.with(BasicLayer(None));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::ERROR),
"\n stack: {:#?}",
subscriber
);
// Check that we aren't doing anything truly wrong
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>)
.with(BasicLayer(Some(LevelFilter::DEBUG)));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// Test that per-subscriber filters aren't affected
// One layer is None so it "wins"
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG))
.with(BasicLayer(None));
assert_eq!(
subscriber.max_level_hint(),
None,
"\n stack: {:#?}",
subscriber
);
// The max-levels wins
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG))
.with(BasicLayer(Some(LevelFilter::INFO)));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// Test filter on the other layer
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>)
.with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>)
.with(BasicLayer(None).with_filter(LevelFilter::DEBUG));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::DEBUG),
"\n stack: {:#?}",
subscriber
);
// The `OFF` from `None` over overridden.
let subscriber = tracing_subscriber::registry()
.with(None::<LevelFilter>)
.with(BasicLayer(Some(LevelFilter::INFO)));
assert_eq!(
subscriber.max_level_hint(),
Some(LevelFilter::INFO),
"\n stack: {:#?}",
subscriber
);
}
/// Tests that the logic tested in `doesnt_override_none` works through the reload layer
#[test]
fn reload_works_with_none() {
let (layer1, handle1) = tracing_subscriber::reload::Layer::new(None::<BasicLayer>);
let (layer2, _handle2) = tracing_subscriber::reload::Layer::new(None::<BasicLayer>);
let subscriber = tracing_subscriber::registry().with(layer1).with(layer2);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF));
// reloading one should pass through correctly.
handle1.reload(Some(BasicLayer(None))).unwrap();
assert_eq!(subscriber.max_level_hint(), None);
// Check pass-through of an actual level as well
handle1
.reload(Some(BasicLayer(Some(LevelFilter::DEBUG))))
.unwrap();
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
}

View File

@@ -0,0 +1,53 @@
// A separate test crate for `Option<Filter>` for isolation from other tests
// that may influence the interest cache.
use std::sync::{
atomic::{AtomicUsize, Ordering},
Arc,
};
use tracing_mock::{expect, layer};
use tracing_subscriber::{filter, prelude::*, Layer};
/// A `None` filter should always be interested in events, and it should not
/// needlessly degrade the caching of other filters.
#[test]
fn none_interest_cache() {
let (layer_none, handle_none) = layer::mock()
.event(expect::event())
.event(expect::event())
.only()
.run_with_handle();
let layer_none = layer_none.with_filter(None::<filter::DynFilterFn<_>>);
let times_filtered = Arc::new(AtomicUsize::new(0));
let (layer_filter_fn, handle_filter_fn) = layer::mock()
.event(expect::event())
.event(expect::event())
.only()
.run_with_handle();
let layer_filter_fn = layer_filter_fn.with_filter(filter::filter_fn({
let times_filtered = Arc::clone(&times_filtered);
move |_| {
times_filtered.fetch_add(1, Ordering::Relaxed);
true
}
}));
let subscriber = tracing_subscriber::registry()
.with(layer_none)
.with(layer_filter_fn);
let _guard = subscriber.set_default();
for _ in 0..2 {
tracing::debug!(target: "always_interesting", x="bar");
}
// The `None` filter is unchanging and performs no filtering, so it should
// be cacheable and always be interested in events. The filter fn is a
// non-dynamic filter fn, which means the result can be cached per callsite.
// The filter fn should only need to be called once, and the `Option` filter
// should not interfere in the caching of that result.
assert_eq!(times_filtered.load(Ordering::Relaxed), 1);
handle_none.assert_finished();
handle_filter_fn.assert_finished();
}

View File

@@ -0,0 +1,11 @@
#![cfg(all(feature = "registry", feature = "fmt"))]
use tracing_subscriber::{filter::LevelFilter, prelude::*};
#[test]
fn registry_sets_max_level_hint() {
tracing_subscriber::registry()
.with(tracing_subscriber::fmt::layer())
.with(LevelFilter::DEBUG)
.init();
assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
}

View File

@@ -0,0 +1,25 @@
#![cfg(feature = "registry")]
use tracing_futures::{Instrument, WithSubscriber};
use tracing_subscriber::prelude::*;
#[tokio::test]
async fn future_with_subscriber() {
tracing_subscriber::registry().init();
let span = tracing::info_span!("foo");
let _e = span.enter();
let span = tracing::info_span!("bar");
let _e = span.enter();
tokio::spawn(
async {
async {
let span = tracing::Span::current();
println!("{:?}", span);
}
.instrument(tracing::info_span!("hi"))
.await
}
.with_subscriber(tracing_subscriber::registry()),
)
.await
.unwrap();
}

View File

@@ -0,0 +1,162 @@
#![cfg(feature = "registry")]
use std::sync::atomic::{AtomicUsize, Ordering};
use tracing_core::{
span::{Attributes, Id, Record},
subscriber::Interest,
Event, LevelFilter, Metadata, Subscriber,
};
use tracing_subscriber::{layer, prelude::*, reload::*};
pub struct NopSubscriber;
fn event() {
tracing::info!("my event");
}
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) {}
}
/// Running these two tests in parallel will cause flaky failures, since they are both modifying the MAX_LEVEL value.
/// "cargo test -- --test-threads=1 fixes it, but it runs all tests in serial.
/// The only way to run tests in serial in a single file is this way.
#[test]
fn run_all_reload_test() {
reload_handle();
reload_filter();
}
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 max_level_hint(&self) -> Option<LevelFilter> {
match self {
Filter::One => Some(LevelFilter::INFO),
Filter::Two => Some(LevelFilter::DEBUG),
}
}
}
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);
assert_eq!(LevelFilter::current(), LevelFilter::INFO);
handle.reload(Filter::Two).expect("should reload");
assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
event();
assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 1);
})
}
fn reload_filter() {
struct NopLayer;
impl<S: Subscriber> tracing_subscriber::Layer<S> for NopLayer {
fn register_callsite(&self, _m: &Metadata<'_>) -> Interest {
Interest::sometimes()
}
fn enabled(&self, _m: &Metadata<'_>, _: layer::Context<'_, S>) -> bool {
true
}
}
static FILTER1_CALLS: AtomicUsize = AtomicUsize::new(0);
static FILTER2_CALLS: AtomicUsize = AtomicUsize::new(0);
enum Filter {
One,
Two,
}
impl<S: Subscriber> tracing_subscriber::layer::Filter<S> for Filter {
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 max_level_hint(&self) -> Option<LevelFilter> {
match self {
Filter::One => Some(LevelFilter::INFO),
Filter::Two => Some(LevelFilter::DEBUG),
}
}
}
let (filter, handle) = Layer::new(Filter::One);
let dispatcher = tracing_core::Dispatch::new(
tracing_subscriber::registry().with(NopLayer.with_filter(filter)),
);
tracing_core::dispatcher::with_default(&dispatcher, || {
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);
assert_eq!(LevelFilter::current(), LevelFilter::INFO);
handle.reload(Filter::Two).expect("should reload");
assert_eq!(LevelFilter::current(), LevelFilter::DEBUG);
event();
assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1);
assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 1);
})
}

View File

@@ -0,0 +1,37 @@
#![cfg(all(feature = "env-filter", feature = "tracing-log"))]
use tracing::{self, Level};
use tracing_mock::{expect, subscriber};
use tracing_subscriber::{filter::LevelFilter, prelude::*, reload};
#[test]
fn reload_max_log_level() {
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.only()
.run_with_handle();
let (filter, reload_handle) = reload::Layer::new(LevelFilter::INFO);
subscriber.with(filter).init();
assert!(log::log_enabled!(log::Level::Info));
assert!(!log::log_enabled!(log::Level::Debug));
assert!(!log::log_enabled!(log::Level::Trace));
log::debug!("i'm disabled");
log::info!("i'm enabled");
reload_handle
.reload(Level::DEBUG)
.expect("reloading succeeds");
assert!(log::log_enabled!(log::Level::Info));
assert!(log::log_enabled!(log::Level::Debug));
assert!(!log::log_enabled!(log::Level::Trace));
log::debug!("i'm enabled now");
log::info!("i'm still enabled, too");
finished.assert_finished();
}

View File

@@ -0,0 +1,81 @@
// These tests include field filters with no targets, so they have to go in a
// separate file.
#![cfg(feature = "env-filter")]
use tracing::{self, subscriber::with_default, Level};
use tracing_mock::*;
use tracing_subscriber::{filter::EnvFilter, prelude::*};
#[test]
fn same_length_targets() {
let filter: EnvFilter = "foo=trace,bar=trace".parse().expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::TRACE))
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!(target: "foo", "foo");
tracing::trace!(target: "bar", "bar");
});
finished.assert_finished();
}
#[test]
fn same_num_fields_event() {
let filter: EnvFilter = "[{foo}]=trace,[{bar}]=trace"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(
expect::event()
.at_level(Level::TRACE)
.with_fields(expect::field("foo")),
)
.event(
expect::event()
.at_level(Level::TRACE)
.with_fields(expect::field("bar")),
)
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace!(foo = 1);
tracing::trace!(bar = 3);
});
finished.assert_finished();
}
#[test]
fn same_num_fields_and_name_len() {
let filter: EnvFilter = "[foo{bar=1}]=trace,[baz{boz=1}]=trace"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.new_span(
expect::span()
.named("foo")
.at_level(Level::TRACE)
.with_fields(expect::field("bar")),
)
.new_span(
expect::span()
.named("baz")
.at_level(Level::TRACE)
.with_fields(expect::field("boz")),
)
.only()
.run_with_handle();
let subscriber = subscriber.with(filter);
with_default(subscriber, || {
tracing::trace_span!("foo", bar = 1);
tracing::trace_span!("baz", boz = 1);
});
finished.assert_finished();
}

View File

@@ -0,0 +1,126 @@
#![cfg(feature = "registry")]
use tracing::Level;
use tracing_mock::{
expect,
layer::{self, MockLayer},
subscriber,
};
use tracing_subscriber::{filter::DynFilterFn, prelude::*};
#[test]
fn layer_filters() {
let (unfiltered, unfiltered_handle) = unfiltered("unfiltered");
let (filtered, filtered_handle) = filtered("filtered");
let _subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered.with_filter(filter()))
.set_default();
events();
unfiltered_handle.assert_finished();
filtered_handle.assert_finished();
}
#[test]
fn layered_layer_filters() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let unfiltered = unfiltered1.and_then(unfiltered2);
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let filtered = filtered1
.with_filter(filter())
.and_then(filtered2.with_filter(filter()));
let _subscriber = tracing_subscriber::registry()
.with(unfiltered)
.with(filtered)
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn out_of_order() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let _subscriber = tracing_subscriber::registry()
.with(unfiltered1)
.with(filtered1.with_filter(filter()))
.with(unfiltered2)
.with(filtered2.with_filter(filter()))
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
#[test]
fn mixed_layered() {
let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1");
let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2");
let (filtered1, filtered1_handle) = filtered("filtered_1");
let (filtered2, filtered2_handle) = filtered("filtered_2");
let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1);
let layered2 = unfiltered2.and_then(filtered2.with_filter(filter()));
let _subscriber = tracing_subscriber::registry()
.with(layered1)
.with(layered2)
.set_default();
events();
unfiltered1_handle.assert_finished();
unfiltered2_handle.assert_finished();
filtered1_handle.assert_finished();
filtered2_handle.assert_finished();
}
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
fn filter<S>() -> DynFilterFn<S> {
DynFilterFn::new(|metadata, _| metadata.level() <= &Level::INFO)
}
fn unfiltered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::TRACE))
.event(expect::event().at_level(Level::DEBUG))
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}
fn filtered(name: &str) -> (MockLayer, subscriber::MockHandle) {
layer::named(name)
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle()
}

View File

@@ -0,0 +1,39 @@
#![cfg(feature = "std")]
use tracing_mock::*;
use tracing_subscriber::prelude::*;
#[test]
fn init_ext_works() {
let (subscriber, finished) = subscriber::mock()
.event(
expect::event()
.at_level(tracing::Level::INFO)
.with_target("init_works"),
)
.only()
.run_with_handle();
let _guard = subscriber.set_default();
tracing::info!(target: "init_works", "it worked!");
finished.assert_finished();
}
#[test]
#[cfg(feature = "fmt")]
fn builders_are_init_ext() {
tracing_subscriber::fmt().set_default();
let _ = tracing_subscriber::fmt()
.with_target(false)
.compact()
.try_init();
}
#[test]
#[cfg(all(feature = "fmt", feature = "env-filter"))]
fn layered_is_init_ext() {
tracing_subscriber::registry()
.with(tracing_subscriber::fmt::layer())
.with(tracing_subscriber::EnvFilter::new("foo=info"))
.set_default();
}

19
vendor/tracing-subscriber/tests/vec.rs vendored Normal file
View File

@@ -0,0 +1,19 @@
#![cfg(feature = "registry")]
use tracing::level_filters::LevelFilter;
use tracing::Subscriber;
use tracing_subscriber::prelude::*;
#[test]
fn just_empty_vec() {
// Just a None means everything is off
let subscriber = tracing_subscriber::registry().with(Vec::<LevelFilter>::new());
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF));
}
#[test]
fn layer_and_empty_vec() {
let subscriber = tracing_subscriber::registry()
.with(LevelFilter::INFO)
.with(Vec::<LevelFilter>::new());
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO));
}

View File

@@ -0,0 +1,115 @@
#![cfg(feature = "registry")]
use std::{
collections::HashMap,
sync::{Arc, Mutex},
};
use tracing::{Level, Subscriber};
use tracing_mock::{layer::MockLayer, *};
use tracing_subscriber::{filter, prelude::*};
#[test]
fn vec_layer_filter_interests_are_cached() {
let mk_filtered = |level: Level, subscriber: MockLayer| {
let seen = Arc::new(Mutex::new(HashMap::new()));
let filter = filter::filter_fn({
let seen = seen.clone();
move |meta| {
*seen.lock().unwrap().entry(*meta.level()).or_insert(0usize) += 1;
meta.level() <= &level
}
});
(subscriber.with_filter(filter).boxed(), seen)
};
// This layer will return Interest::always for INFO and lower.
let (info_layer, info_handle) = layer::named("info")
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::INFO))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let (info_layer, seen_info) = mk_filtered(Level::INFO, info_layer);
// This layer will return Interest::always for WARN and lower.
let (warn_layer, warn_handle) = layer::named("warn")
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.event(expect::event().at_level(Level::WARN))
.event(expect::event().at_level(Level::ERROR))
.only()
.run_with_handle();
let (warn_layer, seen_warn) = mk_filtered(Level::WARN, warn_layer);
let subscriber = tracing_subscriber::registry().with(vec![warn_layer, info_layer]);
assert!(subscriber.max_level_hint().is_none());
let _subscriber = subscriber.set_default();
fn events() {
tracing::trace!("hello trace");
tracing::debug!("hello debug");
tracing::info!("hello info");
tracing::warn!("hello warn");
tracing::error!("hello error");
}
events();
{
let lock = seen_info.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the INFO subscriber (after first set of events)",
level
);
}
let lock = seen_warn.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the WARN subscriber (after first set of events)",
level
);
}
}
events();
{
let lock = seen_info.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the INFO subscriber (after second set of events)",
level
);
}
let lock = seen_warn.lock().unwrap();
for (&level, &count) in lock.iter() {
if level == Level::INFO {
continue;
}
assert_eq!(
count, 1,
"level {:?} should have been seen 1 time by the WARN subscriber (after second set of events)",
level
);
}
}
info_handle.assert_finished();
warn_handle.assert_finished();
}