Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Sign up
Appearance settings

Add tracing support for GraphQL objects, interfaces and subscriptions #972

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
ArsileLuci wants to merge 91 commits into graphql-rust:master
base: master
Choose a base branch
Loading
from ArsileLuci:tracing-support

Conversation

@ArsileLuci
Copy link
Contributor

@ArsileLuci ArsileLuci commented Jul 23, 2021
edited
Loading

Superseeds #720
Part of #953

This PR adds tracing support for GraphQL objects, interfaces and subscriptions.

  • Add #[tracing] attribute that should be used #[graphql_object], #[graphql_interface] attributes and derived GraphQL objects.
  • Add #[instrument] attribute on GraphQL fields, that can be used to tune how each field is traced
  • Impl tests for code related to tracing

Before review:

  • Ensure proper formatting
  • Run all tests
  • Update the CHANGELOG

mickdekkers, fourbytes, mathroc, nitnelave, and rinsuki reacted with heart emoji
mihai-dinculescu and others added 30 commits July 25, 2020 20:57
Copy link
Contributor Author

Copy link
Member

@tyranron tyranron left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci thanks, quite raw and rough at the moment, needs more design polishing and some reconsiderations.

.iter()
.map(|e| format!("{}", e))
.collect::<Vec<_>>()
.join("\n");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci here the allocation is redundant. There are easier and more obvious way to strip the last newline.

@@ -0,0 +1,130 @@
// Macros to instrument future spans.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci why not doc comment?

&document, operation, root_node, variables, context,
);

__juniper_instrument_trace!(f, "execute_validated_query").await
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci seems that shoud be:

__juniper_instrument_trace!(f, "execute_validated_query_async").await

assert_eq!(&to_camel_case("")[..], "");
}

#[cfg(feature = "tracing-futures")]
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci why "tracing-futures"? It will complicate looking for feature-gated stuff. It's better to gate everything under the single "tracing" feature, unless these two are going to be used separately, which is not our case.

ArsileLuci reacted with thumbs up emoji

/// Required to pass sanity tests when `Instrument` already imported.
pub trait InstrumentInternal {
fn __instrument(self, span: Span) -> Instrumented<Self>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci still, seems to be quite redundant.

}
}
});
}) #trace_async;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

and here it will be like

});
#trace_async

pub mod span_container;

#[cfg(feature = "tracing")]
pub mod tracing;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci it's better to move it from util module to crate root and have a straight-forward tracing module.

pub span: Span,

#[cfg(feature = "tracing")]
pub tracing: Option<tracing::Attr>,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci also, as #[tracing] represent a separate attribute, it woud be nice to not embed it here, but rather parse separately and use directly.

Copy link
Contributor Author

@ArsileLuci ArsileLuci Jul 23, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tyranron

parse separately and use directly.

You mean instead of expanding it within #[graphql_object]/#[graphql_interface] etc, we could just expand it separately for each field?

/// Derived GraphQL object marked with `trace = "complex"`.
#[derive(GraphQLObject)]
#[graphql(trace = "complex")]
pub struct DerivedComplex {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci I think we can use here #[tracing(complex)] too.

Also, let's check whether we can do that for #[graphql_object] macro, by looking up this attribute on a definition, parsing it and removing it. If not, it would be better to keep the similar to other cases format:

#[graphql_object(tracing(complex))]

This should also simplify the parsing, as we would have similar patterns everywhere.

ArsileLuci reacted with thumbs up emoji
name: Option<syn::LitStr>,

/// Overwritten `level` of span generated, if `None` `Level::INFO` should be used.
level: Option<syn::LitStr>,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ArsileLuci also, why parse all the attribute arguments by ourselves? Cannot we piggyback everything to upstream (tracing crate)?

Copy link
Contributor Author

@ArsileLuci ArsileLuci Jul 23, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tyranron span!(...) macro is pretty strict on argument order, and we need to cleanup arguments specific for juniper, so a little of extra work here will allow to forget about argument order.

Copy link
Member

@ArsileLuci #971 is merged.

ArsileLuci reacted with rocket emoji

Copy link
Contributor Author

ArsileLuci commented Aug 15, 2021
edited
Loading

@tyranron I want to discuss one feature in tracing that is currently risky to implement in Juniper. This is so called Empty fields, due to how we resolve fields we cannot use it in actual resolver (fn that's called within resolve_field and resolve_field_async to get value), we're limited to context of resolve_field or resolve_field_async.

It could be implemented by dirty modification of fns signature, but it's a little bit unfair, I guess.

Edit:

This also can be solved if user implicitly reference Span passed to fn, similarly to how Context and Executor passed, this variant more fair and clean than one suggested above.

Edit2:

The solution is much simpler. User could just use tracing::Span::current() to get access to current Span within resolver fn. So we don't need to bother about dealing with it.

tyranron reacted with eyes emoji

Copy link

mathroc commented Nov 24, 2021

Hi!

Once this lands, I'd like to work on #953 and hope to be able to leverage this. My idea is to create a tracing collector and capture relevant span data to later be able to output the expected JSON. I'm wondering if there is enough already or if some tracing could be added (now or later):

 "tracing": {
 "version": 1,
 "startTime": <>, → that would be the "enter execute"
 "endTime": <>, → "close execute"
 "duration": <>, → the duration of the "execute" span
 "parsing": { → I don't think this is present at the moment
 "startOffset": <>, 
 "duration": <>,
 },
 "validation": { -> there's "validate_document" & "validate_input_values" but I don't know if a duration can be extracted from simple spans. Should they be wrapped by a "start/close validation" span ?
 "startOffset": <>,
 "duration": <>,
 },
 "execution": {
 "resolvers": [ → They are traced. I would need to check if, 1: they can be identified easily, 2: everything below can be extracted from the span or could be added later
 {
 "path": [<>, ...],
 "parentType": <>,
 "fieldName": <>,
 "returnType": <>,
 "startOffset": <>,
 "duration": <>,
 },
 ...
 ]
 }

Do you think something like that would be possible?

tyranron reacted with eyes emoji

Copy link
Member

What outstanding issues are we waiting on here?

Copy link
Contributor Author

ArsileLuci commented Nov 25, 2021
edited
Loading

Hi @mathroc

About this one:

"validation": { -> there's "validate_document" & "validate_input_values" but I don't know if a duration can be extracted from simple spans. Should they be wrapped by a "start/close validation"

Everything related to duration/time should be implemented on Subscriber side.

1: they can be identified easily, 2: everything below can be extracted from the span or could be added later

  1. It's not so simple, probably the only way to identify whether this is field resolver or not is to add custom marker field in every resolver, something like juniper-resolver=true.

  2. Let's walk through every field and check what we can do:

  • path: This will involve some work but all resolver spans follow one naming schema <TypeName>.<resolverName>. Combining it with custom marker field, mentioned above, you can walkthrough every single span and build resolver chain.
  • parentType: If I understand it right this is <TypeName> in span name so there should be no problems with it.
  • fieldName: Same to parentType but this is <resolverName>
  • returnType: This should be implemented, probably using late binding fields
  • startOffset and duration: also should be implemented manually

The biggest disadvantage I see so far is making a whole lot of custom fields. In process of working on this PR I've tested this with stack tracing -> tracing_opentelemetry -> opentelemetry_jaeger and all custom fields were sent to Jaeger. This resulted in Jaeger denying nearly half of my traces because "they are too large".

Copy link

mathroc commented Nov 25, 2021

thx @ArsileLuci for the feedback. Would you recommend doing something completely separate instead?

Copy link
Contributor Author

@mathroc

Would you recommend doing something completely separate instead?

If you need this exact feature, it could be implemented under feature flag either disabling or enabling it. The issue with Jaeger, could be simply solved, by just disabling this extra fields. Just explicitly mention it in the docs, and this should be enough.

@LegNeato

What outstanding issues are we waiting on here?

I don't think there's any, except this branch being a bit old (and forgotten).

mathroc reacted with thumbs up emoji

Copy link
Member

@LegNeato this branch requires some serious review. We (me, @ArsileLuci and @ilslv) have plans to revive it after merging #975

After this PR we will land some subsequent ones, hopefully to fully close the question about tracing in juniper.

LegNeato reacted with thumbs up emoji

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@tyranron tyranron Awaiting requested review from tyranron

1 more reviewer

@mathroc mathroc mathroc left review comments

Reviewers whose approvals may not affect merge requirements

Labels

enhancement Improvement of existing features or bugfix k::api Related to API (application interface)

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

AltStyle によって変換されたページ (->オリジナル) /