Open telemetry support

[BrynCooke]

This PR adds instrumentation to emit the following spans:

• federation.request - total time to server a request.
• federation.validate - time to validate the federated query.
• federation.plan - time to plan the federated query.
• federation.execute - the total time executing query.
• federation.fetch - time fetching data from a subgraph.
• federation.postprocessing - time to render the response from all the subgraph data.

The instrumentation looks a little messy due to the requirement to set error status on spans on exception, but also if errors are added to the response.

[apollo-cla]

@BrynCooke: Thank you for submitting a pull request! Before we can merge it, you'll need to sign the Apollo Contributor License Agreement here: https://contribute.apollographql.com/

[trevor-scheer]

This is looking really great! I don't have any majorly blocking issues, and I think my couple larger suggestions are optional/food for thought anyway.

One separate comment I will make is that consistency in style would be nice. Things that come to mind are indentation, bracket spacing, semicolons, and newlines. Note that this is explicitly not enforced on this repo and it's certainly not correct everywhere, either, so do with that what you will. It's not something I'll go around and leaving nitpick comments about or block on.

[trevor-scheer]

This try/catch/finally pattern is pretty repetitive, particularly in the catch/finally bits. It gets a bit harder to stomach with the nesting / longer try blocks.

I'm on the fence about suggesting this still but worth surfacing the idea since maybe something even better will come out of it. I don't feel strongly about this one (and not even sure of its correctness or completeness, just pseudo-ing something).

async function wrapInSpan<T>(
  tracer: Tracer,
  spanName: string,
  do: (span: Span) => Promise<T>,
  onError?: (err) => Promise<T>
): Promise<T> {
  return tracer.startActiveSpan(spanName, async (span) => {
    try {
      return do(span);
    } catch (err) {
      span.setStatus({ code:SpanStatusCode.ERROR });
      if (onError) return onError(err);
      throw err;
    } finally {
      span.end();
    }
  };
}

// ...inside execution
return wrapInSpan(
  tracer,
  OpenTelemetrySpanNames.EXECUTE,
  async (span) => {
  // execution logic
  },
);

[BrynCooke]

I was also wondering about such a helper function. It seems strange that they didn't bake this in to the OpenTelemetry API.
startActiveSpan actually takes a bunch more parameters, and I realised that I should have been using one of these overloads at least once.

Let's leave it for now, but agree it's not pretty.

[trevor-scheer]

Sgtm!

[trevor-scheer]

Can you provide some comments here? I think we're building a tree of spans where nested spans are added to a span-like object under the children property, which gives it the tree shape. I just get a bit mixed up with the mirror stuff in the process.

If I understand what's happening correctly, maybe we could build a map of parentSpanId => childrenSpanId[] and walk that map starting with the undefined root? You can take this with a grain of salt...this really just trades complexity from the data construction over to the data printing.

[BrynCooke]

I added some comments and also simplified the algorithm.
At least part of the issue was that I had named things badly. Hopefully it looks better now.

[trevor-scheer]

I'm less familiar with the nuances of lockfiles generated by npm@7, but I would expect a diff caused by the move of the devDependencies. This change would be represented after running an npm install now that they're in the correct place within the package.json root. Can you please give that a run and see if there's any change?

[trevor-scheer]

Aside from my package-lock.json concern, this looks ready to me!

[trevor-scheer]

Let's update this with the PR # and link. I think the description is fine but if you feel there's anything worth adding here that's great too.

[BrynCooke]

Thanks for all the feedback @trevor-scheer !