Add tracing support for GraphQL objects, interfaces and subscriptions

[ArsileLuci]

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:

• [x] Ensure proper formatting
• [x] Run all tests
• [x] Update the CHANGELOG

[ArsileLuci]

cc @tyranron

[tyranron]

@ArsileLuci #971 is merged.

[ArsileLuci]

@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.

[mathroc]

Hi!

Once this lands, I'd like to work on https://github.com/graphql-rust/juniper/issues/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?

[LegNeato]

What outstanding issues are we waiting on here?

[ArsileLuci]

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".

[mathroc]

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

[ArsileLuci]

@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).

[tyranron]

@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.