First pass at #[trace] macro. #16

davidbarsky · 2018-09-30T22:54:26Z

Attributes, generics, and other stuff seems to be handled mostly correctly. The main thing that's missing is inserting the function's parameters into a span and checking that a type is clone-able.

The relevant part of the cargo expand on the example crate is this:

fn main() {
    tokio_trace::Dispatcher::builder()
        .add_subscriber(SloggishSubscriber::new(2))
        .init();
    let server_span = ::Span::new(
        Some("server"),
        ::std::time::Instant::now(),
        Some(::Span::current()),
        &::Meta {
            target: None,
            level: ::Level::Trace,
            module_path: "example",
            file: "tokio-trace-macros/example/src/main.rs",
            line: 16u32,
            field_names: &["local_port"],
        },
        <[_]>::into_vec(box [Box::new(8888)]),
    );
    server_span.clone().enter(move || {
        suggest_band("Parquet Courts");
    });
}
#[deprecated]
#[warn(missing_docs)]
fn suggest_band(band: &str) -> String {
    ::Span::new(
        Some("suggest_band"),
        ::std::time::Instant::now(),
        Some(::Span::current()),
        &::Meta {
            target: None,
            level: ::Level::Trace,
            module_path: "example",
            file: "tokio-trace-macros/example/src/main.rs",
            line: 22u32,
            field_names: &["traced_function"],
        },
        <[_]>::into_vec(box [Box::new("suggest_band")]),
    )
    .enter(move || {
        {
            {
                let field_values: &[&dyn::Value] = &[&band.to_string()];
                use Subscriber;
                ::Dispatcher::current().observe_event(&::Event {
                    timestamp: ::std::time::Instant::now(),
                    parent: ::Span::current().into(),
                    follows_from: &[],
                    meta: &::Meta {
                        target: None,
                        level: Level::Info,
                        module_path: "example",
                        file: "tokio-trace-macros/example/src/main.rs",
                        line: 26u32,
                        field_names: &["band"],
                    },
                    field_values: &field_values[..],
                    message: ::std::fmt::Arguments::new_v1(
                        &["suggested a band"],
                        &match () {
                            () => [],
                        },
                    ),
                });
            }
        };
        ::fmt::format(::std::fmt::Arguments::new_v1_formatted(
            &["Have you listened to ", "?"],
            &match (&band,) {
                (arg0,) => [::std::fmt::ArgumentV1::new(arg0, ::std::fmt::Display::fmt)],
            },
            &[::std::fmt::rt::v1::Argument {
                position: ::std::fmt::rt::v1::Position::At(0usize),
                format: ::std::fmt::rt::v1::FormatSpec {
                    fill: ' ',
                    align: ::std::fmt::rt::v1::Alignment::Unknown,
                    flags: 0u32,
                    precision: ::std::fmt::rt::v1::Count::Implied,
                    width: ::std::fmt::rt::v1::Count::Implied,
                },
            }],
        ))
    })
}

davidbarsky · 2018-09-30T22:57:45Z

Travis is broken, I'll need to add a feature flag on the proc macro feature on stable/beta.

tokio-trace-macros/tokio-trace-macros/src/lib.rs

davidbarsky · 2018-10-01T20:39:45Z

I removed the feature flag #![feature(proc_macro_diagnostic)] in tokio-trace-macros, but I'm getting an error on stable that looks like:

error[E0658]: attribute procedural macros are experimental (see issue #35896)
  --> tokio-trace-macros/example/src/main.rs:22:1
   |
3  | #[macro_use]
   | ------------ procedural macro imported here
...
22 | #[trace]
   | ^^^^^^^^

This is expected, but I wonder how I can tell Travis to only build anything under tokio-trace-macros under nightly only.

carllerche · 2018-10-04T18:51:00Z

I definitely like this idea 👍 ( haven't reviewed the PR).

davidbarsky · 2018-10-05T15:19:59Z

Thanks! There's still some room to improve this.

…

On Thu, Oct 4, 2018 at 2:51 PM Carl Lerche ***@***.***> wrote: I definitely like this idea 👍 ( haven't reviewed the PR). — You are receiving this because you were assigned. Reply to this email directly, view it on GitHub <#16 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AB-NPiwSDW7G5qTkdY0Xq28QK7se4j9fks5uhliUgaJpZM4XBMqI> .

carllerche · 2018-10-05T15:27:04Z

I'm guessing that this will have the most win w/ async/await.

davidbarsky · 2018-10-05T15:49:44Z

Yeah, totally. It's also nice, imo, for cases where someone wants to try out Tokio Trace in their application's critical path without investing *too* much effort, and getting some useful information.

…

On Fri, Oct 5, 2018 at 11:27 AM Carl Lerche ***@***.***> wrote: I'm guessing that this will have the most win w/ async/await. — You are receiving this because you were assigned. Reply to this email directly, view it on GitHub <#16 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AB-NPvvAQrtrmFAh-2So8gs0tlMsgTM7ks5uh3pIgaJpZM4XBMqI> .

hawkw · 2018-10-25T18:22:52Z

@davidbarsky Since Rust 1.30 was just released, this shouldn't break the build any longer, correct?

davidbarsky · 2018-10-25T18:29:47Z

Yes, that's correct. There just might be some breaking changes that have occurred in Tokio Trace since.

…

On Thu, Oct 25, 2018 at 2:22 PM Eliza Weisman ***@***.***> wrote: @davidbarsky <https://github.com/davidbarsky> Since Rust 1.30 was just released <https://blog.rust-lang.org/2018/10/25/Rust-1.30.0.html>, this shouldn't break the build any longer, correct? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#16 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AB-NPmD_UOrwxW14gAL6COpfGhT2hPssks5uogF8gaJpZM4XBMqI> .

hawkw

Now that Rust 1.30 is stable, I think we can start thinking about what it takes to merge this branch!

The proc-macro itself is looking good. Most of my requested changes have to do with the project structure etc.

tokio-trace-macros/tokio-trace-macros/src/lib.rs

Cargo.toml

tokio-trace-macros/example/Cargo.toml

tokio-trace-macros/example/src/main.rs

hawkw · 2018-10-25T18:39:06Z

@davidbarsky

There just might be some breaking changes that have occurred in Tokio Trace since.

Hmm, actually, I don't think so --- since your macro just farms out to the span! macro internally, I think all the changes that could potentially be breaking should be encapsulated behind that macro.

hawkw · 2018-10-25T18:41:00Z

tokio-trace-macros/tokio-trace-macros/src/lib.rs

+ quote_spanned!(call_site=>
+ #(#attrs) *
+ #vis #constness #unsafety #asyncness #abi fn #ident(#params) #return_type {
+ span!(#ident_str, traced_function = #ident_str).enter(move || {


For future work: it would be really cool if we could pass all the params to the function as fields here as well.

Since some parameters may not be valid span fields, we might consider adding an additional attribute (#[trace_ignore]?) to annotate those fields that should be skipped.

Agreed, yeah. The biggest blocker on passing all the params to into a span field was the T: Clone requirement. Now that's gone, it'll be far easier to implement.

hawkw · 2018-10-25T18:45:50Z

tokio-trace-macros/tokio-trace-macros/src/lib.rs

+
+#[proc_macro_attribute]
+pub fn trace(_args: TokenStream, item: TokenStream) -> TokenStream {
+ let input: ItemFn = parse_macro_input!(item as ItemFn);


Also for potential future work: it would be cool to allow things that aren't functions to be traced. At the very least, it would be nice to detect if we're annotating a future, and instrument it in the "right way" --- by constructing the span once and wrapping the future in a tokio_trace_futures::Instrumented future.

The naïve approach --- just putting the #[trace] macro on the implementation of Future::poll for that future --- wouldn't do the Right Thing; it would instead create a new span that's entered for every individual time that future is polled. This could potentially be a big enough gotcha that I think it's probably worthwhile to special-case this.

We'd probably want to figure out a similar approach for async fns as well...

Also for potential future work: it would be cool to allow things that aren't functions to be traced. At the very least, it would be nice to detect if we're annotating a future, and instrument it in the "right way" --- by constructing the span once and wrapping the future in a tokio_trace_futures::Instrumented future.

The naïve approach --- just putting the #[trace] macro on the implementation of Future::poll for that future --- wouldn't do the Right Thing; it would instead create a new span that's entered for every individual time that future is polled. This could potentially be a big enough gotcha that I think it's probably worthwhile to special-case this.

That's a good point, and I'd need to dig deeper into the Syn docs.

We'd probably want to figure out a similar approach for async fns as well...

It already is! See the #asyncness on line 41? That's all the work we need to do to support async functions, from a macro standpoint.

We'd probably want to figure out a similar approach for async fns as well...

It already is! See the #asyncness on line 41? That's all the work we need to do to support async functions, from a macro standpoint.

Yes, but I think we'd want to make sure we do the right thing for async fns --- namely, I think we'd want to make sure that the future created by that async fn is instrumented by that span, rather than just the initial call to the async fn that returns the future. This may require some testing.

hawkw · 2018-10-29T20:27:31Z

@davidbarsky looks like all the blocking changes I requested were resolved, thanks!

Mind opening new issues for the follow-up work (#16 (comment) and #16 (comment))?

davidbarsky · 2018-10-29T20:28:23Z

Sure! Gimme about an hour.

…

On Mon, Oct 29, 2018 at 4:27 PM Eliza Weisman ***@***.***> wrote: @davidbarsky <https://github.com/davidbarsky> looks like all the blocking changes I requested were resolved, thanks! Mind opening new issues for the follow-up work (#16 (comment) <#16 (comment)> and #16 (comment) <#16 (comment)> )? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#16 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AB-NPtwdloy69bPOnAATjhRSR192enRHks5up2TCgaJpZM4XBMqI> .

davidbarsky · 2018-10-29T22:10:21Z

Created #53 and #54.

hawkw · 2018-10-29T22:12:15Z

@davidbarsky thanks for creating the followup issues! I believe merging this PR should close #9, since the additional work is now tracked by those tickets.

First pass at #[trace] macro.

6a1c91e

davidbarsky assigned davidbarsky and hawkw Sep 30, 2018

davidbarsky requested a review from hawkw September 30, 2018 22:54

hawkw approved these changes Sep 30, 2018

View reviewed changes

tokio-trace-macros/tokio-trace-macros/src/lib.rs Outdated Show resolved Hide resolved

hawkw suggested changes Oct 25, 2018

View reviewed changes

tokio-trace-macros/tokio-trace-macros/src/lib.rs Outdated Show resolved Hide resolved

Cargo.toml Outdated Show resolved Hide resolved

tokio-trace-macros/example/Cargo.toml Outdated Show resolved Hide resolved

tokio-trace-macros/example/src/main.rs Outdated Show resolved Hide resolved

hawkw reviewed Oct 25, 2018

View reviewed changes

David Barsky added 5 commits October 25, 2018 20:59

Remove warnings, allow building on stable.

2130212

Merge branch 'master' into trace-proc-macro

52309d4

Got macros to compile on stable, simplified examples.

16914ac

Reorganized proc macros crates to be more idiomatic.

2233d2f

Ran cargo fmt to avoid travis build failures.

5ac8e18

hawkw approved these changes Oct 29, 2018

View reviewed changes

davidbarsky merged commit ce6b7c3 into master Oct 29, 2018

davidbarsky deleted the trace-proc-macro branch October 29, 2018 20:29

This was referenced Oct 29, 2018

Pass paramaters into a new span in #[trace] macro. #53

Open

Ensure #[trace] macro works correctly for async functions. #54

Open

hawkw mentioned this pull request Oct 29, 2018

Ability to derive spans for functions #9

Closed

This was referenced Feb 8, 2019

Pass paramaters into a new span in #[trace] macro tokio-rs/tracing#5

Closed

Ensure #[trace] macro works correctly for async functions. tokio-rs/tracing#6

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

First pass at #[trace] macro. #16

First pass at #[trace] macro. #16

davidbarsky commented Sep 30, 2018 •

edited

Loading

davidbarsky commented Sep 30, 2018

davidbarsky commented Oct 1, 2018 •

edited

Loading

carllerche commented Oct 4, 2018

davidbarsky commented Oct 5, 2018 via email

carllerche commented Oct 5, 2018

davidbarsky commented Oct 5, 2018 via email

hawkw commented Oct 25, 2018

davidbarsky commented Oct 25, 2018 via email

hawkw left a comment

hawkw commented Oct 25, 2018

hawkw Oct 25, 2018

davidbarsky Oct 25, 2018

hawkw Oct 25, 2018

davidbarsky Oct 25, 2018

hawkw Oct 25, 2018

hawkw commented Oct 29, 2018

davidbarsky commented Oct 29, 2018 via email

davidbarsky commented Oct 29, 2018

hawkw commented Oct 29, 2018

First pass at #[trace] macro. #16

First pass at #[trace] macro. #16

Conversation

davidbarsky commented Sep 30, 2018 • edited Loading

davidbarsky commented Sep 30, 2018

davidbarsky commented Oct 1, 2018 • edited Loading

carllerche commented Oct 4, 2018

davidbarsky commented Oct 5, 2018 via email

carllerche commented Oct 5, 2018

davidbarsky commented Oct 5, 2018 via email

hawkw commented Oct 25, 2018

davidbarsky commented Oct 25, 2018 via email

hawkw left a comment

Choose a reason for hiding this comment

hawkw commented Oct 25, 2018

hawkw Oct 25, 2018

Choose a reason for hiding this comment

davidbarsky Oct 25, 2018

Choose a reason for hiding this comment

hawkw Oct 25, 2018

Choose a reason for hiding this comment

davidbarsky Oct 25, 2018

Choose a reason for hiding this comment

hawkw Oct 25, 2018

Choose a reason for hiding this comment

hawkw commented Oct 29, 2018

davidbarsky commented Oct 29, 2018 via email

davidbarsky commented Oct 29, 2018

hawkw commented Oct 29, 2018

davidbarsky commented Sep 30, 2018 •

edited

Loading

davidbarsky commented Oct 1, 2018 •

edited

Loading