tikv / minitrace-rust Goto Github PK

Related to issue #81
In the course of issue #112

I had a look at the proc-macro crate, with a view to fixing #112. Not being a proc-macro guru I'm a little intimidated/lost by the current structure.
The proposal is to, in the first instance restructure the code into the following pipeline:

The file layout would be:

src
|-- lib.rs
`-- trace
    |-- analyze.rs
    |-- codegen.rs
    |-- lower.rs
    `-- parse.rs

New proc-macro-attributes, proc-macro-functions would be expected to follow the same convention.

The idea would be to write tests as the code is migrated.

A WIP example is in the issue-1 branch of tracing-attributes-http:

https://github.com/taqtiqa-mark/tracing-attributes-http/tree/issue-1/src

Thoughts?

With latest intellij-rust (14 Feb 2022), the IDE doesn't work well for such functions:

The current README provides a benchmark chart produced by criterion. It works great, for knowing how precise the benchmark result is, but it does not do a good job of proving how good minitrace is.

A helpful chart may be comparing how is the performance of existing tracing libraries in the wild, when generating and collecting different number of spans (as there is a batch mechanism in minitrace).

This feature is implemented in PR #127.should not be attempted until the new pipeline refactoring lands, and related bugs are squashed:

• implemented in PR #127

At that point we should try to make the proc-macro parsing errors more recoverable. From the user perspective it should mean they get prompted about relevant functions. In our case a prompt to use record(..) on the variable name passed in via the recorder=spanr attribute option.

An illustration of what this looks like is here (Tokio specific).

Relevant resources:

• IDEs and proc-macros: "fix" the proc-macro ecosystem
• Prior art implementation: Tokio PR tokio-rs/tokio/pull/4162
  • Particularly darksonn's implementation suggestion
• Rust Analyzer discussion rust-lang/rust-analyzer/issues/11014

Can follow log! tracing levels, and use a cache friendly static location.

Currently this library lacks basic description about what is the "tracing" we would like to solve. It is not friendly for wild people that accidentally discovered this library, for example, from TiKV and its friend repositories.

A nice example would be https://tracing-rs.netlify.app/tracing/ where core concepts are explained in detail.

This blocking on eupn/macrotest/issues/74

I've reached the Model stage of the pipeline is #113. This involves setting up defaults....

Current macro implementation has some confusing, to my mind, defaults. Described here.

Proposal is for these defaults (macro impl details follow, but you get the idea):

• enter_on_poll:
  • None (sync)
  • Some(true) (async)
• span-scope:
  • Local (sync, is current default),
  • Local (async) & this follows from enter-on-poll default (above) being true (correct?)

If enter_on_poll=false then convention is for default span-scope to be Threads.

My expectation is that if you just want to add #[trace], it is likely you're new or (more likely) an occasional user needing to debug something now - you're already having a lousy day, and we shouldn't force you to dive into docs to find out what you need to do to get the help you need... in these cases enter-on-poll is likely to be what you want when debugging? Also if you're new to async we don't hide the effect of polling.

Regular users will already know what they want.

I believe these defaults are consistent with the rust-lang goal of 'empowering everyone' here it is new/occasional users. Also for these users their productivity is enhanced - at a cost to regular users who want a different default. However thos regular/power users are still empowered to do what they want, just with some additional cost of having to enter their desired parameters.

Thoughts?

This blocking on eupn/macrotest/issues/74

We can have a list of minitrace users to improve the confidence.

Hi 👋

I am trying to use the trace_async macro to add span tracing on a tonic Grpc server using async functions. I am getting an error of error[E0599]: no method named `in_new_span` found for struct `Pin<Box<impl futures_util::Future>>` in the current scope when I try applying the trace_async macro to one of these async functions.

It appears that maybe in_new_span was renamed to in_local_span in this pr, but the usage on line 105 of crates/minitrace-macro/src/lib.rs was missed in the refactoring?

I am new to Rust, so I don't know if there are any implications for fixing this beyond just changing the name to in_local_span, but I would be happy to help if I can.

We can have a CI to ensure that everything works in ARM.

Before starting a LocalSpan, a scope of parent span should be set using Span::set_local_parent(). Use LocalSpan::enter_with_local_parent() to start a LocalSpan, and then, it will become the new local parent.

If no local parent is set, the enter_with_local_parent() will do nothing.

However, the asynronous example does not invoke Span::set_local_parent(), and yet it works i.e. does not 'do nothing'.

Currently the #[trace] attribute is a mixture of:

1. optional, required or prohibited arguments
2. named/keyword and positional arguments

This makes the attribute logic brittle and more difficult to extend than it needs to be. Specifically, the trace name is a positional argument which is both required and optional:

1. from the attribute logic PoV it is required
2. from the user PoV it is optional

Other arguments can be prohibited or required from the attribute logic PoV, e.g. enter_on_poll is prohibited for non-async functions, but required for async functions.

We can't do anything about the required/prohibited/optional properties - these arise naturally from the domain.

We can simplify required/prohibited/optional parsing logic by not complicating things with positional and named/keyword parameter categories.
That is, by removing the use of a positional arguments.

Specifically, in the course of issue #113, landing as PR #127, the following supported syntax has simplified matters by eliminating the need for a validation stage, leaving only a parse stage:

1. #[trace] fn f(){} shorthand for #[trace(name='f')] fn f(){}
2. #[trace(enter_on_poll=true)] async fn f(){} shorthand for #[trace(enter_on_poll=true,name='f')] async fn f(){} . Note: Here order is immaterial.
3. #[trace(name='a')] fn f(){}

The existing mixture of named and positional arguments would no longer be accepted:

1. #[trace] fn f(){} shorthand for #[trace('f')] fn f(){}
2. #[trace(enter_on_poll=true)] async fn f(){} shorthand for #[trace(f,enter_on_poll=true)] async fn f(){} . Note: Here order is material.
3. #[trace('a')] fn f(){}

This would improve the readability of code.
This would deviate from the tracing crate convention, depending on your PoV this is a positive or negative.

Once there is a comprehensive test suite in place and all bugs are eliminated - perhaps then we could consider adding subtle corner cases to the parsing logic by supporting a mixture of positional and named/keyword arguments?

Thoughts?

minitrace::Span, minitrace::local and minitrace_datadog lacks documentation so far. Although the API should be intuitive enough, I hope, having a fruitful document will be better.

This is useful in the context of generating spans with fields that get populated in the course of the code path that is within the span.

I'm not yet fully familiar with minitrace, so this may not be the performant way to achieve this.

Additional context:
I'd like to reach a point where tracing is a compile-time plugin with zero performance overhead at runtime when it is disabled.
Not sure if that is a minitrace objective? e.g a runtime plugin model is an alternative

In general I don't, yet, believe there is use for Minitrace counterparts to the Logging and Tracing crates features related to levels debug, warn, error and info.

I believe users are better served by leaving levels to the application author to setup via cfg/cfg_attr and Cargo features - supported by some documentation/guidance/template.

That said, I do think there is utility in Minitrace having the features (named for consistency with Logging and Tracing crates):

• max_level_off
• release_max_level_off

These features would control the value of some constant. The proc-macro-attribute #[trace(...)]checks this constant value before constructing a span. By default, span creation is enabled.

This is post issue #113 landing.

Embedded device use cases will likely have trace requirements that Minitrace could support.

One of several steps for this to be realized is to support the embedded async runtime Embassy.

Potentially significant changes to the integration test harness/setup may be required.
Hence, I'm flagging this as something to add only once the macro refactor in #113 has landed.

• Identify PoC test case: minitrace-tests/src/build/defaults/no-be-no-drop-local.rs. this test case is already broken in the existing implementation, issue #126. Hence breaking it further by having it be the PoC doesn't add additional noise.
• Add Qemu to test environment
• Add async runtime Embassy to [features] for integration tests (minitest-tests crate): This has landed as part of #113 via PR #127. This was done to ensure we didn't set up the test configuration in a way that makes adding embassy more difficult than it needs to be.
• Alter main in integration tests, i.e. now have three cases for execution of async functions.
• Introduce test pro-macro #[trace_test(...)] or trace_test!(...) to setup testing boiler plate code.

References:

• https://github.com/embassy-rs/embassy

There are some typical usages of a tracing library. One may be interested in the following examples (comments are welcome!):

• Basic (multiple function spans) - an implicit style can be involed.
• Macro shortcut - use macros to make life easier.
• Async - We are in year 2022 now. Async is the new standard.
• Send spans across threads - This is less common compared to async in year 2022.
• Other Advanced Usages

Hi, I've read your blog at https://en.pingcap.com/blog/how-we-trace-a-kv-database-with-less-than-5-percent-performance-impact . It says x86 CPU TSC was used in this crate. How about other CPUs? Particularly, do you support ARM CPUs? I don't know if I missed it somewhere. Thanks.

#[minitrace::trace("a", enter_on_poll = true)]
async fn a(mut b: String) {
    c(&mut b)
}

fn c(d: &mut String) {
    d;
}

gives this error, which is resolved per this comment:

173 | async fn a(mut b: String) {
    |                - help: consider changing this to be mutable: `mut b`
174 |     c(&mut b)
    |       ^^^^^^ cannot borrow as mutable

error[E0596]: cannot borrow `client` as mutable, as it is not declared as mutable

Remove the trace macro and the error goes away.

For anyone caught out, until a fix lands, the workaround should have no performance impact (should be optimized by the compiler):

async fn a( b: String) {
   let mut b = b;
    c(&mut b)
}

Note the synchronous version appears to survive intact:

#[minitrace::trace("a")]
fn a(mut b: String) {
    c(&mut b)
}

fn c(d: &mut String) {
    d;
}

Test cases related to issue #81.

I can't find clear documentation or examples showing the following Tracing functionality is possible in minitrace.

Specifically, in Tracing the tracing::Span::current() involves a thread local lookup, so you only want to do this once for all the record(...) actions within the function. Hence, you end up with something like the following:

fn span_setup(&span) {
    span.as_ref().unwrap()
}
fn mine() {
            let span: Option<_>;
            if cfg!(feature = "traceable") {
                span = Some(tracing::Span::current());
            } else {
                span = None;
            }
       //
       // Other coded logic here
       //
        #[cfg(feature = "traceable")]
        {
            let s = span_setup(&span);
            s.record(
                "http.status_code",
                &format!("{:?}", msg.head.subject).as_str(),
            );
            ...
        }
        // other coded logic
        // other `let s = span_setup(&span); s.record; ....` actions
}

In case it helps anyone else coming down this path...

As best I can tell, the minitrace workaround for not having minitrace::Span::current() is to use Cargo features and this function signature "trick" to pass the last parent span around.

This workaround is required, as best I know, when:

• you want to record within the function
• you want to spawn a thread and trace it under the span where it was spawned

The feature of this workaround is that it becomes redundant to use the #[trace(...)] attribute, because we have to create a child of the parent span that is passed in via the 'trick'

fn d(
    va: std::string::String,
    #[cfg(feature = "traceable")] span: &minitrace::Span,
) 
{
....
}

fn c(
    va: std::string::String,
    #[cfg(feature = "traceable")] span: &minitrace::Span,
) { 
    #[cfg(feature = "traceable")]
    let span = Span::enter_with_parent("A child span", span);

    #[cfg(feature = "debug")]
    let d = d(a,b, &span)

    #[cfg(not(feature = traceable))]
    let d = d(a,b)
    //
    // One could use if cfg!(...) { ... } else { ... }
    // However, that would leave a run-time footprint.
    ... 
}

Where the Cargo features in your crate are:

...

[features]
traceable = [
  "minitrace",
  "minitrace-jaeger",
  "rand"
]
trace = [
  "traceable",
  "debug",
  "error",
  "warn",
  "info",
]
debug = [
  "traceable",
  "error",
  "warn",
  "info",
]
error = [
  "traceable",
  "warn",
  "info",
]
warn = [
  "traceable",
  "info",
]
info = ["traceable"]

...

In fact thinking about it some more.... I'm beginning to wonder if this "workaround" is not where the end state might be?

I believe it will come down to the relative 'cost/expense' of mintrace::Span::current() compared to Span::enter_with_parent("A child span", &span);

Hopefully, mintrace::Span::current() is feasible, because the workaround does end up creating a child span just for the record actions.

Hopefully that makes sense?

It would be nice to know the scope and goals of the maintainers, with respect to compatibility with the Logging/Tracing crate ecosystems.

My preference is to place compatibility as a secondary goal, with the requirement that any compatibility does not adversely impact performance.

Specifically, here I'll address the provision of macro functions such a debug!(...), warn!(...), etc.

My 2c:
The minitrace overhead is sufficiently low that, if users find it useful to have:

fn mine() {
    ...
    server.start();
    debug!("server instance started")
    ...
}

They could be encouraged to add the #[trace] attribute to the start function. In cases where start is defined in a 3rd-party crate, I'd advocate guiding user to adopt a "new-function" idiom/pattern that is a counterpart to the "new-type" pattern.

Where by we could say something like: Tracing your usage of third-party crates using a "new-function" idiom/pattern, gives compile time guarantees that the function start/entry and end/exit times are visible. The previous example would become:

fn mine(){
    ...
    start(server);
    ...
}

#[trace("server-start")]
fn start(server: Server){
    server.start;
}

This feature request arose in the course of iterating on an integration test for the proc-macro-attribute #[trace(...)].

use minitrace::trace;
use regex::Regex;
use test_utilities::*;

#[trace("test-span")]
fn f(a: u32) -> u32 {
    a
}

fn main() {
    let (root, collector) = minitrace::Span::root("root");
    {
        root.set_local_parent();
        f(1);
    }
    drop(root);
    let records: Vec<minitrace::collector::SpanRecord> =
        futures::executor::block_on(collector.collect());
    let expected = r#"[ ... ]"#;
    let pre = format!("{records:#?}");
    let re1 = Regex::new(r"begin_unix_time_ns: \d+,").unwrap();
    let re2 = 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();
    assert_eq_text!(expected, &actual);
}

The black-box feature requires nightly.

Requirements:

• The macro should report the nightly requirement in any error messages related to black-box=true.
• The default is black-box=false

Thank you for your effort in making minitrace. And for making it open source.

Is batch uploading to the Jaeger instance possible?

AFAICT all spans are held in memory and then a bulk upload in one-shot is done.
Is that understanding correct?

If so is there any guard-rail for the amount of memory that can be used

Legacy minitrace-macro code converts

fn f() {}

into

fn f<>() {
    let __guard = minitrace::local::LocalSpan::enter_with_local_parent("f");
    {}
}

There are two issues:

1. The __guard should be inside the block expression - correct?
2. The superfluous <>

This arose in the course of writing unit tests for issue #113

We should document whether or not we support the valuable crate. The tracing crate has announced experimental support

Use case:
This allows users to record both user-defined types, and standard library collections such as Vec and HashMap, as structured data attached to tracing spans.

Case For

1. We mimic the tracing crate - its familiar for tracing users.
2. It is convenient.

Case Against

1. It's a special-purpose use case, e.g. debugging, we can likely better support more simply.
2. We should discourage pushing complex user-defined types, and standard library collections to the tracing UI as a general practice - moving such volumes of data around the network will cripple your app performance - see 1.
3. As we mimic tracing crate behavior we can expect to approach tracing "like" performance.
4. It's yet another crate to build.

One Alternative

Better, in my mind, is to stick with a simple record!(span, "key", "value") API.
For more complex use cases, the documents should encourage users to employ the standard format!(). Specifically, for example: record!(span, "key", format!("{:#?}", udt)). For more complex user defined types and data they have the ability to implement Display and/or Debug traits. The Debug trait will likely already exist in most development stories. In performance monitoring stories there are strong incentives to keep-it-simple, and here the Display trait can be repurposed to support that use case.

We should document whether or not "Object-safe value inspection, used to pass un-typed structured data across trait-object boundaries." is within the scope of Minitrace, or not.
I think not.

Thoughts?

In particular, my focus (head-space), is occupied by the #[trace] attribute... there may be Minitrace implementation details that mean it is more performant to use the valuable crate when recording and passing these data to Jaeger, datadog etc.

I'm working on the #[trace] documentation for users.

From a (newish) user PoV: #[trace] is an attribute.

From a user perspective, especially users new to Rust, it adds complexity to be simultaneously encountering concepts of macros, proc-macros, attributes and proc-macro-attributes.

The use of proc-macros is an implementation detail that should not surface in the user documentation.

Renaming minitrace-macros to minitrace-attributes means the user docs can describe this attribute without having the usage instructions referring to minitrace-macros.

Another advantage is this frees minitrace-macros to hold macros, where the implementation could use macro-rules or pro-macros.
While I am opposed to replicating the log and tracing crate macros debug!(...), info!(...), etc. I'm beginning to think that there may be a use for record!(span, "key", "value") rather than span.record("key","value").
If that turns out to be the case it is conceivable users may want one of attributes or macros but not the other.

Timeline Tracing is a word describing a TiKV planned feature. However, it is not something standard and easy to understood by community users.

Once proc-macro-attribute #[trace(...)] has test coverage and documentation covering the relevant code, it may be possible to simplify the logic within minitrace-macro/lib: transform_sig(...). Specifically, by eliminating these lines, (per this observation in PR #119):

minitrace = 0.4.0
monoio = 0.0.4

collector.collect().await does not return

As a standard convention, the git commit that is published to the crates.io should be git-tagged.

When viewing https://github.com/tikv/minitrace-rust/tree/master/minitrace user will get confused, as it seems to have the same content as the https://github.com/tikv/minitrace-rust but the image is broken.

Maybe referring to how typical workspace projects do may help.

We can add more tracing libraries to the bench suite, especially for those specifically designed for the OpenTracing and OpenTelemetry.

As we care performance a lot, it may be necessary to run benchmarks for each PR submission.

For example, a typical user of minitrace -- TiKV needs ARM support.

More optimized?

Another use case to take into account while the model phase of #113 is taking shape.....

This is also related to the #134 use case, but not limited to:

• aiding a new/infrequent user quickly get useful data to assist with debugging.
• 'tracing' the LHS of the expression where the function is in a sealed trait or 3rd-party crate.

The following should be possible (initially sync only):

#[trace(variables=[p, n]]
fn factorial(mut n: u64) -> u64 {
    let mut p = 1;
    while n > 1 {
        p *= n;
        n -= 1;
    }
    p
}

The idea would be to have this become (better suggestions welcome):

fn factorial(mut n: u64) -> u64 {
    let _g = LocalSpan::enter_with_local_parent();
    let mut p;
    {
            let _mt = LocalSpan::enter_with_local_parent();
            p = 1;
    }
    while n > 1 {
        {
            let _mt = LocalSpan::enter_with_local_parent();
            p *= n;
        }
        {
            let _mt = LocalSpan::enter_with_local_parent();
            n -= 1;
        }
    }
    p
}

Producing SpanRecords for:

• p = 1
• p = 8
• n = 7
• p = 56
• n = 6

These integration tests are landing in PR #123. Currently a missing block expression silently compiles and runs. yields different pass/fail behavior in the async/sync cases.

cargo test spans -- --nocapture &>log.txt

The documentation is silent (issue #125 ) so it is not clear what is to be expected. considered broken behavior.

I'm guessing the async failure shown here is "wrong", but the silent omission of spans that have been configured also seems wrong, so I'm not sure, maybe this case span output should be considered correct, and the expected value is wrong....

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
#[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<minitrace::collector::SpanRecord> = 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);
}

generates this failure:

�[0mtest �[0m�[1mtests/spans/no-be-local-async.rs�[0m ... �[0m�[1m�[31merror
�[0m�[31mTest case failed at runtime.
�[0m
�[0m�[1m�[31mSTDERR:
�[0m�[31m┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈
�[0m�[31mLeft:
�[0m�[31m[
�[0m�[31m    SpanRecord {
�[0m�[31m        id: 1,
�[0m�[31m        parent_id: 0,
�[0m�[31m        begin_unix_time_ns: \d+,
�[0m�[31m        duration_ns: \d+,
�[0m�[31m        event: "root",
�[0m�[31m        properties: [],
�[0m�[31m    },
�[0m�[31m]
�[0m�[31m
�[0m�[31mRight:
�[0m�[31m[
�[0m�[31m    SpanRecord {
�[0m�[31m        id: 1,
�[0m�[31m        parent_id: 0,
�[0m�[31m        begin_unix_time_ns: \d+,
�[0m�[31m        duration_ns: \d+,
�[0m�[31m        event: "root",
�[0m�[31m        properties: [],
�[0m�[31m    },
�[0m�[31m    SpanRecord {
�[0m�[31m        id: 2,
�[0m�[31m        parent_id: 1,
�[0m�[31m        begin_unix_time_ns: \d+,
�[0m�[31m        duration_ns: \d+,
�[0m�[31m        event: "a-span",
�[0m�[31m        properties: [],
�[0m�[31m    },
�[0m�[31m]
�[0m�[31m
�[0m�[31mDiff:
�[0m�[31m[
�[0m�[31m    SpanRecord {
�[0m�[31m        id: 1,
�[0m�[31m        parent_id: 0,
�[0m�[31m        begin_unix_time_ns: \d+,
�[0m�[31m        duration_ns: \d+,
�[0m�[31m        event: "root",
�[0m�[31m        properties: [],
�[0m�[31m    },
�[0m�[31m�[42m    SpanRecord {
�[0m�[31m        id: 2,
�[0m�[31m        parent_id: 1,
�[0m�[31m        begin_unix_time_ns: \d+,
�[0m�[31m        duration_ns: \d+,
�[0m�[31m        event: "a-span",
�[0m�[31m        properties: [],
�[0m�[31m    },
�[0m�[31m�[0m]
�[0m�[31m
�[0m�[31m
�[0m�[31mthread 'main' panicked at 'text differs', /home/hedge/src/minitrace-rust/minitrace-macro/tests/spans/no-be-local-async.rs:33:5
�[0m�[31mnote: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
�[0m�[31m┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈
�[0m

However, this sync version passes:

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
#[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<minitrace::collector::SpanRecord> =
        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);
}

Giving:

test �[0m�[1mtests/spans/no-be-local-sync.rs�[0m ... �[0m�[32mok

I should also note the threads "scope" tests omit the second SpanRecord which is currently considered 'correct', and they are green:

�[0mtest �[0m�[1mtests/spans/no-be-threads-async.rs�[0m ... �[0m�[32mok
�[0mtest �[0m�[1mtests/spans/no-be-threads-sync.rs�[0m ... �[0m�[32mok
```~~

Hopefully I haven't overlooked anything obvious.

This arose in the course of populating integration test suite related to #113.

The following survive untouched:

#[trace]
async fn empty_async() {}

#[trace]
fn empty_sync() {}

Currently, we have different API trace_task and trace_async, misuse them two may cause unnecessary performance cost, maybe we can have a way to lead user to use the right API in compile time, but I have no idea how to achieve it yet.

Only 66.3% now. Hope increasing it up to 85%.

See: https://coveralls.io/builds/45965582/source?filename=minitrace-macro%2Fsrc%2Flib.rs

The documentation is entirely silent on the fact that block expressions are an absolute requirement for setting up spans in addition to the #[trace] attribute.

https://github.com/tikv/minitrace-rust/blob/master/CONTRIBUTING.md points to a dead link.

Due to the fact that the current tracing is based on runtime TLS stacks to decide whether to enable or not. This brings us a clean codebase (no explicit context required) but also a certain mental burden to users, especially with async codes.

How to make lives easier?

My idea is to introduce a new crate feature. When specifying it, if any of the buried points fail to enable at runtime, warning information will be issued (or the program will be panicked).

For #8 as an example, we can easily put trace_async everywhere at first. Turn on check mode. Soon, it will complain to us there is no parent where trace_task is needed.

cc @Renkai

As the integration test suite expands - and as trace matures it will grow (e.g. regression test cases are currently already 4) - the test times will increase.

These best-practice references will help anyone wanting to improve the situation.

References:

• https://www.infinyon.com/blog/2021/04/github-actions-best-practices/

To support this use case: The minitrace-attributes crate is a dependency only in development:

[package]
...
resolver = "2"

[dependencies]
minitrace = {version = "0.5", default-features = false}

[dev-dependencies]
minitrace = {version = "0.5", features = ["attributes"]}

This arose in the course of #113 and PR #127.

Currently, the proc-macro code is the, largely, tokio specific code, per this comment.

In fact, at the time of writing, all tests are carried out using the Tokio runtime.

Ideally, IMO, we'd like to support embedded device developers (issue #131). To do so requires adding another runtime to the test infrastructure.
An incremental step in the test infrastructure in that direction is to add another (non-embedded) runtime.
The only other real alternative to Tokio is async-std.

A less painful route to add async-std to the test suite is to ensure we can always isolate all tokio tests, and ensure they remain green - while other runtime tests evolve in the background without breaking CI.
This means gathering/isolating existing tests under something like crfg_attr/cfg(features = "minitrace-tests/tk")

Ironically, this biases toward some other runtime "naturally" become the default, i.e. when there is no feature guard. Which suggests async-std would, eventually, in the fullness of time, etc., be the default test environment.

I'm not unhappy with this serendipitous outcome, since async-std is explicitly aiming at Rust std lib feel, see here.

That said, there maybe a performance cost to async-std over tokio that others weigh more heavily.

However, we are only talking about the minitrace-tests crate, so there is nothing user impacting in this decision....

Thoughts?

Need to evaluate the defaults in #133 in light of the following behavior - are those defaults the least restrictive? Here we'll need to have the test suite be more comprehensive.

The model phase of #113 is taking shape.

The following two cases should be possible (initially sync only):

Tracing inner functions

#[trace(recurse=all)]
pub fn outer() {
    defined_later();

    fn defined_later() {
        println!("I'm traced too"):
    }
}

Where all setting from the outer trace percolate down. It is the users responsibility to ensure the settings are appropriate for the child functions.

Tracing a module

More tricky, but likely possible, and empowering for novice-users when debugging:

#[trace(recurse=all)]
mod traced {
    fn outer() {
       println!("Look Dad, I'm traced!");
        defined_later();

        pub fn defined_later() {
            println!("I'm traced too");
        }
    }
}

async and entry on poll traces should also be possible, but can be second phase.

A natural extension is to have option settings:

#[trace(recurse=all)]
#[trace(recurse=public)]
#[trace(recurse=private)]

Thoughts?

A compatibility or feature matrix with some famous tracing standard (namely, opentracing and opentelemetry) and library implementations may be very helpful to people who are trying with minitrace.