diff --git a/.github/workflows/coverage.yml b/.github/workflows/coverage.yml index e506fb64..11b8fd40 100644 --- a/.github/workflows/coverage.yml +++ b/.github/workflows/coverage.yml @@ -22,8 +22,6 @@ jobs: RUSTDOCFLAGS: "-Zprofile -Ccodegen-units=1 -Cinline-threshold=0 -Clink-dead-code -Coverflow-checks=off -Cpanic=abort -Zpanic_abort_tests" run: | cargo test --workspace --all-features --no-fail-fast - cargo run --example synchronous - cargo run --example asynchronous cargo run --example get_started - id: coverage uses: actions-rs/grcov@v0.1 diff --git a/minitrace-macro/Cargo.toml b/minitrace-macro/Cargo.toml index b80174c7..8999f863 100644 --- a/minitrace-macro/Cargo.toml +++ b/minitrace-macro/Cargo.toml @@ -22,9 +22,9 @@ proc-macro2 = "1" proc-macro-error = "1" [dev-dependencies] -trybuild = "1" -minitrace = "0.4.0" +futures = "0.3.21" +futures-timer = "3.0.2" +minitrace = { path = "../minitrace" } +test-utilities = { path = "../test-utilities" } tokio = { version = "1", features = ["full"] } - -[patch.crates-io] -minitrace = { path = "../" } \ No newline at end of file +trybuild = "1" diff --git a/minitrace-macro/tests/spans.rs b/minitrace-macro/tests/spans.rs new file mode 100644 index 00000000..daf423c8 --- /dev/null +++ b/minitrace-macro/tests/spans.rs @@ -0,0 +1,5 @@ +#[test] +fn spans() { + let t = trybuild::TestCases::new(); + t.pass("tests/spans/*.rs"); +} diff --git a/minitrace-macro/tests/spans/black-box-false-local-async.rs b/minitrace-macro/tests/spans/black-box-false-local-async.rs new file mode 100644 index 00000000..61ab08ca --- /dev/null +++ b/minitrace-macro/tests/spans/black-box-false-local-async.rs @@ -0,0 +1,41 @@ +use minitrace::trace; +use test_utilities::*; + +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/122 +#[trace("a-span")] +async fn f(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _child_span = root.set_local_parent(); + f(1).await; + } + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "a-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/black-box-false-local-sync.rs b/minitrace-macro/tests/spans/black-box-false-local-sync.rs new file mode 100644 index 00000000..49247547 --- /dev/null +++ b/minitrace-macro/tests/spans/black-box-false-local-sync.rs @@ -0,0 +1,40 @@ +use minitrace::trace; +use test_utilities::*; + +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/122 +#[trace("a-span")] +fn f(a: u32) -> u32 { + a +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _sg1 = root.set_local_parent(); + f(1); + } + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "a-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/black-box-false-threads-async.rs b/minitrace-macro/tests/spans/black-box-false-threads-async.rs new file mode 100644 index 00000000..f6d0e147 --- /dev/null +++ b/minitrace-macro/tests/spans/black-box-false-threads-async.rs @@ -0,0 +1,42 @@ +use minitrace::trace; +use test_utilities::*; + +// Span names passed via `enter_with_parent` override default names. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/122 +#[trace("a-span")] +async fn f(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _child_span = minitrace::Span::enter_with_parent("test-span", &root); + f(1).await; + } + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "test-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/black-box-false-threads-sync.rs b/minitrace-macro/tests/spans/black-box-false-threads-sync.rs new file mode 100644 index 00000000..a2535f86 --- /dev/null +++ b/minitrace-macro/tests/spans/black-box-false-threads-sync.rs @@ -0,0 +1,41 @@ +use minitrace::trace; +use test_utilities::*; + +// Span names passed via `enter_with_parent` override default names. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/122 +#[trace("a-span")] +fn f(a: u32) -> u32 { + a +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _sg1 = minitrace::Span::enter_with_parent("test-span", &root); + f(1); + } + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "test-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/default-name-local-async.rs b/minitrace-macro/tests/spans/default-name-local-async.rs new file mode 100644 index 00000000..9c20034d --- /dev/null +++ b/minitrace-macro/tests/spans/default-name-local-async.rs @@ -0,0 +1,39 @@ +use minitrace::trace; +use test_utilities::*; + +#[trace] +async fn fa(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _g = root.set_local_parent(); + fa(1).await; + } + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "fa", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/default-name-local-sync.rs b/minitrace-macro/tests/spans/default-name-local-sync.rs new file mode 100644 index 00000000..12fcf7d2 --- /dev/null +++ b/minitrace-macro/tests/spans/default-name-local-sync.rs @@ -0,0 +1,38 @@ +use minitrace::trace; +use test_utilities::*; + +#[trace] +fn f(a: u64) { + std::thread::sleep(std::time::Duration::from_nanos(a)); +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _g = root.set_local_parent(); + f(1); + } + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "f", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/default-name-threads-async.rs b/minitrace-macro/tests/spans/default-name-threads-async.rs new file mode 100644 index 00000000..d0094ddc --- /dev/null +++ b/minitrace-macro/tests/spans/default-name-threads-async.rs @@ -0,0 +1,40 @@ +use minitrace::trace; +use test_utilities::*; + +// Span names passed via `enter_with_parent` override default names. +#[trace] +async fn fa(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _child_span = minitrace::Span::enter_with_parent("test-span", &root); + fa(1).await; + } + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "test-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/default-name-threads-sync.rs b/minitrace-macro/tests/spans/default-name-threads-sync.rs new file mode 100644 index 00000000..485fddd6 --- /dev/null +++ b/minitrace-macro/tests/spans/default-name-threads-sync.rs @@ -0,0 +1,39 @@ +use minitrace::trace; +use test_utilities::*; + +// Span names passed via `enter_with_parent` override default names. +#[trace] +fn f(a: u64) { + std::thread::sleep(std::time::Duration::from_nanos(a)); +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + { + let _g = minitrace::Span::enter_with_parent("test-span", &root); + f(1); + } + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "test-span", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/doctest-async.rs b/minitrace-macro/tests/spans/doctest-async.rs new file mode 100644 index 00000000..92404cad --- /dev/null +++ b/minitrace-macro/tests/spans/doctest-async.rs @@ -0,0 +1,47 @@ +use futures::executor::block_on; +use minitrace::prelude::*; +use test_utilities::*; + +// Implement documentation example as an integration test. +// +// Reference: +// - https://github.com/tikv/minitrace-rust/blob/master/minitrace/src/lib.rs#L178-L202 + +#[trace("do_something_async")] +async fn do_something_async(i: u64) { + futures_timer::Delay::new(std::time::Duration::from_millis(i)).await; +} + +fn main() { + let (root, collector) = Span::root("root"); + + { + let _g = root.set_local_parent(); + block_on(do_something_async(100)); + } + + drop(root); + let records: Vec = block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "do_something_async", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); + +} diff --git a/minitrace-macro/tests/spans/doctest-sync.rs b/minitrace-macro/tests/spans/doctest-sync.rs new file mode 100644 index 00000000..89368a20 --- /dev/null +++ b/minitrace-macro/tests/spans/doctest-sync.rs @@ -0,0 +1,46 @@ +use futures::executor::block_on; +use minitrace::prelude::*; +use test_utilities::*; + +// Implement documentation example as an integration test. +// +// Reference: +// - https://github.com/tikv/minitrace-rust/blob/master/minitrace/src/lib.rs#L178-L202 + +#[trace("do_something")] +fn do_something(i: u64) { + std::thread::sleep(std::time::Duration::from_millis(i)); +} + +fn main() { + let (root, collector) = Span::root("root"); + + { + let _g = root.set_local_parent(); + do_something(100); + } + + drop(root); + let records: Vec = block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "do_something", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/example-async.rs b/minitrace-macro/tests/spans/example-async.rs new file mode 100644 index 00000000..de998cb2 --- /dev/null +++ b/minitrace-macro/tests/spans/example-async.rs @@ -0,0 +1,193 @@ +// Copyright 2020 TiKV Project Authors. Licensed under Apache-2.0. + +use futures::executor::block_on; +use minitrace::prelude::*; +use test_utilities::*; + +fn parallel_job() -> Vec> { + let mut v = Vec::with_capacity(4); + for i in 0..4 { + v.push(tokio::spawn( + iter_job(i).in_span(Span::enter_with_local_parent("iter job")), + )); + } + v +} + +async fn iter_job(iter: u64) { + std::thread::sleep(std::time::Duration::from_millis(iter * 10)); + tokio::task::yield_now().await; + other_job().await; +} + +#[trace("other job", enter_on_poll = true)] +async fn other_job() { + for i in 0..20 { + if i == 10 { + tokio::task::yield_now().await; + } + std::thread::sleep(std::time::Duration::from_millis(1)); + } +} + +#[tokio::main] +async fn main() { + let (span, collector) = Span::root("root"); + + let f = async { + let jhs = { + let mut span = LocalSpan::enter_with_local_parent("a span"); + span.add_property(|| ("a property", "a value".to_owned())); + parallel_job() + }; + + other_job().await; + + for jh in jhs { + jh.await.unwrap(); + } + } + .in_span(span); + + tokio::spawn(f).await.unwrap(); + + let records: Vec = block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 65537, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "a span", + properties: [ + ( + "a property", + "a value", + ), + ], + }, + SpanRecord { + id: 65542, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 131073, + parent_id: 65539, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 131074, + parent_id: 65538, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 131075, + parent_id: 65539, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65539, + parent_id: 65537, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "iter job", + properties: [], + }, + SpanRecord { + id: 131076, + parent_id: 65538, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65538, + parent_id: 65537, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "iter job", + properties: [], + }, + SpanRecord { + id: 131077, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65543, + parent_id: 65541, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 131078, + parent_id: 65540, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65544, + parent_id: 65541, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65541, + parent_id: 65537, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "iter job", + properties: [], + }, + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 131079, + parent_id: 65540, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "other job", + properties: [], + }, + SpanRecord { + id: 65540, + parent_id: 65537, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "iter job", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/example-sync.rs b/minitrace-macro/tests/spans/example-sync.rs new file mode 100644 index 00000000..3274a3ce --- /dev/null +++ b/minitrace-macro/tests/spans/example-sync.rs @@ -0,0 +1,220 @@ +// Copyright 2020 TiKV Project Authors. Licensed under Apache-2.0. + +use futures::executor::block_on; +use minitrace::prelude::*; +use test_utilities::*; + +fn func1(i: u64) { + let _guard = LocalSpan::enter_with_local_parent("func1"); + std::thread::sleep(std::time::Duration::from_millis(i)); + func2(i); +} + +#[trace("func2")] +fn func2(i: u64) { + std::thread::sleep(std::time::Duration::from_millis(i)); +} + +fn main() { + let collector = { + let (span, collector) = Span::root("root"); + + let _sg1 = span.set_local_parent(); + let mut sg2 = LocalSpan::enter_with_local_parent("a span"); + sg2.add_property(|| ("a property", "a value".to_owned())); + + for i in 1..=10 { + func1(i); + } + + collector + }; + + let records: Vec = block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, + SpanRecord { + id: 2, + parent_id: 1, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "a span", + properties: [ + ( + "a property", + "a value", + ), + ], + }, + SpanRecord { + id: 3, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 4, + parent_id: 3, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 5, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 6, + parent_id: 5, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 7, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 8, + parent_id: 7, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 9, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 10, + parent_id: 9, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 11, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 12, + parent_id: 11, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 13, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 14, + parent_id: 13, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 15, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 16, + parent_id: 15, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 17, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 18, + parent_id: 17, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 19, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 20, + parent_id: 19, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, + SpanRecord { + id: 21, + parent_id: 2, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func1", + properties: [], + }, + SpanRecord { + id: 22, + parent_id: 21, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "func2", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/no-be-local-async.rs b/minitrace-macro/tests/spans/no-be-local-async.rs new file mode 100644 index 00000000..7f32620e --- /dev/null +++ b/minitrace-macro/tests/spans/no-be-local-async.rs @@ -0,0 +1,35 @@ +use minitrace::trace; +use test_utilities::*; + +// With no block expression the span "a-span" is silently omitted. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/125 +// - https://github.com/tikv/minitrace-rust/issues/126 +#[trace("a-span")] +async fn f(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + //{ + let _child_span = root.set_local_parent(); + f(1).await; + //} + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/no-be-local-sync.rs b/minitrace-macro/tests/spans/no-be-local-sync.rs new file mode 100644 index 00000000..51ee51be --- /dev/null +++ b/minitrace-macro/tests/spans/no-be-local-sync.rs @@ -0,0 +1,34 @@ +use minitrace::trace; +use test_utilities::*; + +// With no block expression the span "a-span" is silently omitted. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/125 +// - https://github.com/tikv/minitrace-rust/issues/126 +#[trace("a-span")] +fn f(a: u32) -> u32 { + a +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + //{ + let _sg1 = root.set_local_parent(); + f(1); + //} + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/no-be-threads-async.rs b/minitrace-macro/tests/spans/no-be-threads-async.rs new file mode 100644 index 00000000..708a9b65 --- /dev/null +++ b/minitrace-macro/tests/spans/no-be-threads-async.rs @@ -0,0 +1,35 @@ +use minitrace::trace; +use test_utilities::*; + +// With no block expression the span "test-span" is silently omitted. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/125 +// - https://github.com/tikv/minitrace-rust/issues/126 +#[trace("a-span")] +async fn f(a: u32) -> u32 { + a +} + +#[tokio::main] +async fn main() { + let (root, collector) = minitrace::Span::root("root"); + //{ + let _child_span = minitrace::Span::enter_with_parent("test-span", &root); + f(1).await; + //} + drop(root); + let records: Vec = futures::executor::block_on(collector.collect()); + + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/spans/no-be-threads-sync.rs b/minitrace-macro/tests/spans/no-be-threads-sync.rs new file mode 100644 index 00000000..23dabb21 --- /dev/null +++ b/minitrace-macro/tests/spans/no-be-threads-sync.rs @@ -0,0 +1,34 @@ +use minitrace::trace; +use test_utilities::*; + +// With no block expression the span "test-span" is silently omitted. +// Reference: +// - https://github.com/tikv/minitrace-rust/issues/125 +// - https://github.com/tikv/minitrace-rust/issues/126 +#[trace("a-span")] +fn f(a: u32) -> u32 { + a +} + +fn main() { + let (root, collector) = minitrace::Span::root("root"); + //{ + let _sg1 = minitrace::Span::enter_with_parent("test-span", &root); + f(1); + //} + drop(root); + let records: Vec = + futures::executor::block_on(collector.collect()); + let expected = r#"[ + SpanRecord { + id: 1, + parent_id: 0, + begin_unix_time_ns: \d+, + duration_ns: \d+, + event: "root", + properties: [], + }, +]"#; + let actual = normalize_spans(records); + assert_eq_text!(expected, &actual); +} diff --git a/minitrace-macro/tests/ui/err/has-expr-argument.stderr b/minitrace-macro/tests/ui/err/has-expr-argument.stderr index ebdf3f52..e3460630 100644 --- a/minitrace-macro/tests/ui/err/has-expr-argument.stderr +++ b/minitrace-macro/tests/ui/err/has-expr-argument.stderr @@ -1,4 +1,4 @@ -error: expected string literal +error: expected `enter_on_poll = ` --> tests/ui/err/has-expr-argument.rs:3:9 | 3 | #[trace(true)] diff --git a/minitrace-macro/tests/ui/err/has-too-many-arguments.stderr b/minitrace-macro/tests/ui/err/has-too-many-arguments.stderr index c3a7cd1a..03364047 100644 --- a/minitrace-macro/tests/ui/err/has-too-many-arguments.stderr +++ b/minitrace-macro/tests/ui/err/has-too-many-arguments.stderr @@ -1,4 +1,4 @@ -error: expected string literal +error: expected `enter_on_poll = ` --> tests/ui/err/has-too-many-arguments.rs:3:9 | 3 | #[trace(a, b)] diff --git a/minitrace-macro/tests/ui/err/name-is-not-an-assignment-expression.stderr b/minitrace-macro/tests/ui/err/name-is-not-an-assignment-expression.stderr index f58ba099..80dad9e9 100644 --- a/minitrace-macro/tests/ui/err/name-is-not-an-assignment-expression.stderr +++ b/minitrace-macro/tests/ui/err/name-is-not-an-assignment-expression.stderr @@ -1,4 +1,4 @@ -error: expected string literal +error: expected `enter_on_poll = ` --> tests/ui/err/name-is-not-an-assignment-expression.rs:3:9 | 3 | #[trace(b)] diff --git a/minitrace-macro/tests/ui/err/trace-interleaved.stderr b/minitrace-macro/tests/ui/err/trace-interleaved.stderr index 587f1c2c..49ce11f0 100644 --- a/minitrace-macro/tests/ui/err/trace-interleaved.stderr +++ b/minitrace-macro/tests/ui/err/trace-interleaved.stderr @@ -1,4 +1,4 @@ -error: expected string literal +error: expected `enter_on_poll = ` --> tests/ui/err/trace-interleaved.rs:4:9 | 4 | #[trace(struct)] diff --git a/minitrace-macro/tests/ui/ok/has-no-arguments.rs b/minitrace-macro/tests/ui/ok/has-no-arguments.rs new file mode 100644 index 00000000..a801bd08 --- /dev/null +++ b/minitrace-macro/tests/ui/ok/has-no-arguments.rs @@ -0,0 +1,10 @@ +use minitrace::trace; + +// This Tracing crate like-syntax +#[allow(unused_braces)] +#[trace] +fn f(a: u32) -> u32 { + a +} + +fn main() {} diff --git a/test-utilities/Cargo.toml b/test-utilities/Cargo.toml new file mode 100644 index 00000000..75567303 --- /dev/null +++ b/test-utilities/Cargo.toml @@ -0,0 +1,15 @@ +[package] +name = "test-utilities" +version = "0.0.0" +description = "Utilities for Minitrace development" +license = "MIT OR Apache-2.0" +edition = "2021" + +[lib] +doctest = false + +# Avoid adding crates, this is widely used in tests. It should compile fast! +[dependencies] +dissimilar = "1.0.2" +minitrace = { path = "../minitrace" } +regex = "1.5.5" diff --git a/test-utilities/src/lib.rs b/test-utilities/src/lib.rs new file mode 100644 index 00000000..71dfebb3 --- /dev/null +++ b/test-utilities/src/lib.rs @@ -0,0 +1,72 @@ +//! Assorted testing utilities. +//! +//! Most notable: +//! +//! * `assert_eq_text!`: Rich text comparison, which outputs a diff then panics. + +pub use dissimilar::diff as __diff; + +/// Asserts two strings are equal, otherwise sends a diff to stderr then panics. +/// +/// The rich diff shows changes from the "original" left string to the "actual" +/// right string. +/// +/// All arguments starting from and including the 3rd one are passed to +/// `eprintln!()` macro in case of text inequality. +/// +/// # Panics +/// +/// The macro will panic in case of text inequality. +/// +/// # License +/// +/// SPDX-License-Identifier: Apache-2.0 OR MIT +/// Copyright 2022 rust-analyzer project authors +/// +#[macro_export] +macro_rules! assert_eq_text { + ($left:expr, $right:expr) => { + assert_eq_text!($left, $right,) + }; + ($left:expr, $right:expr, $($tt:tt)*) => {{ + let left = $left; + let right = $right; + if left != right { + if left.trim() == right.trim() { + std::eprintln!("Left:\n{:?}\n\nRight:\n{:?}\n\nWhitespace difference\n", left, right); + } else { + let diff = $crate::__diff(left, right); + std::eprintln!("Left:\n{}\n\nRight:\n{}\n\nDiff:\n{}\n", left, right, $crate::format_diff(diff)); + } + std::eprintln!($($tt)*); + panic!("text differs"); + } + }}; +} + +pub fn format_diff(chunks: Vec) -> String { + let mut buf = String::new(); + for chunk in chunks { + let formatted = match chunk { + dissimilar::Chunk::Equal(text) => text.into(), + dissimilar::Chunk::Delete(text) => format!("\x1b[41m{}\x1b[0m", text), + dissimilar::Chunk::Insert(text) => format!("\x1b[42m{}\x1b[0m", text), + }; + buf.push_str(&formatted); + } + buf +} + +pub fn normalize_spans(records: R) -> std::string::String +where + S: Sized, + R: AsRef<[S]> + std::fmt::Debug, +{ + let pre = format!("{records:#?}"); + //let pre = records.to_string(); + let re1 = regex::Regex::new(r"begin_unix_time_ns: \d+,").unwrap(); + let re2 = regex::Regex::new(r"duration_ns: \d+,").unwrap(); + let int: std::string::String = re1.replace_all(&pre, r"begin_unix_time_ns: \d+,").into(); + let actual: std::string::String = re2.replace_all(&int, r"duration_ns: \d+,").into(); + actual +}