diff options
author | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-28 14:29:10 +0000 |
---|---|---|
committer | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-28 14:29:10 +0000 |
commit | 2aa4a82499d4becd2284cdb482213d541b8804dd (patch) | |
tree | b80bf8bf13c3766139fbacc530efd0dd9d54394c /third_party/rust/tracing/tests | |
parent | Initial commit. (diff) | |
download | firefox-2aa4a82499d4becd2284cdb482213d541b8804dd.tar.xz firefox-2aa4a82499d4becd2284cdb482213d541b8804dd.zip |
Adding upstream version 86.0.1.upstream/86.0.1upstream
Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>
Diffstat (limited to 'third_party/rust/tracing/tests')
17 files changed, 3669 insertions, 0 deletions
diff --git a/third_party/rust/tracing/tests/event.rs b/third_party/rust/tracing/tests/event.rs new file mode 100644 index 0000000000..d61ef748b8 --- /dev/null +++ b/third_party/rust/tracing/tests/event.rs @@ -0,0 +1,375 @@ +// These tests require the thread-local scoped dispatcher, which only works when +// we have a standard library. The behaviour being tested should be the same +// with the standard lib disabled. +// +// The alternative would be for each of these tests to be defined in a separate +// file, which is :( +#![cfg(feature = "std")] + +#[macro_use] +extern crate tracing; +mod support; + +use self::support::*; + +use tracing::{ + field::{debug, display}, + subscriber::with_default, + Level, +}; + +macro_rules! event_without_message { + ($name:ident: $e:expr) => { + #[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] + #[test] + fn $name() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("answer") + .with_value(&42) + .and( + field::mock("to_question") + .with_value(&"life, the universe, and everything"), + ) + .only(), + ), + ) + .done() + .run_with_handle(); + + with_default(subscriber, || { + info!( + answer = $e, + to_question = "life, the universe, and everything" + ); + }); + + handle.assert_finished(); + } + }; +} + +event_without_message! {event_without_message: 42} +event_without_message! {wrapping_event_without_message: std::num::Wrapping(42)} +event_without_message! {nonzeroi32_event_without_message: std::num::NonZeroI32::new(42).unwrap()} +// needs API breakage +//event_without_message!{nonzerou128_event_without_message: std::num::NonZeroU128::new(42).unwrap()} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event_with_message() { + let (subscriber, handle) = subscriber::mock() + .event(event::mock().with_fields(field::mock("message").with_value( + &tracing::field::debug(format_args!("hello from my event! yak shaved = {:?}", true)), + ))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + debug!("hello from my event! yak shaved = {:?}", true); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn message_without_delims() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("answer") + .with_value(&42) + .and(field::mock("question").with_value(&"life, the universe, and everything")) + .and( + field::mock("message").with_value(&tracing::field::debug(format_args!( + "hello from my event! tricky? {:?}!", + true + ))), + ) + .only(), + ), + ) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let question = "life, the universe, and everything"; + debug!(answer = 42, question, "hello from {where}! tricky? {:?}!", true, where = "my event"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn string_message_without_delims() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("answer") + .with_value(&42) + .and(field::mock("question").with_value(&"life, the universe, and everything")) + .and( + field::mock("message").with_value(&tracing::field::debug(format_args!( + "hello from my event" + ))), + ) + .only(), + ), + ) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let question = "life, the universe, and everything"; + debug!(answer = 42, question, "hello from my event"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn one_with_everything() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock() + .with_fields( + field::mock("message") + .with_value(&tracing::field::debug(format_args!( + "{:#x} make me one with{what:.>20}", + 4_277_009_102u64, + what = "everything" + ))) + .and(field::mock("foo").with_value(&666)) + .and(field::mock("bar").with_value(&false)) + .only(), + ) + .at_level(Level::ERROR) + .with_target("whatever"), + ) + .done() + .run_with_handle(); + + with_default(subscriber, || { + event!( + target: "whatever", + Level::ERROR, + { foo = 666, bar = false }, + "{:#x} make me one with{what:.>20}", 4_277_009_102u64, what = "everything" + ); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn moved_field() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("foo") + .with_value(&display("hello from my event")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + let from = "my event"; + event!(Level::INFO, foo = display(format!("hello from {}", from))) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn dotted_field_name() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("foo.bar") + .with_value(&true) + .and(field::mock("foo.baz").with_value(&false)) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + event!(Level::INFO, foo.bar = true, foo.baz = false); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn borrowed_field() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("foo") + .with_value(&display("hello from my event")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + let from = "my event"; + let mut message = format!("hello from {}", from); + event!(Level::INFO, foo = display(&message)); + message.push_str(", which happened!"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +// If emitting log instrumentation, this gets moved anyway, breaking the test. +#[cfg(not(feature = "log"))] +fn move_field_out_of_struct() { + use tracing::field::debug; + + #[derive(Debug)] + struct Position { + x: f32, + y: f32, + } + + let pos = Position { + x: 3.234, + y: -1.223, + }; + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("x") + .with_value(&debug(3.234)) + .and(field::mock("y").with_value(&debug(-1.223))) + .only(), + ), + ) + .event(event::mock().with_fields(field::mock("position").with_value(&debug(&pos)))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let pos = Position { + x: 3.234, + y: -1.223, + }; + debug!(x = debug(pos.x), y = debug(pos.y)); + debug!(target: "app_events", { position = debug(pos) }, "New position"); + }); + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn display_shorthand() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("my_field") + .with_value(&display("hello world")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + event!(Level::TRACE, my_field = %"hello world"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_shorthand() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("my_field") + .with_value(&debug("hello world")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + event!(Level::TRACE, my_field = ?"hello world"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn both_shorthands() { + let (subscriber, handle) = subscriber::mock() + .event( + event::mock().with_fields( + field::mock("display_field") + .with_value(&display("hello world")) + .and(field::mock("debug_field").with_value(&debug("hello world"))) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + event!(Level::TRACE, display_field = %"hello world", debug_field = ?"hello world"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_child() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .event(event::mock().with_explicit_parent(Some("foo"))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + event!(parent: foo.id(), Level::TRACE, "bar"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_child_at_levels() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .event(event::mock().with_explicit_parent(Some("foo"))) + .event(event::mock().with_explicit_parent(Some("foo"))) + .event(event::mock().with_explicit_parent(Some("foo"))) + .event(event::mock().with_explicit_parent(Some("foo"))) + .event(event::mock().with_explicit_parent(Some("foo"))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + trace!(parent: foo.id(), "a"); + debug!(parent: foo.id(), "b"); + info!(parent: foo.id(), "c"); + warn!(parent: foo.id(), "d"); + error!(parent: foo.id(), "e"); + }); + + handle.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/filter_caching_is_lexically_scoped.rs b/third_party/rust/tracing/tests/filter_caching_is_lexically_scoped.rs new file mode 100644 index 0000000000..9b997a0c6b --- /dev/null +++ b/third_party/rust/tracing/tests/filter_caching_is_lexically_scoped.rs @@ -0,0 +1,69 @@ +// Tests that depend on a count of the number of times their filter is evaluated +// can't exist in the same file with other tests that add subscribers to the +// registry. The registry was changed so that each time a new dispatcher is +// added all filters are re-evaluated. The tests being run only in separate +// threads with shared global state lets them interfere with each other + +#[cfg(not(feature = "std"))] +extern crate std; + +#[macro_use] +extern crate tracing; +mod support; + +use self::support::*; +use tracing::Level; + +use std::sync::{ + atomic::{AtomicUsize, Ordering}, + Arc, +}; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn filter_caching_is_lexically_scoped() { + pub fn my_great_function() -> bool { + span!(Level::TRACE, "emily").in_scope(|| true) + } + + pub fn my_other_function() -> bool { + span!(Level::TRACE, "frank").in_scope(|| true) + } + + let count = Arc::new(AtomicUsize::new(0)); + let count2 = count.clone(); + + let subscriber = subscriber::mock() + .with_filter(move |meta| match meta.name() { + "emily" | "frank" => { + count2.fetch_add(1, Ordering::Relaxed); + true + } + _ => false, + }) + .run(); + + // Since this test is in its own file anyway, we can do this. Thus, this + // test will work even with no-std. + tracing::subscriber::set_global_default(subscriber).unwrap(); + + // Call the function once. The filter should be re-evaluated. + assert!(my_great_function()); + assert_eq!(count.load(Ordering::Relaxed), 1); + + // Call the function again. The cached result should be used. + assert!(my_great_function()); + assert_eq!(count.load(Ordering::Relaxed), 1); + + assert!(my_other_function()); + assert_eq!(count.load(Ordering::Relaxed), 2); + + assert!(my_great_function()); + assert_eq!(count.load(Ordering::Relaxed), 2); + + assert!(my_other_function()); + assert_eq!(count.load(Ordering::Relaxed), 2); + + assert!(my_great_function()); + assert_eq!(count.load(Ordering::Relaxed), 2); +} diff --git a/third_party/rust/tracing/tests/filters_are_not_reevaluated_for_the_same_span.rs b/third_party/rust/tracing/tests/filters_are_not_reevaluated_for_the_same_span.rs new file mode 100644 index 0000000000..53e11ef448 --- /dev/null +++ b/third_party/rust/tracing/tests/filters_are_not_reevaluated_for_the_same_span.rs @@ -0,0 +1,74 @@ +// Tests that depend on a count of the number of times their filter is evaluated +// cant exist in the same file with other tests that add subscribers to the +// registry. The registry was changed so that each time a new dispatcher is +// added all filters are re-evaluated. The tests being run only in separate +// threads with shared global state lets them interfere with each other +#[cfg(not(feature = "std"))] +extern crate std; + +#[macro_use] +extern crate tracing; +mod support; + +use self::support::*; +use tracing::Level; + +use std::sync::{ + atomic::{AtomicUsize, Ordering}, + Arc, +}; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn filters_are_not_reevaluated_for_the_same_span() { + // Asserts that the `span!` macro caches the result of calling + // `Subscriber::enabled` for each span. + let alice_count = Arc::new(AtomicUsize::new(0)); + let bob_count = Arc::new(AtomicUsize::new(0)); + let alice_count2 = alice_count.clone(); + let bob_count2 = bob_count.clone(); + + let (subscriber, handle) = subscriber::mock() + .with_filter(move |meta| match meta.name() { + "alice" => { + alice_count2.fetch_add(1, Ordering::Relaxed); + false + } + "bob" => { + bob_count2.fetch_add(1, Ordering::Relaxed); + true + } + _ => false, + }) + .run_with_handle(); + + // Since this test is in its own file anyway, we can do this. Thus, this + // test will work even with no-std. + tracing::subscriber::set_global_default(subscriber).unwrap(); + + // Enter "alice" and then "bob". The dispatcher expects to see "bob" but + // not "alice." + let alice = span!(Level::TRACE, "alice"); + let bob = alice.in_scope(|| { + let bob = span!(Level::TRACE, "bob"); + bob.in_scope(|| ()); + bob + }); + + // The filter should have seen each span a single time. + assert_eq!(alice_count.load(Ordering::Relaxed), 1); + assert_eq!(bob_count.load(Ordering::Relaxed), 1); + + alice.in_scope(|| bob.in_scope(|| {})); + + // The subscriber should see "bob" again, but the filter should not have + // been called. + assert_eq!(alice_count.load(Ordering::Relaxed), 1); + assert_eq!(bob_count.load(Ordering::Relaxed), 1); + + bob.in_scope(|| {}); + assert_eq!(alice_count.load(Ordering::Relaxed), 1); + assert_eq!(bob_count.load(Ordering::Relaxed), 1); + + handle.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/filters_are_reevaluated_for_different_call_sites.rs b/third_party/rust/tracing/tests/filters_are_reevaluated_for_different_call_sites.rs new file mode 100644 index 0000000000..5675e4e678 --- /dev/null +++ b/third_party/rust/tracing/tests/filters_are_reevaluated_for_different_call_sites.rs @@ -0,0 +1,84 @@ +// Tests that depend on a count of the number of times their filter is evaluated +// cant exist in the same file with other tests that add subscribers to the +// registry. The registry was changed so that each time a new dispatcher is +// added all filters are re-evaluated. The tests being run only in separate +// threads with shared global state lets them interfere with each other +#[cfg(not(feature = "std"))] +extern crate std; + +#[macro_use] +extern crate tracing; +mod support; + +use self::support::*; +use tracing::Level; + +use std::sync::{ + atomic::{AtomicUsize, Ordering}, + Arc, +}; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn filters_are_reevaluated_for_different_call_sites() { + // Asserts that the `span!` macro caches the result of calling + // `Subscriber::enabled` for each span. + let charlie_count = Arc::new(AtomicUsize::new(0)); + let dave_count = Arc::new(AtomicUsize::new(0)); + let charlie_count2 = charlie_count.clone(); + let dave_count2 = dave_count.clone(); + + let subscriber = subscriber::mock() + .with_filter(move |meta| { + println!("Filter: {:?}", meta.name()); + match meta.name() { + "charlie" => { + charlie_count2.fetch_add(1, Ordering::Relaxed); + false + } + "dave" => { + dave_count2.fetch_add(1, Ordering::Relaxed); + true + } + _ => false, + } + }) + .run(); + + // Since this test is in its own file anyway, we can do this. Thus, this + // test will work even with no-std. + tracing::subscriber::set_global_default(subscriber).unwrap(); + + // Enter "charlie" and then "dave". The dispatcher expects to see "dave" but + // not "charlie." + let charlie = span!(Level::TRACE, "charlie"); + let dave = charlie.in_scope(|| { + let dave = span!(Level::TRACE, "dave"); + dave.in_scope(|| {}); + dave + }); + + // The filter should have seen each span a single time. + assert_eq!(charlie_count.load(Ordering::Relaxed), 1); + assert_eq!(dave_count.load(Ordering::Relaxed), 1); + + charlie.in_scope(|| dave.in_scope(|| {})); + + // The subscriber should see "dave" again, but the filter should not have + // been called. + assert_eq!(charlie_count.load(Ordering::Relaxed), 1); + assert_eq!(dave_count.load(Ordering::Relaxed), 1); + + // A different span with the same name has a different call site, so it + // should cause the filter to be reapplied. + let charlie2 = span!(Level::TRACE, "charlie"); + charlie.in_scope(|| {}); + assert_eq!(charlie_count.load(Ordering::Relaxed), 2); + assert_eq!(dave_count.load(Ordering::Relaxed), 1); + + // But, the filter should not be re-evaluated for the new "charlie" span + // when it is re-entered. + charlie2.in_scope(|| span!(Level::TRACE, "dave").in_scope(|| {})); + assert_eq!(charlie_count.load(Ordering::Relaxed), 2); + assert_eq!(dave_count.load(Ordering::Relaxed), 2); +} diff --git a/third_party/rust/tracing/tests/filters_dont_leak.rs b/third_party/rust/tracing/tests/filters_dont_leak.rs new file mode 100644 index 0000000000..666335a8a4 --- /dev/null +++ b/third_party/rust/tracing/tests/filters_dont_leak.rs @@ -0,0 +1,82 @@ +#![cfg(feature = "std")] + +mod support; +use self::support::*; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn spans_dont_leak() { + fn do_span() { + let span = tracing::debug_span!("alice"); + let _e = span.enter(); + } + + let (subscriber, handle) = subscriber::mock() + .named("spans/subscriber1") + .with_filter(|_| false) + .done() + .run_with_handle(); + + let _guard = tracing::subscriber::set_default(subscriber); + + do_span(); + + let alice = span::mock().named("alice"); + let (subscriber2, handle2) = subscriber::mock() + .named("spans/subscriber2") + .with_filter(|_| true) + .new_span(alice.clone()) + .enter(alice.clone()) + .exit(alice.clone()) + .drop_span(alice) + .done() + .run_with_handle(); + + tracing::subscriber::with_default(subscriber2, || { + println!("--- subscriber 2 is default ---"); + do_span() + }); + + println!("--- subscriber 1 is default ---"); + do_span(); + + handle.assert_finished(); + handle2.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn events_dont_leak() { + fn do_event() { + tracing::debug!("alice"); + } + + let (subscriber, handle) = subscriber::mock() + .named("events/subscriber1") + .with_filter(|_| false) + .done() + .run_with_handle(); + + let _guard = tracing::subscriber::set_default(subscriber); + + do_event(); + + let (subscriber2, handle2) = subscriber::mock() + .named("events/subscriber2") + .with_filter(|_| true) + .event(event::mock()) + .done() + .run_with_handle(); + + tracing::subscriber::with_default(subscriber2, || { + println!("--- subscriber 2 is default ---"); + do_event() + }); + + println!("--- subscriber 1 is default ---"); + + do_event(); + + handle.assert_finished(); + handle2.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/macro_imports.rs b/third_party/rust/tracing/tests/macro_imports.rs new file mode 100644 index 0000000000..2d0a9d6528 --- /dev/null +++ b/third_party/rust/tracing/tests/macro_imports.rs @@ -0,0 +1,23 @@ +use tracing::Level; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn prefixed_span_macros() { + tracing::span!(Level::DEBUG, "foo"); + tracing::trace_span!("foo"); + tracing::debug_span!("foo"); + tracing::info_span!("foo"); + tracing::warn_span!("foo"); + tracing::error_span!("foo"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn prefixed_event_macros() { + tracing::event!(Level::DEBUG, "foo"); + tracing::trace!("foo"); + tracing::debug!("foo"); + tracing::info!("foo"); + tracing::warn!("foo"); + tracing::error!("foo"); +} diff --git a/third_party/rust/tracing/tests/macros.rs b/third_party/rust/tracing/tests/macros.rs new file mode 100644 index 0000000000..39642667f7 --- /dev/null +++ b/third_party/rust/tracing/tests/macros.rs @@ -0,0 +1,890 @@ +#![deny(warnings)] +use tracing::Level; + +#[macro_use] +extern crate tracing; +// Tests that macros work across various invocation syntax. +// +// These are quite repetitive, and _could_ be generated by a macro. However, +// they're compile-time tests, so I want to get line numbers etc out of +// failures, and producing them with a macro would muddy the waters a bit. + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span() { + span!(target: "foo_events", Level::DEBUG, "foo", bar.baz = ?2, quux = %3, quuux = 4); + span!(target: "foo_events", Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(target: "foo_events", Level::DEBUG, "foo"); + span!(target: "foo_events", Level::DEBUG, "bar",); + span!(Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(Level::DEBUG, "foo", bar.baz = ?2); + span!(Level::DEBUG, "foo", bar.baz = %2); + span!(Level::DEBUG, "foo"); + span!(Level::DEBUG, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace_span() { + trace_span!(target: "foo_events", "foo", bar.baz = ?2, quux = %3, quuux = 4); + trace_span!(target: "foo_events", "foo", bar.baz = 2, quux = 3); + trace_span!(target: "foo_events", "foo", bar.baz = 2, quux = 4,); + trace_span!(target: "foo_events", "foo"); + trace_span!(target: "foo_events", "bar",); + trace_span!("foo", bar.baz = 2, quux = 3); + trace_span!("foo", bar.baz = 2, quux = 4,); + trace_span!("foo", bar.baz = ?2); + trace_span!("foo", bar.baz = %2); + trace_span!("bar"); + trace_span!("bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_span() { + debug_span!(target: "foo_events", "foo", bar.baz = ?2, quux = %3, quuux = 4); + debug_span!(target: "foo_events", "foo", bar.baz = 2, quux = 3); + debug_span!(target: "foo_events", "foo", bar.baz = 2, quux = 4,); + debug_span!(target: "foo_events", "foo"); + debug_span!(target: "foo_events", "bar",); + debug_span!("foo", bar.baz = 2, quux = 3); + debug_span!("foo", bar.baz = 2, quux = 4,); + debug_span!("foo", bar.baz = ?2); + debug_span!("foo", bar.baz = %2); + debug_span!("bar"); + debug_span!("bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info_span() { + info_span!(target: "foo_events", "foo", bar.baz = ?2, quux = %3, quuux = 4); + info_span!(target: "foo_events", "foo", bar.baz = 2, quux = 3); + info_span!(target: "foo_events", "foo", bar.baz = 2, quux = 4,); + info_span!(target: "foo_events", "foo"); + info_span!(target: "foo_events", "bar",); + info_span!("foo", bar.baz = 2, quux = 3); + info_span!("foo", bar.baz = 2, quux = 4,); + info_span!("foo", bar.baz = ?2); + info_span!("foo", bar.baz = %2); + info_span!("bar"); + info_span!("bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn_span() { + warn_span!(target: "foo_events", "foo", bar.baz = ?2, quux = %3, quuux = 4); + warn_span!(target: "foo_events", "foo", bar.baz = 2, quux = 3); + warn_span!(target: "foo_events", "foo", bar.baz = 2, quux = 4,); + warn_span!(target: "foo_events", "foo"); + warn_span!(target: "foo_events", "bar",); + warn_span!("foo", bar.baz = 2, quux = 3); + warn_span!("foo", bar.baz = 2, quux = 4,); + warn_span!("foo", bar.baz = ?2); + warn_span!("foo", bar.baz = %2); + warn_span!("bar"); + warn_span!("bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error_span() { + error_span!(target: "foo_events", "foo", bar.baz = ?2, quux = %3, quuux = 4); + error_span!(target: "foo_events", "foo", bar.baz = 2, quux = 3); + error_span!(target: "foo_events", "foo", bar.baz = 2, quux = 4,); + error_span!(target: "foo_events", "foo"); + error_span!(target: "foo_events", "bar",); + error_span!("foo", bar.baz = 2, quux = 3); + error_span!("foo", bar.baz = 2, quux = 4,); + error_span!("foo", bar.baz = ?2); + error_span!("foo", bar.baz = %2); + error_span!("bar"); + error_span!("bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span_root() { + span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", parent: None, Level::TRACE, "foo", bar.baz = 2, quux = 4,); + span!(target: "foo_events", parent: None, Level::TRACE, "foo"); + span!(target: "foo_events", parent: None, Level::TRACE, "bar",); + span!(parent: None, Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(parent: None, Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(parent: None, Level::DEBUG, "foo"); + span!(parent: None, Level::DEBUG, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace_span_root() { + trace_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); + trace_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); + trace_span!(target: "foo_events", parent: None, "foo"); + trace_span!(target: "foo_events", parent: None, "bar",); + trace_span!(parent: None, "foo", bar.baz = 2, quux = 3); + trace_span!(parent: None, "foo", bar.baz = 2, quux = 4,); + trace_span!(parent: None, "foo"); + trace_span!(parent: None, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_span_root() { + debug_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); + debug_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); + debug_span!(target: "foo_events", parent: None, "foo"); + debug_span!(target: "foo_events", parent: None, "bar",); + debug_span!(parent: None, "foo", bar.baz = 2, quux = 3); + debug_span!(parent: None, "foo", bar.baz = 2, quux = 4,); + debug_span!(parent: None, "foo"); + debug_span!(parent: None, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info_span_root() { + info_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); + info_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); + info_span!(target: "foo_events", parent: None, "foo"); + info_span!(target: "foo_events", parent: None, "bar",); + info_span!(parent: None, "foo", bar.baz = 2, quux = 3); + info_span!(parent: None, "foo", bar.baz = 2, quux = 4,); + info_span!(parent: None, "foo"); + info_span!(parent: None, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn_span_root() { + warn_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); + warn_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); + warn_span!(target: "foo_events", parent: None, "foo"); + warn_span!(target: "foo_events", parent: None, "bar",); + warn_span!(parent: None, "foo", bar.baz = 2, quux = 3); + warn_span!(parent: None, "foo", bar.baz = 2, quux = 4,); + warn_span!(parent: None, "foo"); + warn_span!(parent: None, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error_span_root() { + error_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 3); + error_span!(target: "foo_events", parent: None, "foo", bar.baz = 2, quux = 4,); + error_span!(target: "foo_events", parent: None, "foo"); + error_span!(target: "foo_events", parent: None, "bar",); + error_span!(parent: None, "foo", bar.baz = 2, quux = 3); + error_span!(parent: None, "foo", bar.baz = 2, quux = 4,); + error_span!(parent: None, "foo"); + error_span!(parent: None, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + span!(target: "foo_events", parent: &p, Level::TRACE, "foo", bar.baz = 2, quux = 3); + span!(target: "foo_events", parent: &p, Level::TRACE, "foo", bar.baz = 2, quux = 4,); + span!(target: "foo_events", parent: &p, Level::TRACE, "foo"); + span!(target: "foo_events", parent: &p, Level::TRACE, "bar",); + span!(parent: &p, Level::DEBUG, "foo", bar.baz = 2, quux = 3); + span!(parent: &p, Level::DEBUG, "foo", bar.baz = 2, quux = 4,); + span!(parent: &p, Level::DEBUG, "foo"); + span!(parent: &p, Level::DEBUG, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + trace_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 3); + trace_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 4,); + trace_span!(target: "foo_events", parent: &p, "foo"); + trace_span!(target: "foo_events", parent: &p, "bar",); + + trace_span!(parent: &p, "foo", bar.baz = 2, quux = 3); + trace_span!(parent: &p, "foo", bar.baz = 2, quux = 4,); + + trace_span!(parent: &p, "foo"); + trace_span!(parent: &p, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + debug_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 3); + debug_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 4,); + debug_span!(target: "foo_events", parent: &p, "foo"); + debug_span!(target: "foo_events", parent: &p, "bar",); + + debug_span!(parent: &p, "foo", bar.baz = 2, quux = 3); + debug_span!(parent: &p, "foo", bar.baz = 2, quux = 4,); + + debug_span!(parent: &p, "foo"); + debug_span!(parent: &p, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + info_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 3); + info_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 4,); + info_span!(target: "foo_events", parent: &p, "foo"); + info_span!(target: "foo_events", parent: &p, "bar",); + + info_span!(parent: &p, "foo", bar.baz = 2, quux = 3); + info_span!(parent: &p, "foo", bar.baz = 2, quux = 4,); + + info_span!(parent: &p, "foo"); + info_span!(parent: &p, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + warn_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 3); + warn_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 4,); + warn_span!(target: "foo_events", parent: &p, "foo"); + warn_span!(target: "foo_events", parent: &p, "bar",); + + warn_span!(parent: &p, "foo", bar.baz = 2, quux = 3); + warn_span!(parent: &p, "foo", bar.baz = 2, quux = 4,); + + warn_span!(parent: &p, "foo"); + warn_span!(parent: &p, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + error_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 3); + error_span!(target: "foo_events", parent: &p, "foo", bar.baz = 2, quux = 4,); + error_span!(target: "foo_events", parent: &p, "foo"); + error_span!(target: "foo_events", parent: &p, "bar",); + + error_span!(parent: &p, "foo", bar.baz = 2, quux = 3); + error_span!(parent: &p, "foo", bar.baz = 2, quux = 4,); + + error_span!(parent: &p, "foo"); + error_span!(parent: &p, "bar",); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span_with_non_rust_symbol() { + span!(Level::TRACE, "non-rust", "guid:x-request-id" = ?"abcdef", "more {}", 42); + span!(Level::TRACE, "non-rust", "guid:x-request-id" = %"abcdef", "more {}", 51); + span!( + Level::TRACE, + "non-rust", + "guid:x-request-id" = "abcdef", + "more {}", + 60 + ); + span!(Level::TRACE, "non-rust", "guid:x-request-id" = ?"abcdef"); + span!(Level::TRACE, "non-rust", "guid:x-request-id" = %"abcdef"); + span!(Level::TRACE, "non-rust", "guid:x-request-id" = "abcdef"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event() { + event!(Level::DEBUG, foo = ?3, bar.baz = %2, quux = false); + event!(Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(Level::DEBUG, foo = 3, bar.baz = 3,); + event!(Level::DEBUG, "foo"); + event!(Level::DEBUG, "foo: {}", 3); + event!(Level::INFO, foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + event!( + Level::INFO, + foo = 3, + bar.baz = 2, + quux = false, + "hello world {:?}", + 42 + ); + event!(Level::INFO, foo = 3, bar.baz = 3, "hello world {:?}", 42,); + event!(Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(Level::DEBUG, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", Level::DEBUG, foo = 3, bar.baz = 3,); + event!(target: "foo_events", Level::DEBUG, "foo"); + event!(target: "foo_events", Level::DEBUG, "foo: {}", 3); + event!(target: "foo_events", Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + event!(Level::DEBUG, ?foo); + event!(Level::DEBUG, %foo); + event!(Level::DEBUG, foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn locals_with_message() { + let data = (42, "forty-two"); + let private_data = "private"; + let error = "a bad error"; + event!(Level::ERROR, %error, "Received error"); + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + "App warning: {}", + error + ); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn locals_no_message() { + let data = (42, "forty-two"); + let private_data = "private"; + let error = "a bad error"; + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + ); + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + error, + ); + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + error + ); + event!(Level::WARN, private_data, ?data, error,); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace() { + trace!(foo = ?3, bar.baz = %2, quux = false); + trace!(foo = 3, bar.baz = 2, quux = false); + trace!(foo = 3, bar.baz = 3,); + trace!("foo"); + trace!("foo: {}", 3); + trace!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + trace!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); + trace!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); + trace!({ foo = 3, bar.baz = 80 }, "quux"); + trace!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!({ foo = 2, bar.baz = 78 }, "quux"); + trace!({ foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", foo = 3, bar.baz = 3,); + trace!(target: "foo_events", "foo"); + trace!(target: "foo_events", "foo: {}", 3); + trace!(target: "foo_events", { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + trace!(?foo); + trace!(%foo); + trace!(foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug() { + debug!(foo = ?3, bar.baz = %2, quux = false); + debug!(foo = 3, bar.baz = 2, quux = false); + debug!(foo = 3, bar.baz = 3,); + debug!("foo"); + debug!("foo: {}", 3); + debug!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + debug!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); + debug!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); + debug!({ foo = 3, bar.baz = 80 }, "quux"); + debug!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!({ foo = 2, bar.baz = 78 }, "quux"); + debug!({ foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", foo = 3, bar.baz = 3,); + debug!(target: "foo_events", "foo"); + debug!(target: "foo_events", "foo: {}", 3); + debug!(target: "foo_events", { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + debug!(?foo); + debug!(%foo); + debug!(foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info() { + info!(foo = ?3, bar.baz = %2, quux = false); + info!(foo = 3, bar.baz = 2, quux = false); + info!(foo = 3, bar.baz = 3,); + info!("foo"); + info!("foo: {}", 3); + info!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + info!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); + info!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); + info!({ foo = 3, bar.baz = 80 }, "quux"); + info!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!({ foo = 2, bar.baz = 78 }, "quux"); + info!({ foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", foo = 3, bar.baz = 3,); + info!(target: "foo_events", "foo"); + info!(target: "foo_events", "foo: {}", 3); + info!(target: "foo_events", { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + info!(?foo); + info!(%foo); + info!(foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn() { + warn!(foo = ?3, bar.baz = %2, quux = false); + warn!(foo = 3, bar.baz = 2, quux = false); + warn!(foo = 3, bar.baz = 3,); + warn!("foo"); + warn!("foo: {}", 3); + warn!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + warn!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); + warn!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); + warn!({ foo = 3, bar.baz = 80 }, "quux"); + warn!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!({ foo = 2, bar.baz = 78 }, "quux"); + warn!({ foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", foo = 3, bar.baz = 3,); + warn!(target: "foo_events", "foo"); + warn!(target: "foo_events", "foo: {}", 3); + warn!(target: "foo_events", { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + warn!(?foo); + warn!(%foo); + warn!(foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error() { + error!(foo = ?3, bar.baz = %2, quux = false); + error!(foo = 3, bar.baz = 2, quux = false); + error!(foo = 3, bar.baz = 3,); + error!("foo"); + error!("foo: {}", 3); + error!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); + error!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); + error!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); + error!({ foo = 3, bar.baz = 80 }, "quux"); + error!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!({ foo = 2, bar.baz = 78, }, "quux"); + error!({ foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", foo = 3, bar.baz = 3,); + error!(target: "foo_events", "foo"); + error!(target: "foo_events", "foo: {}", 3); + error!(target: "foo_events", { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); + let foo = 1; + error!(?foo); + error!(%foo); + error!(foo); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event_root() { + event!(parent: None, Level::DEBUG, foo = ?3, bar.baz = %2, quux = false); + event!( + parent: None, + Level::DEBUG, + foo = 3, + bar.baz = 2, + quux = false + ); + event!(parent: None, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(parent: None, Level::DEBUG, "foo"); + event!(parent: None, Level::DEBUG, "foo: {}", 3); + event!(parent: None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(parent: None, Level::DEBUG, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", parent: None, Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", parent: None, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(target: "foo_events", parent: None, Level::DEBUG, "foo"); + event!(target: "foo_events", parent: None, Level::DEBUG, "foo: {}", 3); + event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", parent: None, Level::DEBUG, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace_root() { + trace!(parent: None, foo = ?3, bar.baz = %2, quux = false); + trace!(parent: None, foo = 3, bar.baz = 2, quux = false); + trace!(parent: None, foo = 3, bar.baz = 3,); + trace!(parent: None, "foo"); + trace!(parent: None, "foo: {}", 3); + trace!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + trace!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + trace!(target: "foo_events", parent: None, "foo"); + trace!(target: "foo_events", parent: None, "foo: {}", 3); + trace!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_root() { + debug!(parent: None, foo = ?3, bar.baz = %2, quux = false); + debug!(parent: None, foo = 3, bar.baz = 2, quux = false); + debug!(parent: None, foo = 3, bar.baz = 3,); + debug!(parent: None, "foo"); + debug!(parent: None, "foo: {}", 3); + debug!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + debug!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + debug!(target: "foo_events", parent: None, "foo"); + debug!(target: "foo_events", parent: None, "foo: {}", 3); + debug!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info_root() { + info!(parent: None, foo = ?3, bar.baz = %2, quux = false); + info!(parent: None, foo = 3, bar.baz = 2, quux = false); + info!(parent: None, foo = 3, bar.baz = 3,); + info!(parent: None, "foo"); + info!(parent: None, "foo: {}", 3); + info!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + info!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + info!(target: "foo_events", parent: None, "foo"); + info!(target: "foo_events", parent: None, "foo: {}", 3); + info!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn_root() { + warn!(parent: None, foo = ?3, bar.baz = %2, quux = false); + warn!(parent: None, foo = 3, bar.baz = 2, quux = false); + warn!(parent: None, foo = 3, bar.baz = 3,); + warn!(parent: None, "foo"); + warn!(parent: None, "foo: {}", 3); + warn!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + warn!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + warn!(target: "foo_events", parent: None, "foo"); + warn!(target: "foo_events", parent: None, "foo: {}", 3); + warn!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error_root() { + error!(parent: None, foo = ?3, bar.baz = %2, quux = false); + error!(parent: None, foo = 3, bar.baz = 2, quux = false); + error!(parent: None, foo = 3, bar.baz = 3,); + error!(parent: None, "foo"); + error!(parent: None, "foo: {}", 3); + error!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + error!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + error!(target: "foo_events", parent: None, "foo"); + error!(target: "foo_events", parent: None, "foo: {}", 3); + error!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + event!(parent: &p, Level::DEBUG, foo = ?3, bar.baz = %2, quux = false); + event!(parent: &p, Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(parent: &p, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(parent: &p, Level::DEBUG, "foo"); + event!(parent: &p, Level::DEBUG, "foo: {}", 3); + event!(parent: &p, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(parent: &p, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(parent: &p, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(parent: &p, Level::DEBUG, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", parent: &p, Level::DEBUG, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", parent: &p, Level::DEBUG, foo = 3, bar.baz = 3,); + event!(target: "foo_events", parent: &p, Level::DEBUG, "foo"); + event!(target: "foo_events", parent: &p, Level::DEBUG, "foo: {}", 3); + event!(target: "foo_events", parent: &p, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", parent: &p, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", parent: &p, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", parent: &p, Level::DEBUG, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn trace_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + trace!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + trace!(parent: &p, foo = 3, bar.baz = 2, quux = false); + trace!(parent: &p, foo = 3, bar.baz = 3,); + trace!(parent: &p, "foo"); + trace!(parent: &p, "foo: {}", 3); + trace!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + trace!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + trace!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + trace!(target: "foo_events", parent: &p, "foo"); + trace!(target: "foo_events", parent: &p, "foo: {}", 3); + trace!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + debug!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + debug!(parent: &p, foo = 3, bar.baz = 2, quux = false); + debug!(parent: &p, foo = 3, bar.baz = 3,); + debug!(parent: &p, "foo"); + debug!(parent: &p, "foo: {}", 3); + debug!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + debug!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + debug!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + debug!(target: "foo_events", parent: &p, "foo"); + debug!(target: "foo_events", parent: &p, "foo: {}", 3); + debug!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn info_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + info!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + info!(parent: &p, foo = 3, bar.baz = 2, quux = false); + info!(parent: &p, foo = 3, bar.baz = 3,); + info!(parent: &p, "foo"); + info!(parent: &p, "foo: {}", 3); + info!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + info!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + info!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + info!(target: "foo_events", parent: &p, "foo"); + info!(target: "foo_events", parent: &p, "foo: {}", 3); + info!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn warn_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + warn!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + warn!(parent: &p, foo = 3, bar.baz = 2, quux = false); + warn!(parent: &p, foo = 3, bar.baz = 3,); + warn!(parent: &p, "foo"); + warn!(parent: &p, "foo: {}", 3); + warn!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + warn!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + warn!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + warn!(target: "foo_events", parent: &p, "foo"); + warn!(target: "foo_events", parent: &p, "foo: {}", 3); + warn!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn error_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + error!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + error!(parent: &p, foo = 3, bar.baz = 2, quux = false); + error!(parent: &p, foo = 3, bar.baz = 3,); + error!(parent: &p, "foo"); + error!(parent: &p, "foo: {}", 3); + error!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + error!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + error!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + error!(target: "foo_events", parent: &p, "foo"); + error!(target: "foo_events", parent: &p, "foo: {}", 3); + error!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn field_shorthand_only() { + #[derive(Debug)] + struct Position { + x: f32, + y: f32, + } + let pos = Position { + x: 3.234, + y: -1.223, + }; + + trace!(?pos.x, ?pos.y); + debug!(?pos.x, ?pos.y); + info!(?pos.x, ?pos.y); + warn!(?pos.x, ?pos.y); + error!(?pos.x, ?pos.y); + event!(Level::TRACE, ?pos.x, ?pos.y); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn borrow_val_events() { + // Reproduces https://github.com/tokio-rs/tracing/issues/954 + let mut foo = (String::new(), String::new()); + let zero = &mut foo.0; + trace!(one = ?foo.1); + debug!(one = ?foo.1); + info!(one = ?foo.1); + warn!(one = ?foo.1); + error!(one = ?foo.1); + zero.push_str("hello world"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn borrow_val_spans() { + // Reproduces https://github.com/tokio-rs/tracing/issues/954 + let mut foo = (String::new(), String::new()); + let zero = &mut foo.0; + let _span = trace_span!("span", one = ?foo.1); + let _span = debug_span!("span", one = ?foo.1); + let _span = info_span!("span", one = ?foo.1); + let _span = warn_span!("span", one = ?foo.1); + let _span = error_span!("span", one = ?foo.1); + zero.push_str("hello world"); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn callsite_macro_api() { + // This test should catch any inadvertent breaking changes + // caused by changes to the macro. + let _callsite = callsite! { + name: "test callsite", + kind: tracing::metadata::Kind::EVENT, + target: "test target", + level: tracing::Level::TRACE, + fields: foo, bar, + }; + let _callsite = callsite! { + name: "test callsite", + kind: tracing::metadata::Kind::SPAN, + level: tracing::Level::TRACE, + fields: foo, + }; + let _callsite = callsite! { + name: "test callsite", + kind: tracing::metadata::Kind::SPAN, + fields: foo, + }; +} diff --git a/third_party/rust/tracing/tests/max_level_hint.rs b/third_party/rust/tracing/tests/max_level_hint.rs new file mode 100644 index 0000000000..49f14d55fe --- /dev/null +++ b/third_party/rust/tracing/tests/max_level_hint.rs @@ -0,0 +1,39 @@ +mod support; + +use self::support::*; +use tracing::Level; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn max_level_hints() { + // This test asserts that when a subscriber provides us with the global + // maximum level that it will enable (by implementing the + // `Subscriber::max_level_hint` method), we will never call + // `Subscriber::enabled` for events above that maximum level. + // + // In this case, we test that by making the `enabled` method assert that no + // `Metadata` for spans or events at the `TRACE` or `DEBUG` levels. + let (subscriber, handle) = subscriber::mock() + .with_max_level_hint(Level::INFO) + .with_filter(|meta| { + assert!( + dbg!(meta).level() <= &Level::INFO, + "a TRACE or DEBUG event was dynamically filtered: " + ); + true + }) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + tracing::subscriber::set_global_default(subscriber).unwrap(); + + tracing::info!("doing a thing that you might care about"); + tracing::debug!("charging turboencabulator with interocitor"); + tracing::warn!("extremely serious warning, pay attention"); + tracing::trace!("interocitor charge level is 10%"); + tracing::error!("everything is on fire"); + handle.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/multiple_max_level_hints.rs b/third_party/rust/tracing/tests/multiple_max_level_hints.rs new file mode 100644 index 0000000000..b2be6351cf --- /dev/null +++ b/third_party/rust/tracing/tests/multiple_max_level_hints.rs @@ -0,0 +1,70 @@ +#![cfg(feature = "std")] +mod support; + +use self::support::*; +use tracing::Level; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn multiple_max_level_hints() { + // This test ensures that when multiple subscribers are active, their max + // level hints are handled correctly. The global max level should be the + // maximum of the level filters returned by the two `Subscriber`'s + // `max_level_hint` method. + // + // In this test, we create a subscriber whose max level is `INFO`, and + // another whose max level is `DEBUG`. We then add an assertion to both of + // those subscribers' `enabled` method that no metadata for `TRACE` spans or + // events are filtered, since they are disabled by the global max filter. + + fn do_events() { + tracing::info!("doing a thing that you might care about"); + tracing::debug!("charging turboencabulator with interocitor"); + tracing::warn!("extremely serious warning, pay attention"); + tracing::trace!("interocitor charge level is 10%"); + tracing::error!("everything is on fire"); + } + + let (subscriber1, handle1) = subscriber::mock() + .named("subscriber1") + .with_max_level_hint(Level::INFO) + .with_filter(|meta| { + let level = dbg!(meta.level()); + assert!( + level <= &Level::DEBUG, + "a TRACE event was dynamically filtered by subscriber1" + ); + level <= &Level::INFO + }) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let (subscriber2, handle2) = subscriber::mock() + .named("subscriber2") + .with_max_level_hint(Level::DEBUG) + .with_filter(|meta| { + let level = dbg!(meta.level()); + assert!( + level <= &Level::DEBUG, + "a TRACE event was dynamically filtered by subscriber2" + ); + level <= &Level::DEBUG + }) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let dispatch1 = tracing::Dispatch::new(subscriber1); + + tracing::dispatcher::with_default(&dispatch1, do_events); + handle1.assert_finished(); + + let dispatch2 = tracing::Dispatch::new(subscriber2); + tracing::dispatcher::with_default(&dispatch2, do_events); + handle2.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/span.rs b/third_party/rust/tracing/tests/span.rs new file mode 100644 index 0000000000..79914950c2 --- /dev/null +++ b/third_party/rust/tracing/tests/span.rs @@ -0,0 +1,767 @@ +// These tests require the thread-local scoped dispatcher, which only works when +// we have a standard library. The behaviour being tested should be the same +// with the standard lib disabled. +#![cfg(feature = "std")] + +#[macro_use] +extern crate tracing; +mod support; + +use self::support::*; +use std::thread; +use tracing::{ + field::{debug, display}, + subscriber::with_default, + Level, Span, +}; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn handles_to_the_same_span_are_equal() { + // Create a mock subscriber that will return `true` on calls to + // `Subscriber::enabled`, so that the spans will be constructed. We + // won't enter any spans in this test, so the subscriber won't actually + // expect to see any spans. + with_default(subscriber::mock().run(), || { + let foo1 = span!(Level::TRACE, "foo"); + let foo2 = foo1.clone(); + // Two handles that point to the same span are equal. + assert_eq!(foo1, foo2); + }); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn handles_to_different_spans_are_not_equal() { + with_default(subscriber::mock().run(), || { + // Even though these spans have the same name and fields, they will have + // differing metadata, since they were created on different lines. + let foo1 = span!(Level::TRACE, "foo", bar = 1u64, baz = false); + let foo2 = span!(Level::TRACE, "foo", bar = 1u64, baz = false); + + assert_ne!(foo1, foo2); + }); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn handles_to_different_spans_with_the_same_metadata_are_not_equal() { + // Every time time this function is called, it will return a _new + // instance_ of a span with the same metadata, name, and fields. + fn make_span() -> Span { + span!(Level::TRACE, "foo", bar = 1u64, baz = false) + } + + with_default(subscriber::mock().run(), || { + let foo1 = make_span(); + let foo2 = make_span(); + + assert_ne!(foo1, foo2); + // assert_ne!(foo1.data(), foo2.data()); + }); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn spans_always_go_to_the_subscriber_that_tagged_them() { + let subscriber1 = subscriber::mock() + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run(); + let subscriber2 = subscriber::mock().run(); + + let foo = with_default(subscriber1, || { + let foo = span!(Level::TRACE, "foo"); + foo.in_scope(|| {}); + foo + }); + // Even though we enter subscriber 2's context, the subscriber that + // tagged the span should see the enter/exit. + with_default(subscriber2, move || foo.in_scope(|| {})); +} + +// This gets exempt from testing in wasm because of: `thread::spawn` which is +// not yet possible to do in WASM. There is work going on see: +// <https://rustwasm.github.io/2018/10/24/multithreading-rust-and-wasm.html> +// +// But for now since it's not possible we don't need to test for it :) +#[test] +fn spans_always_go_to_the_subscriber_that_tagged_them_even_across_threads() { + let subscriber1 = subscriber::mock() + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run(); + let foo = with_default(subscriber1, || { + let foo = span!(Level::TRACE, "foo"); + foo.in_scope(|| {}); + foo + }); + + // Even though we enter subscriber 2's context, the subscriber that + // tagged the span should see the enter/exit. + thread::spawn(move || { + with_default(subscriber::mock().run(), || { + foo.in_scope(|| {}); + }) + }) + .join() + .unwrap(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn dropping_a_span_calls_drop_span() { + let (subscriber, handle) = subscriber::mock() + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo"); + span.in_scope(|| {}); + drop(span); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span_closes_after_event() { + let (subscriber, handle) = subscriber::mock() + .enter(span::mock().named("foo")) + .event(event::mock()) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "foo").in_scope(|| { + event!(Level::DEBUG, {}, "my event!"); + }); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn new_span_after_event() { + let (subscriber, handle) = subscriber::mock() + .enter(span::mock().named("foo")) + .event(event::mock()) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .enter(span::mock().named("bar")) + .exit(span::mock().named("bar")) + .drop_span(span::mock().named("bar")) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "foo").in_scope(|| { + event!(Level::DEBUG, {}, "my event!"); + }); + span!(Level::TRACE, "bar").in_scope(|| {}); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event_outside_of_span() { + let (subscriber, handle) = subscriber::mock() + .event(event::mock()) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + debug!("my event!"); + span!(Level::TRACE, "foo").in_scope(|| {}); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn cloning_a_span_calls_clone_span() { + let (subscriber, handle) = subscriber::mock() + .clone_span(span::mock().named("foo")) + .run_with_handle(); + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo"); + // Allow the "redundant" `.clone` since it is used to call into the `.clone_span` hook. + #[allow(clippy::redundant_clone)] + let _span2 = span.clone(); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn drop_span_when_exiting_dispatchers_context() { + let (subscriber, handle) = subscriber::mock() + .clone_span(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .run_with_handle(); + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo"); + let _span2 = span.clone(); + drop(span); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn clone_and_drop_span_always_go_to_the_subscriber_that_tagged_the_span() { + let (subscriber1, handle1) = subscriber::mock() + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .clone_span(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .run_with_handle(); + let subscriber2 = subscriber::mock().done().run(); + + let foo = with_default(subscriber1, || { + let foo = span!(Level::TRACE, "foo"); + foo.in_scope(|| {}); + foo + }); + // Even though we enter subscriber 2's context, the subscriber that + // tagged the span should see the enter/exit. + with_default(subscriber2, move || { + let foo2 = foo.clone(); + foo.in_scope(|| {}); + drop(foo); + drop(foo2); + }); + + handle1.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn span_closes_when_exited() { + let (subscriber, handle) = subscriber::mock() + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + + foo.in_scope(|| {}); + + drop(foo); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn enter() { + let (subscriber, handle) = subscriber::mock() + .enter(span::mock().named("foo")) + .event(event::mock()) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + let _enter = foo.enter(); + debug!("dropping guard..."); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn moved_field() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&display("hello from my span")) + .only(), + ), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + with_default(subscriber, || { + let from = "my span"; + let span = span!( + Level::TRACE, + "foo", + bar = display(format!("hello from {}", from)) + ); + span.in_scope(|| {}); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn dotted_field_name() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock() + .named("foo") + .with_field(field::mock("fields.bar").with_value(&true).only()), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "foo", fields.bar = true); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn borrowed_field() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&display("hello from my span")) + .only(), + ), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let from = "my span"; + let mut message = format!("hello from {}", from); + let span = span!(Level::TRACE, "foo", bar = display(&message)); + span.in_scope(|| { + message.insert_str(10, " inside"); + }); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +// If emitting log instrumentation, this gets moved anyway, breaking the test. +#[cfg(not(feature = "log"))] +fn move_field_out_of_struct() { + use tracing::field::debug; + + #[derive(Debug)] + struct Position { + x: f32, + y: f32, + } + + let pos = Position { + x: 3.234, + y: -1.223, + }; + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("x") + .with_value(&debug(3.234)) + .and(field::mock("y").with_value(&debug(-1.223))) + .only(), + ), + ) + .new_span( + span::mock() + .named("bar") + .with_field(field::mock("position").with_value(&debug(&pos)).only()), + ) + .run_with_handle(); + + with_default(subscriber, || { + let pos = Position { + x: 3.234, + y: -1.223, + }; + let foo = span!(Level::TRACE, "foo", x = debug(pos.x), y = debug(pos.y)); + let bar = span!(Level::TRACE, "bar", position = debug(pos)); + foo.in_scope(|| {}); + bar.in_scope(|| {}); + }); + + handle.assert_finished(); +} + +// TODO(#1138): determine a new syntax for uninitialized span fields, and +// re-enable these. +/* +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn add_field_after_new_span() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock() + .named("foo") + .with_field(field::mock("bar").with_value(&5) + .and(field::mock("baz").with_value).only()), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = 5, baz = false); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn add_fields_only_after_new_span() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .record( + span::mock().named("foo"), + field::mock("bar").with_value(&5).only(), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = _, baz = _); + span.record("bar", &5); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} +*/ + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn record_new_value_for_field() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&5) + .and(field::mock("baz").with_value(&false)) + .only(), + ), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = 5, baz = false); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn record_new_values_for_fields() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&4) + .and(field::mock("baz").with_value(&false)) + .only(), + ), + ) + .record( + span::mock().named("foo"), + field::mock("bar").with_value(&5).only(), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = 4, baz = false); + span.record("bar", &5); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn new_span_with_target_and_log_level() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock() + .named("foo") + .with_target("app_span") + .at_level(Level::DEBUG), + ) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(target: "app_span", Level::DEBUG, "foo"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_root_span_is_root() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo").with_explicit_parent(None)) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(parent: None, Level::TRACE, "foo"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_root_span_is_root_regardless_of_ctx() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .new_span(span::mock().named("bar").with_explicit_parent(None)) + .exit(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(Level::TRACE, "foo").in_scope(|| { + span!(parent: None, Level::TRACE, "bar"); + }) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_child() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .new_span(span::mock().named("bar").with_explicit_parent(Some("foo"))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + span!(parent: foo.id(), Level::TRACE, "bar"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_child_at_levels() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .new_span(span::mock().named("a").with_explicit_parent(Some("foo"))) + .new_span(span::mock().named("b").with_explicit_parent(Some("foo"))) + .new_span(span::mock().named("c").with_explicit_parent(Some("foo"))) + .new_span(span::mock().named("d").with_explicit_parent(Some("foo"))) + .new_span(span::mock().named("e").with_explicit_parent(Some("foo"))) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + trace_span!(parent: foo.id(), "a"); + debug_span!(parent: foo.id(), "b"); + info_span!(parent: foo.id(), "c"); + warn_span!(parent: foo.id(), "d"); + error_span!(parent: foo.id(), "e"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn explicit_child_regardless_of_ctx() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .new_span(span::mock().named("bar")) + .enter(span::mock().named("bar")) + .new_span(span::mock().named("baz").with_explicit_parent(Some("foo"))) + .exit(span::mock().named("bar")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let foo = span!(Level::TRACE, "foo"); + span!(Level::TRACE, "bar").in_scope(|| span!(parent: foo.id(), Level::TRACE, "baz")) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn contextual_root() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo").with_contextual_parent(None)) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(Level::TRACE, "foo"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn contextual_child() { + let (subscriber, handle) = subscriber::mock() + .new_span(span::mock().named("foo")) + .enter(span::mock().named("foo")) + .new_span( + span::mock() + .named("bar") + .with_contextual_parent(Some("foo")), + ) + .exit(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + span!(Level::TRACE, "foo").in_scope(|| { + span!(Level::TRACE, "bar"); + }) + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn display_shorthand() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("my_span").with_field( + field::mock("my_field") + .with_value(&display("hello world")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "my_span", my_field = %"hello world"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn debug_shorthand() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("my_span").with_field( + field::mock("my_field") + .with_value(&debug("hello world")) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "my_span", my_field = ?"hello world"); + }); + + handle.assert_finished(); +} + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn both_shorthands() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("my_span").with_field( + field::mock("display_field") + .with_value(&display("hello world")) + .and(field::mock("debug_field").with_value(&debug("hello world"))) + .only(), + ), + ) + .done() + .run_with_handle(); + with_default(subscriber, || { + span!(Level::TRACE, "my_span", display_field = %"hello world", debug_field = ?"hello world"); + }); + + handle.assert_finished(); +} diff --git a/third_party/rust/tracing/tests/subscriber.rs b/third_party/rust/tracing/tests/subscriber.rs new file mode 100644 index 0000000000..2a810c9111 --- /dev/null +++ b/third_party/rust/tracing/tests/subscriber.rs @@ -0,0 +1,57 @@ +// These tests require the thread-local scoped dispatcher, which only works when +// we have a standard library. The behaviour being tested should be the same +// with the standard lib disabled. +// +// The alternative would be for each of these tests to be defined in a separate +// file, which is :( +#![cfg(feature = "std")] + +#[macro_use] +extern crate tracing; +use tracing::{ + span, + subscriber::{with_default, Interest, Subscriber}, + Event, Level, Metadata, +}; + +#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)] +#[test] +fn event_macros_dont_infinite_loop() { + // This test ensures that an event macro within a subscriber + // won't cause an infinite loop of events. + struct TestSubscriber; + impl Subscriber for TestSubscriber { + fn register_callsite(&self, _: &Metadata<'_>) -> Interest { + // Always return sometimes so that `enabled` will be called + // (which can loop). + Interest::sometimes() + } + + fn enabled(&self, meta: &Metadata<'_>) -> bool { + assert!(meta.fields().iter().any(|f| f.name() == "foo")); + event!(Level::TRACE, bar = false); + true + } + + fn new_span(&self, _: &span::Attributes<'_>) -> span::Id { + span::Id::from_u64(0xAAAA) + } + + fn record(&self, _: &span::Id, _: &span::Record<'_>) {} + + fn record_follows_from(&self, _: &span::Id, _: &span::Id) {} + + fn event(&self, event: &Event<'_>) { + assert!(event.metadata().fields().iter().any(|f| f.name() == "foo")); + event!(Level::TRACE, baz = false); + } + + fn enter(&self, _: &span::Id) {} + + fn exit(&self, _: &span::Id) {} + } + + with_default(TestSubscriber, || { + event!(Level::TRACE, foo = false); + }) +} diff --git a/third_party/rust/tracing/tests/support/event.rs b/third_party/rust/tracing/tests/support/event.rs new file mode 100644 index 0000000000..7033d8a134 --- /dev/null +++ b/third_party/rust/tracing/tests/support/event.rs @@ -0,0 +1,99 @@ +#![allow(missing_docs)] +use super::{field, metadata, Parent}; + +use std::fmt; + +/// A mock event. +/// +/// This is intended for use with the mock subscriber API in the +/// `subscriber` module. +#[derive(Debug, Default, Eq, PartialEq)] +pub struct MockEvent { + pub fields: Option<field::Expect>, + pub(in crate::support) parent: Option<Parent>, + metadata: metadata::Expect, +} + +pub fn mock() -> MockEvent { + MockEvent { + ..Default::default() + } +} + +impl MockEvent { + pub fn named<I>(self, name: I) -> Self + where + I: Into<String>, + { + Self { + metadata: metadata::Expect { + name: Some(name.into()), + ..self.metadata + }, + ..self + } + } + + pub fn with_fields<I>(self, fields: I) -> Self + where + I: Into<field::Expect>, + { + Self { + fields: Some(fields.into()), + ..self + } + } + + pub fn at_level(self, level: tracing::Level) -> Self { + Self { + metadata: metadata::Expect { + level: Some(level), + ..self.metadata + }, + ..self + } + } + + pub fn with_target<I>(self, target: I) -> Self + where + I: Into<String>, + { + Self { + metadata: metadata::Expect { + target: Some(target.into()), + ..self.metadata + }, + ..self + } + } + + pub fn with_explicit_parent(self, parent: Option<&str>) -> MockEvent { + let parent = match parent { + Some(name) => Parent::Explicit(name.into()), + None => Parent::ExplicitRoot, + }; + Self { + parent: Some(parent), + ..self + } + } + + pub(in crate::support) fn check(&mut self, event: &tracing::Event<'_>) { + let meta = event.metadata(); + let name = meta.name(); + self.metadata + .check(meta, format_args!("event \"{}\"", name)); + assert!(meta.is_event(), "expected {}, but got {:?}", self, event); + if let Some(ref mut expected_fields) = self.fields { + let mut checker = expected_fields.checker(name.to_string()); + event.record(&mut checker); + checker.finish(); + } + } +} + +impl fmt::Display for MockEvent { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "an event{}", self.metadata) + } +} diff --git a/third_party/rust/tracing/tests/support/field.rs b/third_party/rust/tracing/tests/support/field.rs new file mode 100644 index 0000000000..3667cf08b4 --- /dev/null +++ b/third_party/rust/tracing/tests/support/field.rs @@ -0,0 +1,226 @@ +use tracing::{ + callsite, + callsite::Callsite, + field::{self, Field, Value, Visit}, + metadata::Kind, +}; + +use std::{collections::HashMap, fmt}; + +#[derive(Default, Debug, Eq, PartialEq)] +pub struct Expect { + fields: HashMap<String, MockValue>, + only: bool, +} + +#[derive(Debug)] +pub struct MockField { + name: String, + value: MockValue, +} + +#[derive(Debug, Eq, PartialEq)] +pub enum MockValue { + I64(i64), + U64(u64), + Bool(bool), + Str(String), + Debug(String), + Any, +} + +pub fn mock<K>(name: K) -> MockField +where + String: From<K>, +{ + MockField { + name: name.into(), + value: MockValue::Any, + } +} + +impl MockField { + /// Expect a field with the given name and value. + pub fn with_value(self, value: &dyn Value) -> Self { + Self { + value: MockValue::from(value), + ..self + } + } + + pub fn and(self, other: MockField) -> Expect { + Expect { + fields: HashMap::new(), + only: false, + } + .and(self) + .and(other) + } + + pub fn only(self) -> Expect { + Expect { + fields: HashMap::new(), + only: true, + } + .and(self) + } +} + +impl Into<Expect> for MockField { + fn into(self) -> Expect { + Expect { + fields: HashMap::new(), + only: false, + } + .and(self) + } +} + +impl Expect { + pub fn and(mut self, field: MockField) -> Self { + self.fields.insert(field.name, field.value); + self + } + + /// Indicates that no fields other than those specified should be expected. + pub fn only(self) -> Self { + Self { only: true, ..self } + } + + fn compare_or_panic(&mut self, name: &str, value: &dyn Value, ctx: &str) { + let value = value.into(); + match self.fields.remove(name) { + Some(MockValue::Any) => {} + Some(expected) => assert!( + expected == value, + "\nexpected `{}` to contain:\n\t`{}{}`\nbut got:\n\t`{}{}`", + ctx, + name, + expected, + name, + value + ), + None if self.only => panic!( + "\nexpected `{}` to contain only:\n\t`{}`\nbut got:\n\t`{}{}`", + ctx, self, name, value + ), + _ => {} + } + } + + pub fn checker(&mut self, ctx: String) -> CheckVisitor<'_> { + CheckVisitor { expect: self, ctx } + } + + pub fn is_empty(&self) -> bool { + self.fields.is_empty() + } +} + +impl fmt::Display for MockValue { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match self { + MockValue::I64(v) => write!(f, "i64 = {:?}", v), + MockValue::U64(v) => write!(f, "u64 = {:?}", v), + MockValue::Bool(v) => write!(f, "bool = {:?}", v), + MockValue::Str(v) => write!(f, "&str = {:?}", v), + MockValue::Debug(v) => write!(f, "&fmt::Debug = {:?}", v), + MockValue::Any => write!(f, "_ = _"), + } + } +} + +pub struct CheckVisitor<'a> { + expect: &'a mut Expect, + ctx: String, +} + +impl<'a> Visit for CheckVisitor<'a> { + fn record_i64(&mut self, field: &Field, value: i64) { + self.expect + .compare_or_panic(field.name(), &value, &self.ctx[..]) + } + + fn record_u64(&mut self, field: &Field, value: u64) { + self.expect + .compare_or_panic(field.name(), &value, &self.ctx[..]) + } + + fn record_bool(&mut self, field: &Field, value: bool) { + self.expect + .compare_or_panic(field.name(), &value, &self.ctx[..]) + } + + fn record_str(&mut self, field: &Field, value: &str) { + self.expect + .compare_or_panic(field.name(), &value, &self.ctx[..]) + } + + fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { + self.expect + .compare_or_panic(field.name(), &field::debug(value), &self.ctx) + } +} + +impl<'a> CheckVisitor<'a> { + pub fn finish(self) { + assert!( + self.expect.fields.is_empty(), + "{}missing {}", + self.expect, + self.ctx + ); + } +} + +impl<'a> From<&'a dyn Value> for MockValue { + fn from(value: &'a dyn Value) -> Self { + struct MockValueBuilder { + value: Option<MockValue>, + } + + impl Visit for MockValueBuilder { + fn record_i64(&mut self, _: &Field, value: i64) { + self.value = Some(MockValue::I64(value)); + } + + fn record_u64(&mut self, _: &Field, value: u64) { + self.value = Some(MockValue::U64(value)); + } + + fn record_bool(&mut self, _: &Field, value: bool) { + self.value = Some(MockValue::Bool(value)); + } + + fn record_str(&mut self, _: &Field, value: &str) { + self.value = Some(MockValue::Str(value.to_owned())); + } + + fn record_debug(&mut self, _: &Field, value: &dyn fmt::Debug) { + self.value = Some(MockValue::Debug(format!("{:?}", value))); + } + } + + let fake_field = callsite!(name: "fake", kind: Kind::EVENT, fields: fake_field) + .metadata() + .fields() + .field("fake_field") + .unwrap(); + let mut builder = MockValueBuilder { value: None }; + value.record(&fake_field, &mut builder); + builder + .value + .expect("finish called before a value was recorded") + } +} + +impl fmt::Display for Expect { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "fields ")?; + let entries = self + .fields + .iter() + .map(|(k, v)| (field::display(k), field::display(v))); + f.debug_map().entries(entries).finish() + } +} diff --git a/third_party/rust/tracing/tests/support/metadata.rs b/third_party/rust/tracing/tests/support/metadata.rs new file mode 100644 index 0000000000..2c3606b05e --- /dev/null +++ b/third_party/rust/tracing/tests/support/metadata.rs @@ -0,0 +1,64 @@ +use std::fmt; +use tracing::Metadata; + +#[derive(Clone, Debug, Eq, PartialEq, Default)] +pub struct Expect { + pub name: Option<String>, + pub level: Option<tracing::Level>, + pub target: Option<String>, +} + +impl Expect { + pub(in crate::support) fn check(&self, actual: &Metadata<'_>, ctx: fmt::Arguments<'_>) { + if let Some(ref expected_name) = self.name { + let name = actual.name(); + assert!( + expected_name == name, + "expected {} to be named `{}`, but got one named `{}`", + ctx, + expected_name, + name + ) + } + + if let Some(ref expected_level) = self.level { + let level = actual.level(); + assert!( + expected_level == level, + "expected {} to be at level `{:?}`, but it was at level `{:?}` instead", + ctx, + expected_level, + level, + ) + } + + if let Some(ref expected_target) = self.target { + let target = actual.target(); + assert!( + expected_target == target, + "expected {} to have target `{}`, but it had target `{}` instead", + ctx, + expected_target, + target, + ) + } + } +} + +impl fmt::Display for Expect { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if let Some(ref name) = self.name { + write!(f, " named `{}`", name)?; + } + + if let Some(ref level) = self.level { + write!(f, " at the `{:?}` level", level)?; + } + + if let Some(ref target) = self.target { + write!(f, " with target `{}`", target)?; + } + + Ok(()) + } +} diff --git a/third_party/rust/tracing/tests/support/mod.rs b/third_party/rust/tracing/tests/support/mod.rs new file mode 100644 index 0000000000..7900f38c76 --- /dev/null +++ b/third_party/rust/tracing/tests/support/mod.rs @@ -0,0 +1,14 @@ +#![allow(dead_code)] +pub mod event; +pub mod field; +mod metadata; +pub mod span; +pub mod subscriber; + +#[derive(Debug, Eq, PartialEq)] +pub(in crate::support) enum Parent { + ContextualRoot, + Contextual(String), + ExplicitRoot, + Explicit(String), +} diff --git a/third_party/rust/tracing/tests/support/span.rs b/third_party/rust/tracing/tests/support/span.rs new file mode 100644 index 0000000000..023e5b7079 --- /dev/null +++ b/third_party/rust/tracing/tests/support/span.rs @@ -0,0 +1,167 @@ +#![allow(missing_docs)] +use super::{field, metadata, Parent}; +use std::fmt; + +/// A mock span. +/// +/// This is intended for use with the mock subscriber API in the +/// `subscriber` module. +#[derive(Clone, Debug, Default, Eq, PartialEq)] +pub struct MockSpan { + pub(in crate::support) metadata: metadata::Expect, +} + +#[derive(Debug, Default, Eq, PartialEq)] +pub struct NewSpan { + pub(in crate::support) span: MockSpan, + pub(in crate::support) fields: field::Expect, + pub(in crate::support) parent: Option<Parent>, +} + +pub fn mock() -> MockSpan { + MockSpan { + ..Default::default() + } +} + +impl MockSpan { + pub fn named<I>(self, name: I) -> Self + where + I: Into<String>, + { + Self { + metadata: metadata::Expect { + name: Some(name.into()), + ..self.metadata + }, + } + } + + pub fn at_level(self, level: tracing::Level) -> Self { + Self { + metadata: metadata::Expect { + level: Some(level), + ..self.metadata + }, + } + } + + pub fn with_target<I>(self, target: I) -> Self + where + I: Into<String>, + { + Self { + metadata: metadata::Expect { + target: Some(target.into()), + ..self.metadata + }, + } + } + + pub fn with_explicit_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Explicit(name.into()), + None => Parent::ExplicitRoot, + }; + NewSpan { + parent: Some(parent), + span: self, + ..Default::default() + } + } + + pub fn with_contextual_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Contextual(name.into()), + None => Parent::ContextualRoot, + }; + NewSpan { + parent: Some(parent), + span: self, + ..Default::default() + } + } + + pub fn name(&self) -> Option<&str> { + self.metadata.name.as_ref().map(String::as_ref) + } + + pub fn with_field<I>(self, fields: I) -> NewSpan + where + I: Into<field::Expect>, + { + NewSpan { + span: self, + fields: fields.into(), + ..Default::default() + } + } + + pub(in crate::support) fn check_metadata(&self, actual: &tracing::Metadata<'_>) { + self.metadata.check(actual, format_args!("span {}", self)); + assert!(actual.is_span(), "expected a span but got {:?}", actual); + } +} + +impl fmt::Display for MockSpan { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if self.metadata.name.is_some() { + write!(f, "a span{}", self.metadata) + } else { + write!(f, "any span{}", self.metadata) + } + } +} + +impl Into<NewSpan> for MockSpan { + fn into(self) -> NewSpan { + NewSpan { + span: self, + ..Default::default() + } + } +} + +impl NewSpan { + pub fn with_explicit_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Explicit(name.into()), + None => Parent::ExplicitRoot, + }; + NewSpan { + parent: Some(parent), + ..self + } + } + + pub fn with_contextual_parent(self, parent: Option<&str>) -> NewSpan { + let parent = match parent { + Some(name) => Parent::Contextual(name.into()), + None => Parent::ContextualRoot, + }; + NewSpan { + parent: Some(parent), + ..self + } + } + + pub fn with_field<I>(self, fields: I) -> NewSpan + where + I: Into<field::Expect>, + { + NewSpan { + fields: fields.into(), + ..self + } + } +} + +impl fmt::Display for NewSpan { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + write!(f, "a new span{}", self.span.metadata)?; + if !self.fields.is_empty() { + write!(f, " with {}", self.fields)?; + } + Ok(()) + } +} diff --git a/third_party/rust/tracing/tests/support/subscriber.rs b/third_party/rust/tracing/tests/support/subscriber.rs new file mode 100644 index 0000000000..83f1139849 --- /dev/null +++ b/third_party/rust/tracing/tests/support/subscriber.rs @@ -0,0 +1,569 @@ +#![allow(missing_docs)] +use super::{ + event::MockEvent, + field as mock_field, + span::{MockSpan, NewSpan}, + Parent, +}; +use std::{ + collections::{HashMap, VecDeque}, + fmt, + sync::{ + atomic::{AtomicUsize, Ordering}, + Arc, Mutex, + }, + thread, +}; +use tracing::{ + level_filters::LevelFilter, + span::{self, Attributes, Id}, + subscriber::Interest, + Event, Metadata, Subscriber, +}; + +#[derive(Debug, Eq, PartialEq)] +enum Expect { + Event(MockEvent), + Enter(MockSpan), + Exit(MockSpan), + CloneSpan(MockSpan), + DropSpan(MockSpan), + Visit(MockSpan, mock_field::Expect), + NewSpan(NewSpan), + Nothing, +} + +struct SpanState { + name: &'static str, + refs: usize, +} + +struct Running<F: Fn(&Metadata<'_>) -> bool> { + spans: Mutex<HashMap<Id, SpanState>>, + expected: Arc<Mutex<VecDeque<Expect>>>, + current: Mutex<Vec<Id>>, + ids: AtomicUsize, + max_level: Option<LevelFilter>, + filter: F, + name: String, +} + +pub struct MockSubscriber<F: Fn(&Metadata<'_>) -> bool> { + expected: VecDeque<Expect>, + max_level: Option<LevelFilter>, + filter: F, + name: String, +} + +pub struct MockHandle(Arc<Mutex<VecDeque<Expect>>>, String); + +pub fn mock() -> MockSubscriber<fn(&Metadata<'_>) -> bool> { + MockSubscriber { + expected: VecDeque::new(), + filter: (|_: &Metadata<'_>| true) as for<'r, 's> fn(&'r Metadata<'s>) -> _, + max_level: None, + name: thread::current() + .name() + .unwrap_or("mock_subscriber") + .to_string(), + } +} + +impl<F> MockSubscriber<F> +where + F: Fn(&Metadata<'_>) -> bool + 'static, +{ + /// Overrides the name printed by the mock subscriber's debugging output. + /// + /// The debugging output is displayed if the test panics, or if the test is + /// run with `--nocapture`. + /// + /// By default, the mock subscriber's name is the name of the test + /// (*technically*, the name of the thread where it was created, which is + /// the name of the test unless tests are run with `--test-threads=1`). + /// When a test has only one mock subscriber, this is sufficient. However, + /// some tests may include multiple subscribers, in order to test + /// interactions between multiple subscribers. In that case, it can be + /// helpful to give each subscriber a separate name to distinguish where the + /// debugging output comes from. + pub fn named(self, name: impl ToString) -> Self { + Self { + name: name.to_string(), + ..self + } + } + + pub fn enter(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::Enter(span)); + self + } + + pub fn event(mut self, event: MockEvent) -> Self { + self.expected.push_back(Expect::Event(event)); + self + } + + pub fn exit(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::Exit(span)); + self + } + + pub fn clone_span(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::CloneSpan(span)); + self + } + + #[allow(deprecated)] + pub fn drop_span(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::DropSpan(span)); + self + } + + pub fn done(mut self) -> Self { + self.expected.push_back(Expect::Nothing); + self + } + + pub fn record<I>(mut self, span: MockSpan, fields: I) -> Self + where + I: Into<mock_field::Expect>, + { + self.expected.push_back(Expect::Visit(span, fields.into())); + self + } + + pub fn new_span<I>(mut self, new_span: I) -> Self + where + I: Into<NewSpan>, + { + self.expected.push_back(Expect::NewSpan(new_span.into())); + self + } + + pub fn with_filter<G>(self, filter: G) -> MockSubscriber<G> + where + G: Fn(&Metadata<'_>) -> bool + 'static, + { + MockSubscriber { + expected: self.expected, + filter, + max_level: self.max_level, + name: self.name, + } + } + + pub fn with_max_level_hint(self, hint: impl Into<LevelFilter>) -> Self { + Self { + max_level: Some(hint.into()), + ..self + } + } + + pub fn run(self) -> impl Subscriber { + let (subscriber, _) = self.run_with_handle(); + subscriber + } + + pub fn run_with_handle(self) -> (impl Subscriber, MockHandle) { + let expected = Arc::new(Mutex::new(self.expected)); + let handle = MockHandle(expected.clone(), self.name.clone()); + let subscriber = Running { + spans: Mutex::new(HashMap::new()), + expected, + current: Mutex::new(Vec::new()), + ids: AtomicUsize::new(1), + filter: self.filter, + max_level: self.max_level, + name: self.name, + }; + (subscriber, handle) + } +} + +impl<F> Subscriber for Running<F> +where + F: Fn(&Metadata<'_>) -> bool + 'static, +{ + fn enabled(&self, meta: &Metadata<'_>) -> bool { + println!("[{}] enabled: {:#?}", self.name, meta); + let enabled = (self.filter)(meta); + println!("[{}] enabled -> {}", self.name, enabled); + enabled + } + + fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest { + println!("[{}] register_callsite: {:#?}", self.name, meta); + if self.enabled(meta) { + Interest::always() + } else { + Interest::never() + } + } + fn max_level_hint(&self) -> Option<LevelFilter> { + self.max_level + } + + fn record(&self, id: &Id, values: &span::Record<'_>) { + let spans = self.spans.lock().unwrap(); + let mut expected = self.expected.lock().unwrap(); + let span = spans + .get(id) + .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id)); + println!( + "[{}] record: {}; id={:?}; values={:?};", + self.name, span.name, id, values + ); + let was_expected = if let Some(Expect::Visit(_, _)) = expected.front() { + true + } else { + false + }; + if was_expected { + if let Expect::Visit(expected_span, mut expected_values) = expected.pop_front().unwrap() + { + if let Some(name) = expected_span.name() { + assert_eq!(name, span.name); + } + let mut checker = expected_values.checker(format!("span {}: ", span.name)); + values.record(&mut checker); + checker.finish(); + } + } + } + + fn event(&self, event: &Event<'_>) { + let name = event.metadata().name(); + println!("[{}] event: {};", self.name, name); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Event(mut expected)) => { + let spans = self.spans.lock().unwrap(); + expected.check(event); + match expected.parent { + Some(Parent::ExplicitRoot) => { + assert!( + event.is_root(), + "[{}] expected {:?} to be an explicit root event", + self.name, + name + ); + } + Some(Parent::Explicit(expected_parent)) => { + let actual_parent = + event.parent().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!( + Some(expected_parent.as_ref()), + actual_parent, + "[{}] expected {:?} to have explicit parent {:?}", + self.name, + name, + expected_parent, + ); + } + Some(Parent::ContextualRoot) => { + assert!( + event.is_contextual(), + "[{}] expected {:?} to have a contextual parent", + self.name, + name + ); + assert!( + self.current.lock().unwrap().last().is_none(), + "[{}] expected {:?} to be a root, but we were inside a span", + self.name, + name + ); + } + Some(Parent::Contextual(expected_parent)) => { + assert!( + event.is_contextual(), + "[{}] expected {:?} to have a contextual parent", + self.name, + name + ); + let stack = self.current.lock().unwrap(); + let actual_parent = + stack.last().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!( + Some(expected_parent.as_ref()), + actual_parent, + "[{}] expected {:?} to have contextual parent {:?}", + self.name, + name, + expected_parent, + ); + } + None => {} + } + } + Some(ex) => ex.bad( + &self.name, + format_args!("[{}] observed event {:?}", self.name, event), + ), + } + } + + fn record_follows_from(&self, _span: &Id, _follows: &Id) { + // TODO: it should be possible to expect spans to follow from other spans + } + + fn new_span(&self, span: &Attributes<'_>) -> Id { + let meta = span.metadata(); + let id = self.ids.fetch_add(1, Ordering::SeqCst); + let id = Id::from_u64(id as u64); + println!( + "[{}] new_span: name={:?}; target={:?}; id={:?};", + self.name, + meta.name(), + meta.target(), + id + ); + let mut expected = self.expected.lock().unwrap(); + let was_expected = match expected.front() { + Some(Expect::NewSpan(_)) => true, + _ => false, + }; + let mut spans = self.spans.lock().unwrap(); + if was_expected { + if let Expect::NewSpan(mut expected) = expected.pop_front().unwrap() { + let name = meta.name(); + expected + .span + .metadata + .check(meta, format_args!("span `{}`", name)); + let mut checker = expected.fields.checker(name.to_string()); + span.record(&mut checker); + checker.finish(); + match expected.parent { + Some(Parent::ExplicitRoot) => { + assert!( + span.is_root(), + "[{}] expected {:?} to be an explicit root span", + self.name, + name + ); + } + Some(Parent::Explicit(expected_parent)) => { + let actual_parent = + span.parent().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!( + Some(expected_parent.as_ref()), + actual_parent, + "[{}] expected {:?} to have explicit parent {:?}", + self.name, + name, + expected_parent, + ); + } + Some(Parent::ContextualRoot) => { + assert!( + span.is_contextual(), + "[{}] expected {:?} to have a contextual parent", + self.name, + name + ); + assert!( + self.current.lock().unwrap().last().is_none(), + "[{}] expected {:?} to be a root, but we were inside a span", + self.name, + name + ); + } + Some(Parent::Contextual(expected_parent)) => { + assert!( + span.is_contextual(), + "[{}] expected {:?} to have a contextual parent", + self.name, + name + ); + let stack = self.current.lock().unwrap(); + let actual_parent = + stack.last().and_then(|id| spans.get(id)).map(|s| s.name); + assert_eq!( + Some(expected_parent.as_ref()), + actual_parent, + "[{}] expected {:?} to have contextual parent {:?}", + self.name, + name, + expected_parent, + ); + } + None => {} + } + } + } + spans.insert( + id.clone(), + SpanState { + name: meta.name(), + refs: 1, + }, + ); + id + } + + fn enter(&self, id: &Id) { + let spans = self.spans.lock().unwrap(); + if let Some(span) = spans.get(id) { + println!("[{}] enter: {}; id={:?};", self.name, span.name, id); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Enter(ref expected_span)) => { + if let Some(name) = expected_span.name() { + assert_eq!(name, span.name); + } + } + Some(ex) => ex.bad(&self.name, format_args!("entered span {:?}", span.name)), + } + }; + self.current.lock().unwrap().push(id.clone()); + } + + fn exit(&self, id: &Id) { + if std::thread::panicking() { + // `exit()` can be called in `drop` impls, so we must guard against + // double panics. + println!("[{}] exit {:?} while panicking", self.name, id); + return; + } + let spans = self.spans.lock().unwrap(); + let span = spans + .get(id) + .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id)); + println!("[{}] exit: {}; id={:?};", self.name, span.name, id); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Exit(ref expected_span)) => { + if let Some(name) = expected_span.name() { + assert_eq!(name, span.name); + } + let curr = self.current.lock().unwrap().pop(); + assert_eq!( + Some(id), + curr.as_ref(), + "[{}] exited span {:?}, but the current span was {:?}", + self.name, + span.name, + curr.as_ref().and_then(|id| spans.get(id)).map(|s| s.name) + ); + } + Some(ex) => ex.bad(&self.name, format_args!("exited span {:?}", span.name)), + }; + } + + fn clone_span(&self, id: &Id) -> Id { + let name = self.spans.lock().unwrap().get_mut(id).map(|span| { + let name = span.name; + println!( + "[{}] clone_span: {}; id={:?}; refs={:?};", + self.name, name, id, span.refs + ); + span.refs += 1; + name + }); + if name.is_none() { + println!("[{}] clone_span: id={:?};", self.name, id); + } + let mut expected = self.expected.lock().unwrap(); + let was_expected = if let Some(Expect::CloneSpan(ref span)) = expected.front() { + assert_eq!( + name, + span.name(), + "[{}] expected to clone a span named {:?}", + self.name, + span.name() + ); + true + } else { + false + }; + if was_expected { + expected.pop_front(); + } + id.clone() + } + + fn drop_span(&self, id: Id) { + let mut is_event = false; + let name = if let Ok(mut spans) = self.spans.try_lock() { + spans.get_mut(&id).map(|span| { + let name = span.name; + if name.contains("event") { + is_event = true; + } + println!( + "[{}] drop_span: {}; id={:?}; refs={:?};", + self.name, name, id, span.refs + ); + span.refs -= 1; + name + }) + } else { + None + }; + if name.is_none() { + println!("[{}] drop_span: id={:?}", self.name, id); + } + if let Ok(mut expected) = self.expected.try_lock() { + let was_expected = match expected.front() { + Some(Expect::DropSpan(ref span)) => { + // Don't assert if this function was called while panicking, + // as failing the assertion can cause a double panic. + if !::std::thread::panicking() { + assert_eq!(name, span.name()); + } + true + } + Some(Expect::Event(_)) => { + if !::std::thread::panicking() { + assert!(is_event, "[{}] expected an event", self.name); + } + true + } + _ => false, + }; + if was_expected { + expected.pop_front(); + } + } + } +} + +impl MockHandle { + pub fn assert_finished(&self) { + if let Ok(ref expected) = self.0.lock() { + assert!( + !expected.iter().any(|thing| thing != &Expect::Nothing), + "[{}] more notifications expected: {:?}", + self.1, + **expected + ); + } + } +} + +impl Expect { + fn bad<'a>(&self, name: impl AsRef<str>, what: fmt::Arguments<'a>) { + let name = name.as_ref(); + match self { + Expect::Event(e) => panic!("[{}] expected event {}, but {} instead", name, e, what,), + Expect::Enter(e) => panic!("[{}] expected to enter {} but {} instead", name, e, what,), + Expect::Exit(e) => panic!("[{}] expected to exit {} but {} instead", name, e, what,), + Expect::CloneSpan(e) => { + panic!("[{}] expected to clone {} but {} instead", name, e, what,) + } + Expect::DropSpan(e) => { + panic!("[{}] expected to drop {} but {} instead", name, e, what,) + } + Expect::Visit(e, fields) => panic!( + "[{}] expected {} to record {} but {} instead", + name, e, fields, what, + ), + Expect::NewSpan(e) => panic!("[{}] expected {} but {} instead", name, e, what), + Expect::Nothing => panic!( + "[{}] expected nothing else to happen, but {} instead", + name, what, + ), + } + } +} |