From 0d4969126956d958e62a5daebf144a6653608a3d Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Tue, 16 Aug 2022 16:06:32 +0200 Subject: [PATCH 01/30] WIP --- .../src/plugins/useInlineTrace.ts | 34 +++++++++++++++++++ 1 file changed, 34 insertions(+) create mode 100644 packages/graphql-yoga/src/plugins/useInlineTrace.ts diff --git a/packages/graphql-yoga/src/plugins/useInlineTrace.ts b/packages/graphql-yoga/src/plugins/useInlineTrace.ts new file mode 100644 index 0000000000..3b47fba11c --- /dev/null +++ b/packages/graphql-yoga/src/plugins/useInlineTrace.ts @@ -0,0 +1,34 @@ +import { Plugin } from './types.js' +import { PromiseOrValue } from '@envelop/core' +import { GraphQLParams } from '../types.js' +import { GraphQLError } from 'graphql' + +interface InlineTracePluginOptions { + /** + * > By default, all errors from this service get included in the trace. You + * > can specify a filter function to exclude specific errors from being + * > reported by returning an explicit `null`, or you can mask certain details + * > of the error by modifying it and returning the modified error. + * + * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts + */ + rewriteError?: (err: GraphQLError) => GraphQLError | null +} + +/** + * > This ftv1 plugin produces a base64'd Trace protobuf containing only the + * > durationNs, startTime, endTime, and root fields. This output is placed + * > on the `extensions`.`ftv1` property of the response. The Apollo Gateway + * > utilizes this data to construct the full trace and submit it to Apollo's + * > usage reporting ingress. + * + * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts + */ +export function useInlineTrace(options: InlineTracePluginOptions): Plugin { + return { + onRequest() {}, + onResponse({ response }) { + response + }, + } +} From b7e44800de5f4b708b19fb6af86aa74373ee862e Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Wed, 17 Aug 2022 13:19:11 +0200 Subject: [PATCH 02/30] designated plugin --- .../__tests__/inline-trace.spec.ts | 22 +++++++++ packages/plugins/inline-trace/package.json | 49 +++++++++++++++++++ .../inline-trace/src/index.ts} | 14 ++++-- .../__tests__/persisted-operations.spec.ts | 2 +- yarn.lock | 13 +++-- 5 files changed, 90 insertions(+), 10 deletions(-) create mode 100644 packages/plugins/inline-trace/__tests__/inline-trace.spec.ts create mode 100644 packages/plugins/inline-trace/package.json rename packages/{graphql-yoga/src/plugins/useInlineTrace.ts => plugins/inline-trace/src/index.ts} (85%) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts new file mode 100644 index 0000000000..e75ca64bcc --- /dev/null +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -0,0 +1,22 @@ +import { createYoga, createSchema } from 'graphql-yoga' +import { useInlineTrace } from '../src' + +describe('Inline Trace', () => { + const yoga = createYoga({ + schema: createSchema({ + typeDefs: /* GraphQL */ ` + type Query { + hello: String! + } + `, + resolvers: { + Query: { + hello() { + return 'world' + }, + }, + }, + }), + plugins: [useInlineTrace()], + }) +}) diff --git a/packages/plugins/inline-trace/package.json b/packages/plugins/inline-trace/package.json new file mode 100644 index 0000000000..77021b1e1b --- /dev/null +++ b/packages/plugins/inline-trace/package.json @@ -0,0 +1,49 @@ +{ + "name": "@graphql-yoga/inline-trace", + "version": "0.0.0", + "description": "Apollo's federated tracing plugin for GraphQL Yoga.", + "repository": { + "type": "git", + "url": "https://github.com/dotansimha/graphql-yoga.git", + "directory": "packages/plugins/inline-trace" + }, + "type": "module", + "main": "dist/cjs/index.js", + "module": "dist/esm/index.js", + "scripts": { + "check": "tsc --pretty --noEmit" + }, + "author": "Denis Badurina ", + "license": "MIT", + "exports": { + ".": { + "require": { + "types": "./dist/typings/index.d.cts", + "default": "./dist/cjs/index.js" + }, + "import": { + "types": "./dist/typings/index.d.ts", + "default": "./dist/esm/index.js" + }, + "default": { + "types": "./dist/typings/index.d.ts", + "default": "./dist/esm/index.js" + } + }, + "./package.json": "./package.json" + }, + "typings": "dist/typings/index.d.ts", + "typescript": { + "definition": "dist/typings/index.d.ts" + }, + "publishConfig": { + "directory": "dist", + "access": "public" + }, + "peerDependencies": { + "graphql-yoga": "^3.0.0" + }, + "dependencies": { + "apollo-reporting-protobuf": "^3.3.2" + } +} diff --git a/packages/graphql-yoga/src/plugins/useInlineTrace.ts b/packages/plugins/inline-trace/src/index.ts similarity index 85% rename from packages/graphql-yoga/src/plugins/useInlineTrace.ts rename to packages/plugins/inline-trace/src/index.ts index 3b47fba11c..5f621a6664 100644 --- a/packages/graphql-yoga/src/plugins/useInlineTrace.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -1,9 +1,7 @@ -import { Plugin } from './types.js' -import { PromiseOrValue } from '@envelop/core' -import { GraphQLParams } from '../types.js' +import { Plugin } from 'graphql-yoga' import { GraphQLError } from 'graphql' -interface InlineTracePluginOptions { +export interface InlineTracePluginOptions { /** * > By default, all errors from this service get included in the trace. You * > can specify a filter function to exclude specific errors from being @@ -24,7 +22,13 @@ interface InlineTracePluginOptions { * * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts */ -export function useInlineTrace(options: InlineTracePluginOptions): Plugin { +export function useInlineTrace(options: InlineTracePluginOptions = {}): Plugin { + interface Context { + tracer: null + } + + const ctxForReq = new WeakMap() + return { onRequest() {}, onResponse({ response }) { diff --git a/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts b/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts index f9f319288f..0dee629274 100644 --- a/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts +++ b/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts @@ -1,6 +1,6 @@ import { createYoga, createSchema } from 'graphql-yoga' import request from 'supertest' -import { usePersistedOperations } from '@graphql-yoga/plugin-persisted-operations' +import { usePersistedOperations } from 'packages/plugins/inline-trace/src' const schema = createSchema({ typeDefs: /* GraphQL */ ` diff --git a/yarn.lock b/yarn.lock index 7113b773ba..bed6554aac 100644 --- a/yarn.lock +++ b/yarn.lock @@ -14526,10 +14526,10 @@ lowercase-keys@^2.0.0: resolved "https://registry.yarnpkg.com/lowercase-keys/-/lowercase-keys-2.0.0.tgz#2603e78b7b4b0006cbca2fbcc8a3202558ac9479" integrity sha512-tqNXrS78oMOE73NMxK4EMLQsQowWf8jKooH9g7xPavRT706R6bkQJ6DY2Te7QukaZsulxa30wQ7bk0pm4XiHmA== -lru-cache@*, lru-cache@^7.10.1, lru-cache@^7.13.1, lru-cache@^7.7.1: - version "7.13.2" - resolved "https://registry.yarnpkg.com/lru-cache/-/lru-cache-7.13.2.tgz#bb5d3f1deea3f3a7a35c1c44345566a612e09cd0" - integrity sha512-VJL3nIpA79TodY/ctmZEfhASgqekbT574/c4j3jn4bKXbSCnTTCH/KltZyvL2GlV+tGSMtsWyem8DCX7qKTMBA== +lru-cache@*: + version "7.14.0" + resolved "https://registry.yarnpkg.com/lru-cache/-/lru-cache-7.14.0.tgz#21be64954a4680e303a09e9468f880b98a0b3c7f" + integrity sha512-EIRtP1GrSJny0dqb50QXRUNBxHJhcpxHC++M5tD7RYbvLLn5KVWKsbyswSSqDuU15UFi3bgTQIY8nhDMeF6aDQ== lru-cache@^4.0.1: version "4.1.5" @@ -14546,6 +14546,11 @@ lru-cache@^6.0.0: dependencies: yallist "^4.0.0" +lru-cache@^7.10.1, lru-cache@^7.13.1, lru-cache@^7.7.1: + version "7.13.2" + resolved "https://registry.yarnpkg.com/lru-cache/-/lru-cache-7.13.2.tgz#bb5d3f1deea3f3a7a35c1c44345566a612e09cd0" + integrity sha512-VJL3nIpA79TodY/ctmZEfhASgqekbT574/c4j3jn4bKXbSCnTTCH/KltZyvL2GlV+tGSMtsWyem8DCX7qKTMBA== + luxon@^1.28.0: version "1.28.0" resolved "https://registry.yarnpkg.com/luxon/-/luxon-1.28.0.tgz#e7f96daad3938c06a62de0fb027115d251251fbf" From 80cdac531e26e24e7d8614c7d962b1a0af998182 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Wed, 17 Aug 2022 14:26:04 +0200 Subject: [PATCH 03/30] WIP --- packages/plugins/inline-trace/src/index.ts | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index 5f621a6664..16e5a879ed 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -30,9 +30,15 @@ export function useInlineTrace(options: InlineTracePluginOptions = {}): Plugin { const ctxForReq = new WeakMap() return { - onRequest() {}, - onResponse({ response }) { - response + onRequest({ request }) { + // must be ftv1 tracing protocol + if (request.headers.get('apollo-federation-include-trace') !== 'ftv1') { + return + } + }, + onResolverCalled({ info }) {}, + onResultProcess({ result }) { + // execution completed, we're about to send the response }, } } From 7ded83b3b6bd262f8762751cf464e5a786a412f1 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Wed, 17 Aug 2022 15:22:45 +0200 Subject: [PATCH 04/30] implement using apollo's trace tree builder --- .../src/apolloTraceTreeBuilder.tsx | 324 ++++++++++++++++++ packages/plugins/inline-trace/src/index.ts | 86 ++++- 2 files changed, 404 insertions(+), 6 deletions(-) create mode 100644 packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx diff --git a/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx b/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx new file mode 100644 index 0000000000..640804dc1c --- /dev/null +++ b/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx @@ -0,0 +1,324 @@ +/** + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts + */ +import { GraphQLError, GraphQLResolveInfo, ResponsePath } from 'graphql' +import { Trace, google } from 'apollo-reporting-protobuf' +import { YogaLogger } from 'graphql-yoga' + +function internalError(message: string) { + return new Error(`[internal apollo-server error] ${message}`) +} + +export class TraceTreeBuilder { + private rootNode = new Trace.Node() + private logger: YogaLogger = console + public trace = new Trace({ + root: this.rootNode, + // By default, each trace counts as one operation for the sake of field + // execution counts. If we end up calling the fieldLevelInstrumentation + // callback (once we've successfully resolved the operation) then we + // may set this to a higher number; but we'll start it at 1 so that traces + // that don't successfully resolve the operation (eg parse failures) or + // where we don't call the callback because a plugin set captureTraces to + // true have a reasonable default. + fieldExecutionWeight: 1, + }) + public startHrTime?: [number, number] + private stopped = false + private nodes = new Map([ + [responsePathAsString(), this.rootNode], + ]) + private readonly rewriteError?: (err: GraphQLError) => GraphQLError | null + + public constructor(options: { + logger?: YogaLogger + rewriteError?: (err: GraphQLError) => GraphQLError | null + }) { + this.rewriteError = options.rewriteError + if (options.logger) this.logger = options.logger + } + + public startTiming() { + if (this.startHrTime) { + throw internalError('startTiming called twice!') + } + if (this.stopped) { + throw internalError('startTiming called after stopTiming!') + } + this.trace.startTime = dateToProtoTimestamp(new Date()) + this.startHrTime = process.hrtime() + } + + public stopTiming() { + if (!this.startHrTime) { + throw internalError('stopTiming called before startTiming!') + } + if (this.stopped) { + throw internalError('stopTiming called twice!') + } + + this.trace.durationNs = durationHrTimeToNanos( + process.hrtime(this.startHrTime), + ) + this.trace.endTime = dateToProtoTimestamp(new Date()) + this.stopped = true + } + + public willResolveField(info: GraphQLResolveInfo): () => void { + if (!this.startHrTime) { + throw internalError('willResolveField called before startTiming!') + } + if (this.stopped) { + // We've been stopped, which means execution is done... and yet we're + // still resolving more fields? How can that be? Shouldn't we throw an + // error or something? + // + // Well... we used to do exactly that. But this "shouldn't happen" error + // showed up in practice! Turns out that graphql-js can actually continue + // to execute more fields indefinitely long after `execute()` resolves! + // That's because parallelism on a selection set is implemented using + // `Promise.all`, and as soon as one of its arguments (ie, one field) + // throws an error, the combined Promise resolves, but there's no + // "cancellation" of the Promises that are the other arguments to + // `Promise.all`. So the code contributing to those Promises keeps on + // chugging away indefinitely. + // + // Concrete example: let’s say you have + // + // { x y { ARBITRARY_SELECTION_SET } } + // + // where x has a non-null return type, and x and y both have resolvers + // that return Promises. And let’s say that x returns a Promise that + // rejects (or resolves to null). What this means is that we’re going to + // eventually end up with `data: null` (nothing under y will actually + // matter), but graphql-js execution will continue running whatever is + // under ARBITRARY_SELECTION_SET without any sort of short circuiting. In + // fact, the Promise returned from execute itself can happily resolve + // while execution is still chugging away on an arbitrary amount of fields + // under that ARBITRARY_SELECTION_SET. There’s no way to detect from the + // outside "all the execution related to this operation is done", nor to + // "short-circuit" execution so that it stops going. + // + // So, um. We will record any field whose execution we manage to observe + // before we "stop" the TraceTreeBuilder (whether it is one that actually + // ends up in the response or whether it gets thrown away due to null + // bubbling), but if we get any more fields afterwards, we just ignore + // them rather than throwing a confusing error. + // + // (That said, the error we used to throw here generally was hidden + // anyway, for the same reason: it comes from a branch of execution that + // ends up not being included in the response. But + // https://github.com/graphql/graphql-js/pull/3529 means that this + // sometimes crashed execution anyway. Our error never caught any actual + // problematic cases, so keeping it around doesn't really help.) + return () => {} + } + + const path = info.path + const node = this.newNode(path) + node.type = info.returnType.toString() + node.parentType = info.parentType.toString() + node.startTime = durationHrTimeToNanos(process.hrtime(this.startHrTime)) + if (typeof path.key === 'string' && path.key !== info.fieldName) { + // This field was aliased; send the original field name too (for FieldStats). + node.originalFieldName = info.fieldName + } + + return () => { + node.endTime = durationHrTimeToNanos(process.hrtime(this.startHrTime)) + } + } + + public didEncounterErrors(errors: readonly GraphQLError[]) { + errors.forEach((err) => { + // This is an error from a federated service. We will already be reporting + // it in the nested Trace in the query plan. + // + // XXX This probably shouldn't skip query or validation errors, which are + // not in nested Traces because format() isn't called in this case! Or + // maybe format() should be called in that case? + if (err.extensions?.serviceName) { + return + } + + // In terms of reporting, errors can be re-written by the user by + // utilizing the `rewriteError` parameter. This allows changing + // the message or stack to remove potentially sensitive information. + // Returning `null` will result in the error not being reported at all. + const errorForReporting = this.rewriteAndNormalizeError(err) + + if (errorForReporting === null) { + return + } + + this.addProtobufError( + errorForReporting.path, + errorToProtobufError(errorForReporting), + ) + }) + } + + private addProtobufError( + path: ReadonlyArray | undefined, + error: Trace.Error, + ) { + if (!this.startHrTime) { + throw internalError('addProtobufError called before startTiming!') + } + if (this.stopped) { + throw internalError('addProtobufError called after stopTiming!') + } + + // By default, put errors on the root node. + let node = this.rootNode + // If a non-GraphQLError Error sneaks in here somehow with a non-array + // path, don't crash. + if (Array.isArray(path)) { + const specificNode = this.nodes.get(path.join('.')) + if (specificNode) { + node = specificNode + } else { + this.logger.warn( + `Could not find node with path ${path.join( + '.', + )}; defaulting to put errors on root node.`, + ) + } + } + + node.error.push(error) + } + + private newNode(path: ResponsePath): Trace.Node { + const node = new Trace.Node() + const id = path.key + if (typeof id === 'number') { + node.index = id + } else { + node.responseName = id + } + this.nodes.set(responsePathAsString(path), node) + const parentNode = this.ensureParentNode(path) + parentNode.child.push(node) + return node + } + + private ensureParentNode(path: ResponsePath): Trace.Node { + const parentPath = responsePathAsString(path.prev) + const parentNode = this.nodes.get(parentPath) + if (parentNode) { + return parentNode + } + // Because we set up the root path when creating this.nodes, we now know + // that path.prev isn't undefined. + return this.newNode(path.prev!) + } + + private rewriteAndNormalizeError(err: GraphQLError): GraphQLError | null { + if (this.rewriteError) { + // Before passing the error to the user-provided `rewriteError` function, + // we'll make a shadow copy of the error so the user is free to change + // the object as they see fit. + + // At this stage, this error is only for the purposes of reporting, but + // this is even more important since this is still a reference to the + // original error object and changing it would also change the error which + // is returned in the response to the client. + + // For the clone, we'll create a new object which utilizes the exact same + // prototype of the error being reported. + const clonedError = Object.assign( + Object.create(Object.getPrototypeOf(err)), + err, + ) + + const rewrittenError = this.rewriteError(clonedError) + + // Returning an explicit `null` means the user is requesting that the error + // not be reported to Apollo. + if (rewrittenError === null) { + return null + } + + // We don't want users to be inadvertently not reporting errors, so if + // they haven't returned an explicit `GraphQLError` (or `null`, handled + // above), then we'll report the error as usual. + if (!(rewrittenError instanceof GraphQLError)) { + return err + } + + // We only allow rewriteError to change the message and extensions of the + // error; we keep everything else the same. That way people don't have to + // do extra work to keep the error on the same trace node. We also keep + // extensions the same if it isn't explicitly changed (to, eg, {}). (Note + // that many of the fields of GraphQLError are not enumerable and won't + // show up in the trace (even in the json field) anyway.) + return new GraphQLError( + rewrittenError.message, + err.nodes, + err.source, + err.positions, + err.path, + err.originalError, + rewrittenError.extensions || err.extensions, + ) + } + return err + } +} + +// Converts an hrtime array (as returned from process.hrtime) to nanoseconds. +// +// ONLY CALL THIS ON VALUES REPRESENTING DELTAS, NOT ON THE RAW RETURN VALUE +// FROM process.hrtime() WITH NO ARGUMENTS. +// +// The entire point of the hrtime data structure is that the JavaScript Number +// type can't represent all int64 values without loss of precision: +// Number.MAX_SAFE_INTEGER nanoseconds is about 104 days. Calling this function +// on a duration that represents a value less than 104 days is fine. Calling +// this function on an absolute time (which is generally roughly time since +// system boot) is not a good idea. +// +// XXX We should probably use google.protobuf.Duration on the wire instead of +// ever trying to store durations in a single number. +function durationHrTimeToNanos(hrtime: [number, number]) { + return hrtime[0] * 1e9 + hrtime[1] +} + +// Convert from the linked-list ResponsePath format to a dot-joined +// string. Includes the full path (field names and array indices). +function responsePathAsString(p?: ResponsePath): string { + if (p === undefined) { + return '' + } + + // A previous implementation used `responsePathAsArray` from `graphql-js/execution`, + // however, that employed an approach that created new arrays unnecessarily. + let res = String(p.key) + + while ((p = p.prev) !== undefined) { + res = `${p.key}.${res}` + } + + return res +} + +function errorToProtobufError(error: GraphQLError): Trace.Error { + return new Trace.Error({ + message: error.message, + location: (error.locations || []).map( + ({ line, column }) => new Trace.Location({ line, column }), + ), + json: JSON.stringify(error), + }) +} + +// Converts a JS Date into a Timestamp. +export function dateToProtoTimestamp(date: Date): google.protobuf.Timestamp { + const totalMillis = +date + const millis = totalMillis % 1000 + return new google.protobuf.Timestamp({ + seconds: (totalMillis - millis) / 1000, + nanos: millis * 1e6, + }) +} diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index 16e5a879ed..a5139b9d27 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -1,5 +1,7 @@ -import { Plugin } from 'graphql-yoga' +import { isAsyncIterable, Plugin, YogaInitialContext } from 'graphql-yoga' import { GraphQLError } from 'graphql' +import { TraceTreeBuilder } from './apolloTraceTreeBuilder' +import { Trace } from 'apollo-reporting-protobuf' export interface InlineTracePluginOptions { /** @@ -22,9 +24,11 @@ export interface InlineTracePluginOptions { * * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts */ -export function useInlineTrace(options: InlineTracePluginOptions = {}): Plugin { +export function useInlineTrace( + options: InlineTracePluginOptions = {}, +): Plugin { interface Context { - tracer: null + treeBuilder: TraceTreeBuilder } const ctxForReq = new WeakMap() @@ -35,10 +39,80 @@ export function useInlineTrace(options: InlineTracePluginOptions = {}): Plugin { if (request.headers.get('apollo-federation-include-trace') !== 'ftv1') { return } + + const treeBuilder = new TraceTreeBuilder({ + rewriteError: options.rewriteError, + }) + + treeBuilder.startTiming() + + ctxForReq.set(request, { treeBuilder }) }, - onResolverCalled({ info }) {}, - onResultProcess({ result }) { - // execution completed, we're about to send the response + onResolverCalled({ context: { request }, info }) { + return ctxForReq.get(request)?.treeBuilder.willResolveField(info) + }, + onParse() { + return ({ context: { request }, result }) => { + if (result instanceof GraphQLError) { + ctxForReq.get(request)?.treeBuilder.didEncounterErrors([result]) + } else if (result instanceof Error) { + ctxForReq.get(request)?.treeBuilder.didEncounterErrors([ + new GraphQLError(result.message, { + originalError: result, + }), + ]) + } + } + }, + onValidate() { + return ({ context: { request }, result: errors }) => { + if (errors.length) { + ctxForReq.get(request)?.treeBuilder.didEncounterErrors(errors) + } + } + }, + onExecute() { + return { + onExecuteDone({ + args: { + contextValue: { request }, + }, + result, + }) { + // TODO: should handle streaming results? how? + if (!isAsyncIterable(result) && result.errors?.length) { + ctxForReq + .get(request) + ?.treeBuilder.didEncounterErrors(result.errors) + } + }, + } + }, + // TODO: should track subscription errors? how? + onResultProcess({ request, result }) { + const treeBuilder = ctxForReq.get(request)?.treeBuilder + if (!treeBuilder) return + + // TODO: should handle streaming results? how? + if (isAsyncIterable(result)) return + + treeBuilder.stopTiming() + + const encodedUint8Array = Trace.encode(treeBuilder.trace).finish() + const encodedBuffer = Buffer.from( + encodedUint8Array, + encodedUint8Array.byteOffset, + encodedUint8Array.byteLength, + ) + + const extensions = + result.extensions || (result.extensions = Object.create(null)) + + if (typeof extensions.ftv1 !== 'undefined') { + throw new Error('The `ftv1` extension was already present.') + } + + extensions.ftv1 = encodedBuffer.toString('base64') }, } } From dfcca15d86dc3217cb16df015690373766c95da0 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Wed, 17 Aug 2022 15:30:43 +0200 Subject: [PATCH 05/30] tests and adjustments --- .../__tests__/inline-trace.spec.ts | 66 +++++++++++++++++++ packages/plugins/inline-trace/src/index.ts | 14 ++-- 2 files changed, 73 insertions(+), 7 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index e75ca64bcc..50e4e2b0a7 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -1,5 +1,7 @@ +import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' import { useInlineTrace } from '../src' +import { Trace } from 'apollo-reporting-protobuf' describe('Inline Trace', () => { const yoga = createYoga({ @@ -19,4 +21,68 @@ describe('Inline Trace', () => { }), plugins: [useInlineTrace()], }) + + it('should add ftv1 tracing to result extensions', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ hello }', + }) + + expect(response.ok).toBeTruthy() + expect(response.body?.errors).toBeUndefined() + expect(response.body?.extensions?.ftv1).toBeDefined() + }) + + it('should contain valid proto tracing details on success', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ hello }', + }) + + expect(response.ok).toBeTruthy() + expect(response.body?.errors).toBeUndefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expect(trace.startTime).toBeDefined() + expect(typeof trace.startTime?.seconds).toBe('number') + expect(typeof trace.startTime?.nanos).toBe('number') + + expect(typeof trace.durationNs).toBe('number') + + expect(trace.endTime).toBeDefined() + expect(typeof trace.endTime?.seconds).toBe('number') + expect(typeof trace.endTime?.nanos).toBe('number') + + expect(trace.startTime!.seconds! + trace.startTime!.nanos!).toBeLessThan( + trace.endTime!.seconds! + trace.endTime!.nanos!, + ) + + expect(typeof trace.fieldExecutionWeight).toBe('number') + + expect(trace.root).toBeDefined() + expect(trace.root?.child).toBeInstanceOf(Array) + + const hello = trace.root!.child![0] + + expect(hello.responseName).toBe('hello') + expect(hello.type).toBe('String!') + expect(hello.parentType).toBe('Query') + + expect(typeof hello.startTime).toBe('number') + expect(typeof hello.endTime).toBe('number') + + expect(hello.startTime!).toBeLessThan(hello.endTime!) + }) }) diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index a5139b9d27..4ad7e59a77 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -96,6 +96,10 @@ export function useInlineTrace( // TODO: should handle streaming results? how? if (isAsyncIterable(result)) return + if (result.extensions?.ftv1 !== undefined) { + throw new Error('The `ftv1` extension was already present.') + } + treeBuilder.stopTiming() const encodedUint8Array = Trace.encode(treeBuilder.trace).finish() @@ -105,14 +109,10 @@ export function useInlineTrace( encodedUint8Array.byteLength, ) - const extensions = - result.extensions || (result.extensions = Object.create(null)) - - if (typeof extensions.ftv1 !== 'undefined') { - throw new Error('The `ftv1` extension was already present.') + result.extensions = { + ...result.extensions, + ftv1: encodedBuffer.toString('base64'), } - - extensions.ftv1 = encodedBuffer.toString('base64') }, } } From d1d93dae3909435c1fce690ac742cb13059188a9 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 10:46:08 +0200 Subject: [PATCH 06/30] precision with add seconds and nanos --- .../inline-trace/__tests__/inline-trace.spec.ts | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index 50e4e2b0a7..b477bacc05 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -65,8 +65,10 @@ describe('Inline Trace', () => { expect(typeof trace.endTime?.seconds).toBe('number') expect(typeof trace.endTime?.nanos).toBe('number') - expect(trace.startTime!.seconds! + trace.startTime!.nanos!).toBeLessThan( - trace.endTime!.seconds! + trace.endTime!.nanos!, + expect( + addSecondsAndNanos(trace.startTime!.seconds!, trace.startTime!.nanos!), + ).toBeLessThan( + addSecondsAndNanos(trace.endTime!.seconds!, trace.endTime!.nanos!), ) expect(typeof trace.fieldExecutionWeight).toBe('number') @@ -86,3 +88,7 @@ describe('Inline Trace', () => { expect(hello.startTime!).toBeLessThan(hello.endTime!) }) }) + +function addSecondsAndNanos(seconds: number, nanos: number): number { + return seconds + nanos / 1e9 +} From 470147ba3a0eed2f2c878df5a99646dc9c9be6f7 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 11:01:22 +0200 Subject: [PATCH 07/30] tests adjustments and error cases --- .../__tests__/inline-trace.spec.ts | 142 +++++++++++++++--- 1 file changed, 120 insertions(+), 22 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index b477bacc05..e082d2c60a 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -2,6 +2,7 @@ import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' import { useInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' +import { GraphQLError } from 'graphql' describe('Inline Trace', () => { const yoga = createYoga({ @@ -9,6 +10,7 @@ describe('Inline Trace', () => { typeDefs: /* GraphQL */ ` type Query { hello: String! + boom: String! } `, resolvers: { @@ -16,6 +18,9 @@ describe('Inline Trace', () => { hello() { return 'world' }, + boom() { + throw new Error('bam') + }, }, }, }), @@ -55,40 +60,133 @@ describe('Inline Trace', () => { const ftv1 = response.body?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) - expect(trace.startTime).toBeDefined() - expect(typeof trace.startTime?.seconds).toBe('number') - expect(typeof trace.startTime?.nanos).toBe('number') + expectTrace(trace) - expect(typeof trace.durationNs).toBe('number') + const hello = trace.root!.child![0] + expectTraceNode(hello, 'hello', 'String!') + }) - expect(trace.endTime).toBeDefined() - expect(typeof trace.endTime?.seconds).toBe('number') - expect(typeof trace.endTime?.nanos).toBe('number') + it('should contain valid proto tracing details on parse fail', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ he', + }) - expect( - addSecondsAndNanos(trace.startTime!.seconds!, trace.startTime!.nanos!), - ).toBeLessThan( - addSecondsAndNanos(trace.endTime!.seconds!, trace.endTime!.nanos!), - ) + expect(response.body?.errors).toBeDefined() - expect(typeof trace.fieldExecutionWeight).toBe('number') + // - expect(trace.root).toBeDefined() - expect(trace.root?.child).toBeInstanceOf(Array) + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) - const hello = trace.root!.child![0] + expectTrace(trace) + expectTraceNodeError(trace.root) + }) + + it('should contain valid proto tracing details on validation fail', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ henlo }', + }) + + expect(response.body?.errors).toBeDefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) - expect(hello.responseName).toBe('hello') - expect(hello.type).toBe('String!') - expect(hello.parentType).toBe('Query') + expectTrace(trace) + expectTraceNodeError(trace.root) + }) + + it('should contain valid proto tracing details on execution fail', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ boom }', + }) + + expect(response.body?.errors).toBeDefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) - expect(typeof hello.startTime).toBe('number') - expect(typeof hello.endTime).toBe('number') + expectTrace(trace) - expect(hello.startTime!).toBeLessThan(hello.endTime!) + const boom = trace.root!.child![0] + expectTraceNode(boom, 'boom', 'String!') + expectTraceNodeError(boom) }) }) +function expectTrace(trace: Trace) { + expect(trace.startTime).toBeDefined() + expect(typeof trace.startTime?.seconds).toBe('number') + expect(typeof trace.startTime?.nanos).toBe('number') + + expect(typeof trace.durationNs).toBe('number') + + expect(trace.endTime).toBeDefined() + expect(typeof trace.endTime?.seconds).toBe('number') + expect(typeof trace.endTime?.nanos).toBe('number') + + expect( + addSecondsAndNanos(trace.startTime!.seconds!, trace.startTime!.nanos!), + ).toBeLessThan( + addSecondsAndNanos(trace.endTime!.seconds!, trace.endTime!.nanos!), + ) + + expect(typeof trace.fieldExecutionWeight).toBe('number') + + expect(trace.root).toBeDefined() + expect(trace.root?.child).toBeInstanceOf(Array) +} + +function expectTraceNode( + node: Trace.INode | null | undefined, + field: string, + type: string, +) { + expect(node).toBeDefined() + + expect(node!.responseName).toBe(field) + expect(node!.type).toBe(type) + expect(node!.parentType).toBe('Query') + + expect(typeof node!.startTime).toBe('number') + expect(typeof node!.endTime).toBe('number') + + expect(node!.startTime!).toBeLessThan(node!.endTime!) +} + +function expectTraceNodeError(node: Trace.INode | null | undefined) { + expect(node).toBeDefined() + expect(node!.error).toBeDefined() + const error = node!.error! + expect(error).toBeInstanceOf(Array) + expect(typeof error[0].message).toBe('string') + expect(typeof error[0].location).toBeDefined() + expect(typeof error[0].location?.[0].line).toBe('number') + expect(typeof error[0].location?.[0].column).toBe('number') + expect(() => { + JSON.parse(error[0].json!) + }).not.toThrow() +} + function addSecondsAndNanos(seconds: number, nanos: number): number { return seconds + nanos / 1e9 } From 49200a48396f6330493196e28b4e2d935f09775f Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 11:02:50 +0200 Subject: [PATCH 08/30] micro reorg --- .../__tests__/inline-trace.spec.ts | 109 +++++++++--------- 1 file changed, 54 insertions(+), 55 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index e082d2c60a..265b2307ee 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -2,7 +2,6 @@ import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' import { useInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' -import { GraphQLError } from 'graphql' describe('Inline Trace', () => { const yoga = createYoga({ @@ -42,6 +41,46 @@ describe('Inline Trace', () => { expect(response.body?.extensions?.ftv1).toBeDefined() }) + function expectTrace(trace: Trace) { + expect(trace.startTime).toBeDefined() + expect(typeof trace.startTime?.seconds).toBe('number') + expect(typeof trace.startTime?.nanos).toBe('number') + + expect(typeof trace.durationNs).toBe('number') + + expect(trace.endTime).toBeDefined() + expect(typeof trace.endTime?.seconds).toBe('number') + expect(typeof trace.endTime?.nanos).toBe('number') + + expect( + addSecondsAndNanos(trace.startTime!.seconds!, trace.startTime!.nanos!), + ).toBeLessThan( + addSecondsAndNanos(trace.endTime!.seconds!, trace.endTime!.nanos!), + ) + + expect(typeof trace.fieldExecutionWeight).toBe('number') + + expect(trace.root).toBeDefined() + expect(trace.root?.child).toBeInstanceOf(Array) + } + + function expectTraceNode( + node: Trace.INode | null | undefined, + field: string, + type: string, + ) { + expect(node).toBeDefined() + + expect(node!.responseName).toBe(field) + expect(node!.type).toBe(type) + expect(node!.parentType).toBe('Query') + + expect(typeof node!.startTime).toBe('number') + expect(typeof node!.endTime).toBe('number') + + expect(node!.startTime!).toBeLessThan(node!.endTime!) + } + it('should contain valid proto tracing details on success', async () => { const response = await request(yoga) .post('/graphql') @@ -66,6 +105,20 @@ describe('Inline Trace', () => { expectTraceNode(hello, 'hello', 'String!') }) + function expectTraceNodeError(node: Trace.INode | null | undefined) { + expect(node).toBeDefined() + expect(node!.error).toBeDefined() + const error = node!.error! + expect(error).toBeInstanceOf(Array) + expect(typeof error[0].message).toBe('string') + expect(typeof error[0].location).toBeDefined() + expect(typeof error[0].location?.[0].line).toBe('number') + expect(typeof error[0].location?.[0].column).toBe('number') + expect(() => { + JSON.parse(error[0].json!) + }).not.toThrow() + } + it('should contain valid proto tracing details on parse fail', async () => { const response = await request(yoga) .post('/graphql') @@ -133,60 +186,6 @@ describe('Inline Trace', () => { }) }) -function expectTrace(trace: Trace) { - expect(trace.startTime).toBeDefined() - expect(typeof trace.startTime?.seconds).toBe('number') - expect(typeof trace.startTime?.nanos).toBe('number') - - expect(typeof trace.durationNs).toBe('number') - - expect(trace.endTime).toBeDefined() - expect(typeof trace.endTime?.seconds).toBe('number') - expect(typeof trace.endTime?.nanos).toBe('number') - - expect( - addSecondsAndNanos(trace.startTime!.seconds!, trace.startTime!.nanos!), - ).toBeLessThan( - addSecondsAndNanos(trace.endTime!.seconds!, trace.endTime!.nanos!), - ) - - expect(typeof trace.fieldExecutionWeight).toBe('number') - - expect(trace.root).toBeDefined() - expect(trace.root?.child).toBeInstanceOf(Array) -} - -function expectTraceNode( - node: Trace.INode | null | undefined, - field: string, - type: string, -) { - expect(node).toBeDefined() - - expect(node!.responseName).toBe(field) - expect(node!.type).toBe(type) - expect(node!.parentType).toBe('Query') - - expect(typeof node!.startTime).toBe('number') - expect(typeof node!.endTime).toBe('number') - - expect(node!.startTime!).toBeLessThan(node!.endTime!) -} - -function expectTraceNodeError(node: Trace.INode | null | undefined) { - expect(node).toBeDefined() - expect(node!.error).toBeDefined() - const error = node!.error! - expect(error).toBeInstanceOf(Array) - expect(typeof error[0].message).toBe('string') - expect(typeof error[0].location).toBeDefined() - expect(typeof error[0].location?.[0].line).toBe('number') - expect(typeof error[0].location?.[0].column).toBe('number') - expect(() => { - JSON.parse(error[0].json!) - }).not.toThrow() -} - function addSecondsAndNanos(seconds: number, nanos: number): number { return seconds + nanos / 1e9 } From 17c00cc6c0ed0581205d9c29c1cb5761d1b018d7 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 11:09:03 +0200 Subject: [PATCH 09/30] use optional chaining, tests will fail --- packages/plugins/inline-trace/__tests__/inline-trace.spec.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index 265b2307ee..c6409eb2f4 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -101,7 +101,7 @@ describe('Inline Trace', () => { expectTrace(trace) - const hello = trace.root!.child![0] + const hello = trace.root?.child?.[0] expectTraceNode(hello, 'hello', 'String!') }) @@ -180,7 +180,7 @@ describe('Inline Trace', () => { expectTrace(trace) - const boom = trace.root!.child![0] + const boom = trace.root?.child?.[0] expectTraceNode(boom, 'boom', 'String!') expectTraceNodeError(boom) }) From 5f4b4ef8d71a895707bdc7471d700433f86bad96 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 11:25:04 +0200 Subject: [PATCH 10/30] even more tests --- .../__tests__/inline-trace.spec.ts | 68 +++++++++++++++++-- 1 file changed, 64 insertions(+), 4 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index c6409eb2f4..e29516a1f4 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -10,6 +10,10 @@ describe('Inline Trace', () => { type Query { hello: String! boom: String! + person: Person! + } + type Person { + name: String! } `, resolvers: { @@ -20,6 +24,9 @@ describe('Inline Trace', () => { boom() { throw new Error('bam') }, + person() { + return { name: 'John' } + }, }, }, }), @@ -68,12 +75,13 @@ describe('Inline Trace', () => { node: Trace.INode | null | undefined, field: string, type: string, + parent: string, ) { expect(node).toBeDefined() expect(node!.responseName).toBe(field) expect(node!.type).toBe(type) - expect(node!.parentType).toBe('Query') + expect(node!.parentType).toBe(parent) expect(typeof node!.startTime).toBe('number') expect(typeof node!.endTime).toBe('number') @@ -81,7 +89,7 @@ describe('Inline Trace', () => { expect(node!.startTime!).toBeLessThan(node!.endTime!) } - it('should contain valid proto tracing details on success', async () => { + it('should contain valid proto tracing details on flat query success', async () => { const response = await request(yoga) .post('/graphql') .set({ @@ -102,7 +110,59 @@ describe('Inline Trace', () => { expectTrace(trace) const hello = trace.root?.child?.[0] - expectTraceNode(hello, 'hello', 'String!') + expectTraceNode(hello, 'hello', 'String!', 'Query') + }) + + it('should contain valid proto tracing details on aliased flat query success', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ hi: hello }', + }) + + expect(response.ok).toBeTruthy() + expect(response.body?.errors).toBeUndefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expectTrace(trace) + + const hi = trace.root?.child?.[0] + expectTraceNode(hi, 'hi', 'String!', 'Query') + expect(hi?.originalFieldName).toBe('hello') + }) + + it('should contain valid proto tracing details on nested query success', async () => { + const response = await request(yoga) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ person { name } }', + }) + + expect(response.ok).toBeTruthy() + expect(response.body?.errors).toBeUndefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expectTrace(trace) + + const person = trace.root?.child?.[0] + expectTraceNode(person, 'person', 'Person!', 'Query') + + const personName = person?.child?.[0] + expectTraceNode(personName, 'name', 'String!', 'Person') }) function expectTraceNodeError(node: Trace.INode | null | undefined) { @@ -181,7 +241,7 @@ describe('Inline Trace', () => { expectTrace(trace) const boom = trace.root?.child?.[0] - expectTraceNode(boom, 'boom', 'String!') + expectTraceNode(boom, 'boom', 'String!', 'Query') expectTraceNodeError(boom) }) }) From e5b5d21607565fd9364026881ab99bb3dab2a0ce Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 12:03:42 +0200 Subject: [PATCH 11/30] expect no errors --- .../plugins/inline-trace/__tests__/inline-trace.spec.ts | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index e29516a1f4..2f5b0ed200 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -108,8 +108,10 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) + expect(trace.root?.error).toBeUndefined() const hello = trace.root?.child?.[0] + expect(hello?.error).toBeUndefined() expectTraceNode(hello, 'hello', 'String!', 'Query') }) @@ -132,8 +134,10 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) + expect(trace.root?.error).toBeUndefined() const hi = trace.root?.child?.[0] + expect(hi?.error).toBeUndefined() expectTraceNode(hi, 'hi', 'String!', 'Query') expect(hi?.originalFieldName).toBe('hello') }) @@ -157,11 +161,14 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) + expect(trace.root?.error).toBeUndefined() const person = trace.root?.child?.[0] + expect(person?.error).toBeUndefined() expectTraceNode(person, 'person', 'Person!', 'Query') const personName = person?.child?.[0] + expect(personName?.error).toBeUndefined() expectTraceNode(personName, 'name', 'String!', 'Person') }) From 0917ec5858cf677d0c1ca4359c25faef55d8dc65 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 12:06:08 +0200 Subject: [PATCH 12/30] error expectations --- .../inline-trace/__tests__/inline-trace.spec.ts | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index 2f5b0ed200..bc0bcc7acd 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -108,10 +108,10 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) - expect(trace.root?.error).toBeUndefined() + expect(trace.root?.error?.length).toBe(0) const hello = trace.root?.child?.[0] - expect(hello?.error).toBeUndefined() + expect(hello?.error?.length).toBe(0) expectTraceNode(hello, 'hello', 'String!', 'Query') }) @@ -134,10 +134,10 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) - expect(trace.root?.error).toBeUndefined() + expect(trace.root?.error?.length).toBe(0) const hi = trace.root?.child?.[0] - expect(hi?.error).toBeUndefined() + expect(hi?.error?.length).toBe(0) expectTraceNode(hi, 'hi', 'String!', 'Query') expect(hi?.originalFieldName).toBe('hello') }) @@ -161,14 +161,14 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) - expect(trace.root?.error).toBeUndefined() + expect(trace.root?.error?.length).toBe(0) const person = trace.root?.child?.[0] - expect(person?.error).toBeUndefined() + expect(person?.error?.length).toBe(0) expectTraceNode(person, 'person', 'Person!', 'Query') const personName = person?.child?.[0] - expect(personName?.error).toBeUndefined() + expect(personName?.error?.length).toBe(0) expectTraceNode(personName, 'name', 'String!', 'Person') }) @@ -177,6 +177,7 @@ describe('Inline Trace', () => { expect(node!.error).toBeDefined() const error = node!.error! expect(error).toBeInstanceOf(Array) + expect(error.length).toBeGreaterThan(0) expect(typeof error[0].message).toBe('string') expect(typeof error[0].location).toBeDefined() expect(typeof error[0].location?.[0].line).toBe('number') From 655bbc6b9f05f0421b8ac423f4dc1b7e8bf62836 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 12:45:51 +0200 Subject: [PATCH 13/30] create yoga for each test --- .../__tests__/inline-trace.spec.ts | 96 ++++++++++++------- 1 file changed, 64 insertions(+), 32 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index bc0bcc7acd..ddf59c1a3b 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -4,37 +4,39 @@ import { useInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' describe('Inline Trace', () => { - const yoga = createYoga({ - schema: createSchema({ - typeDefs: /* GraphQL */ ` - type Query { - hello: String! - boom: String! - person: Person! - } - type Person { - name: String! - } - `, - resolvers: { - Query: { - hello() { - return 'world' - }, - boom() { - throw new Error('bam') - }, - person() { - return { name: 'John' } - }, + const schema = createSchema({ + typeDefs: /* GraphQL */ ` + type Query { + hello: String! + boom: String! + person: Person! + } + type Person { + name: String! + } + `, + resolvers: { + Query: { + hello() { + return 'world' + }, + boom() { + throw new Error('bam') + }, + person() { + return { name: 'John' } }, }, - }), - plugins: [useInlineTrace()], + }, }) it('should add ftv1 tracing to result extensions', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -90,7 +92,12 @@ describe('Inline Trace', () => { } it('should contain valid proto tracing details on flat query success', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -116,7 +123,12 @@ describe('Inline Trace', () => { }) it('should contain valid proto tracing details on aliased flat query success', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -143,7 +155,12 @@ describe('Inline Trace', () => { }) it('should contain valid proto tracing details on nested query success', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -188,7 +205,12 @@ describe('Inline Trace', () => { } it('should contain valid proto tracing details on parse fail', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -209,7 +231,12 @@ describe('Inline Trace', () => { }) it('should contain valid proto tracing details on validation fail', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', @@ -230,7 +257,12 @@ describe('Inline Trace', () => { }) it('should contain valid proto tracing details on execution fail', async () => { - const response = await request(yoga) + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) .post('/graphql') .set({ 'apollo-federation-include-trace': 'ftv1', From 1f4dd6b0ca7bb80fdbd120be2a771f7624dabbc0 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 12:52:59 +0200 Subject: [PATCH 14/30] test rewrite error --- .../__tests__/inline-trace.spec.ts | 73 +++++++++++++++++++ 1 file changed, 73 insertions(+) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index ddf59c1a3b..50f32ed9d6 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -2,6 +2,7 @@ import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' import { useInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' +import { GraphQLError } from 'graphql' describe('Inline Trace', () => { const schema = createSchema({ @@ -279,11 +280,83 @@ describe('Inline Trace', () => { const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) + expect(trace.root?.error?.length).toBe(0) const boom = trace.root?.child?.[0] expectTraceNode(boom, 'boom', 'String!', 'Query') expectTraceNodeError(boom) }) + + it('should skip tracing errors through rewriteError', async () => { + const response = await request( + createYoga({ + schema, + plugins: [ + useInlineTrace({ + rewriteError: () => null, + }), + ], + }), + ) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ he', + }) + + expect(response.body?.errors).toBeDefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expectTrace(trace) + expect(trace.root?.error?.length).toBe(0) + }) + + it('should rewrite only error messages and extensions through rewriteError', async () => { + const response = await request( + createYoga({ + schema, + plugins: [ + useInlineTrace({ + rewriteError: () => + new GraphQLError('bim', { extensions: { str: 'ing' } }), + }), + ], + }), + ) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ boom }', + }) + + expect(response.body?.errors).toBeDefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expectTrace(trace) + expect(trace.root?.error?.length).toBe(0) + + const boom = trace.root?.child?.[0] + expectTraceNode(boom, 'boom', 'String!', 'Query') + expectTraceNodeError(boom) // will check for location + + const error = boom!.error! + expect(error[0].message).toBe('bim') // not 'bam' + + const errObj = JSON.parse(error[0].json!) + expect(errObj.extensions).toEqual({ str: 'ing' }) + }) }) function addSecondsAndNanos(seconds: number, nanos: number): number { From 7d70e9a638956d20015e7abd9d2149fad7af1c98 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 13:03:34 +0200 Subject: [PATCH 15/30] test array --- .../__tests__/inline-trace.spec.ts | 43 +++++++++++++++++++ 1 file changed, 43 insertions(+) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index 50f32ed9d6..c316e2207e 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -11,6 +11,7 @@ describe('Inline Trace', () => { hello: String! boom: String! person: Person! + people: [Person!]! } type Person { name: String! @@ -27,6 +28,9 @@ describe('Inline Trace', () => { person() { return { name: 'John' } }, + people() { + return [{ name: 'John' }, { name: 'Jane' }] + }, }, }, }) @@ -155,6 +159,45 @@ describe('Inline Trace', () => { expect(hi?.originalFieldName).toBe('hello') }) + it('should contain valid proto tracing details on flat query with array field success', async () => { + const response = await request( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) + .post('/graphql') + .set({ + 'apollo-federation-include-trace': 'ftv1', + }) + .send({ + query: '{ people { name } }', + }) + + expect(response.ok).toBeTruthy() + expect(response.body?.errors).toBeUndefined() + + // + + const ftv1 = response.body?.extensions?.ftv1 + const trace = Trace.decode(Buffer.from(ftv1, 'base64')) + + expectTrace(trace) + expect(trace.root?.error?.length).toBe(0) + + const people = trace.root?.child?.[0] + expect(people?.error?.length).toBe(0) + expectTraceNode(people, 'people', '[Person!]!', 'Query') + + const arr = people!.child! + for (let i = 0; i < arr.length; i++) { + const person = arr[i] + expect(person?.error?.length).toBe(0) + expect(person.index).toBe(i) + expectTraceNode(person.child?.[0], 'name', 'String!', 'Person') + } + }) + it('should contain valid proto tracing details on nested query success', async () => { const response = await request( createYoga({ From f67abd2783fce0c7be4e9173ddf948c621870c86 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 13:05:13 +0200 Subject: [PATCH 16/30] adjust test naming --- .../inline-trace/__tests__/inline-trace.spec.ts | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index c316e2207e..3263e9f1ae 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -96,7 +96,7 @@ describe('Inline Trace', () => { expect(node!.startTime!).toBeLessThan(node!.endTime!) } - it('should contain valid proto tracing details on flat query success', async () => { + it('should have proto tracing on flat query', async () => { const response = await request( createYoga({ schema, @@ -127,7 +127,7 @@ describe('Inline Trace', () => { expectTraceNode(hello, 'hello', 'String!', 'Query') }) - it('should contain valid proto tracing details on aliased flat query success', async () => { + it('should have proto tracing on aliased flat query', async () => { const response = await request( createYoga({ schema, @@ -159,7 +159,7 @@ describe('Inline Trace', () => { expect(hi?.originalFieldName).toBe('hello') }) - it('should contain valid proto tracing details on flat query with array field success', async () => { + it('should have proto tracing on flat query with array field', async () => { const response = await request( createYoga({ schema, @@ -198,7 +198,7 @@ describe('Inline Trace', () => { } }) - it('should contain valid proto tracing details on nested query success', async () => { + it('should have proto tracing on nested query', async () => { const response = await request( createYoga({ schema, @@ -248,7 +248,7 @@ describe('Inline Trace', () => { }).not.toThrow() } - it('should contain valid proto tracing details on parse fail', async () => { + it('should have proto tracing on parse fail', async () => { const response = await request( createYoga({ schema, @@ -274,7 +274,7 @@ describe('Inline Trace', () => { expectTraceNodeError(trace.root) }) - it('should contain valid proto tracing details on validation fail', async () => { + it('should have proto tracing on validation fail', async () => { const response = await request( createYoga({ schema, @@ -300,7 +300,7 @@ describe('Inline Trace', () => { expectTraceNodeError(trace.root) }) - it('should contain valid proto tracing details on execution fail', async () => { + it('should have proto tracing on execution fail', async () => { const response = await request( createYoga({ schema, From 8e53435b726c351bb66ff48be3f51134113505f0 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:16:18 +0200 Subject: [PATCH 17/30] should not trace subscriptions --- .../__tests__/inline-trace.spec.ts | 47 ++++++++++++++++++- 1 file changed, 46 insertions(+), 1 deletion(-) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts index 3263e9f1ae..8511686366 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts @@ -1,8 +1,11 @@ import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' +import { createServer } from 'http' +import { AddressInfo } from 'net' import { useInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' -import { GraphQLError } from 'graphql' +import { ExecutionResult, GraphQLError } from 'graphql' +import EventSource from 'eventsource' describe('Inline Trace', () => { const schema = createSchema({ @@ -13,6 +16,9 @@ describe('Inline Trace', () => { person: Person! people: [Person!]! } + type Subscription { + hello: String! + } type Person { name: String! } @@ -32,6 +38,13 @@ describe('Inline Trace', () => { return [{ name: 'John' }, { name: 'Jane' }] }, }, + Subscription: { + hello: { + async *subscribe() { + yield { hello: 'world' } + }, + }, + }, }, }) @@ -400,6 +413,38 @@ describe('Inline Trace', () => { const errObj = JSON.parse(error[0].json!) expect(errObj.extensions).toEqual({ str: 'ing' }) }) + + it('should not trace subscriptions', async () => { + const server = createServer( + createYoga({ + schema, + plugins: [useInlineTrace()], + }), + ) + + server.listen(0) + const { port } = server.address() as AddressInfo + const url = `http://localhost:${port}/graphql` + + const result = await new Promise((resolve, reject) => { + const eventSource = new EventSource(`${url}?query=subscription{hello}`) + eventSource.onmessage = (e) => { + resolve(JSON.parse(e.data)) + eventSource.close() + } + eventSource.onerror = (e) => { + reject(e) + } + }) + + await new Promise((resolve, reject) => + server.close((err) => (err ? reject(err) : resolve())), + ) + + expect(result.data).toEqual({ hello: 'world' }) + expect(result.errors).toBeUndefined() + expect(result.extensions).toBeUndefined() + }) }) function addSecondsAndNanos(seconds: number, nanos: number): number { From 1be8f5d517de282ef78b640339bb38a456f02301 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:16:41 +0200 Subject: [PATCH 18/30] own tracing --- .../src/apolloTraceTreeBuilder.tsx | 324 ------------------ packages/plugins/inline-trace/src/index.ts | 258 ++++++++++++-- 2 files changed, 228 insertions(+), 354 deletions(-) delete mode 100644 packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx diff --git a/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx b/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx deleted file mode 100644 index 640804dc1c..0000000000 --- a/packages/plugins/inline-trace/src/apolloTraceTreeBuilder.tsx +++ /dev/null @@ -1,324 +0,0 @@ -/** - * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts - */ -import { GraphQLError, GraphQLResolveInfo, ResponsePath } from 'graphql' -import { Trace, google } from 'apollo-reporting-protobuf' -import { YogaLogger } from 'graphql-yoga' - -function internalError(message: string) { - return new Error(`[internal apollo-server error] ${message}`) -} - -export class TraceTreeBuilder { - private rootNode = new Trace.Node() - private logger: YogaLogger = console - public trace = new Trace({ - root: this.rootNode, - // By default, each trace counts as one operation for the sake of field - // execution counts. If we end up calling the fieldLevelInstrumentation - // callback (once we've successfully resolved the operation) then we - // may set this to a higher number; but we'll start it at 1 so that traces - // that don't successfully resolve the operation (eg parse failures) or - // where we don't call the callback because a plugin set captureTraces to - // true have a reasonable default. - fieldExecutionWeight: 1, - }) - public startHrTime?: [number, number] - private stopped = false - private nodes = new Map([ - [responsePathAsString(), this.rootNode], - ]) - private readonly rewriteError?: (err: GraphQLError) => GraphQLError | null - - public constructor(options: { - logger?: YogaLogger - rewriteError?: (err: GraphQLError) => GraphQLError | null - }) { - this.rewriteError = options.rewriteError - if (options.logger) this.logger = options.logger - } - - public startTiming() { - if (this.startHrTime) { - throw internalError('startTiming called twice!') - } - if (this.stopped) { - throw internalError('startTiming called after stopTiming!') - } - this.trace.startTime = dateToProtoTimestamp(new Date()) - this.startHrTime = process.hrtime() - } - - public stopTiming() { - if (!this.startHrTime) { - throw internalError('stopTiming called before startTiming!') - } - if (this.stopped) { - throw internalError('stopTiming called twice!') - } - - this.trace.durationNs = durationHrTimeToNanos( - process.hrtime(this.startHrTime), - ) - this.trace.endTime = dateToProtoTimestamp(new Date()) - this.stopped = true - } - - public willResolveField(info: GraphQLResolveInfo): () => void { - if (!this.startHrTime) { - throw internalError('willResolveField called before startTiming!') - } - if (this.stopped) { - // We've been stopped, which means execution is done... and yet we're - // still resolving more fields? How can that be? Shouldn't we throw an - // error or something? - // - // Well... we used to do exactly that. But this "shouldn't happen" error - // showed up in practice! Turns out that graphql-js can actually continue - // to execute more fields indefinitely long after `execute()` resolves! - // That's because parallelism on a selection set is implemented using - // `Promise.all`, and as soon as one of its arguments (ie, one field) - // throws an error, the combined Promise resolves, but there's no - // "cancellation" of the Promises that are the other arguments to - // `Promise.all`. So the code contributing to those Promises keeps on - // chugging away indefinitely. - // - // Concrete example: let’s say you have - // - // { x y { ARBITRARY_SELECTION_SET } } - // - // where x has a non-null return type, and x and y both have resolvers - // that return Promises. And let’s say that x returns a Promise that - // rejects (or resolves to null). What this means is that we’re going to - // eventually end up with `data: null` (nothing under y will actually - // matter), but graphql-js execution will continue running whatever is - // under ARBITRARY_SELECTION_SET without any sort of short circuiting. In - // fact, the Promise returned from execute itself can happily resolve - // while execution is still chugging away on an arbitrary amount of fields - // under that ARBITRARY_SELECTION_SET. There’s no way to detect from the - // outside "all the execution related to this operation is done", nor to - // "short-circuit" execution so that it stops going. - // - // So, um. We will record any field whose execution we manage to observe - // before we "stop" the TraceTreeBuilder (whether it is one that actually - // ends up in the response or whether it gets thrown away due to null - // bubbling), but if we get any more fields afterwards, we just ignore - // them rather than throwing a confusing error. - // - // (That said, the error we used to throw here generally was hidden - // anyway, for the same reason: it comes from a branch of execution that - // ends up not being included in the response. But - // https://github.com/graphql/graphql-js/pull/3529 means that this - // sometimes crashed execution anyway. Our error never caught any actual - // problematic cases, so keeping it around doesn't really help.) - return () => {} - } - - const path = info.path - const node = this.newNode(path) - node.type = info.returnType.toString() - node.parentType = info.parentType.toString() - node.startTime = durationHrTimeToNanos(process.hrtime(this.startHrTime)) - if (typeof path.key === 'string' && path.key !== info.fieldName) { - // This field was aliased; send the original field name too (for FieldStats). - node.originalFieldName = info.fieldName - } - - return () => { - node.endTime = durationHrTimeToNanos(process.hrtime(this.startHrTime)) - } - } - - public didEncounterErrors(errors: readonly GraphQLError[]) { - errors.forEach((err) => { - // This is an error from a federated service. We will already be reporting - // it in the nested Trace in the query plan. - // - // XXX This probably shouldn't skip query or validation errors, which are - // not in nested Traces because format() isn't called in this case! Or - // maybe format() should be called in that case? - if (err.extensions?.serviceName) { - return - } - - // In terms of reporting, errors can be re-written by the user by - // utilizing the `rewriteError` parameter. This allows changing - // the message or stack to remove potentially sensitive information. - // Returning `null` will result in the error not being reported at all. - const errorForReporting = this.rewriteAndNormalizeError(err) - - if (errorForReporting === null) { - return - } - - this.addProtobufError( - errorForReporting.path, - errorToProtobufError(errorForReporting), - ) - }) - } - - private addProtobufError( - path: ReadonlyArray | undefined, - error: Trace.Error, - ) { - if (!this.startHrTime) { - throw internalError('addProtobufError called before startTiming!') - } - if (this.stopped) { - throw internalError('addProtobufError called after stopTiming!') - } - - // By default, put errors on the root node. - let node = this.rootNode - // If a non-GraphQLError Error sneaks in here somehow with a non-array - // path, don't crash. - if (Array.isArray(path)) { - const specificNode = this.nodes.get(path.join('.')) - if (specificNode) { - node = specificNode - } else { - this.logger.warn( - `Could not find node with path ${path.join( - '.', - )}; defaulting to put errors on root node.`, - ) - } - } - - node.error.push(error) - } - - private newNode(path: ResponsePath): Trace.Node { - const node = new Trace.Node() - const id = path.key - if (typeof id === 'number') { - node.index = id - } else { - node.responseName = id - } - this.nodes.set(responsePathAsString(path), node) - const parentNode = this.ensureParentNode(path) - parentNode.child.push(node) - return node - } - - private ensureParentNode(path: ResponsePath): Trace.Node { - const parentPath = responsePathAsString(path.prev) - const parentNode = this.nodes.get(parentPath) - if (parentNode) { - return parentNode - } - // Because we set up the root path when creating this.nodes, we now know - // that path.prev isn't undefined. - return this.newNode(path.prev!) - } - - private rewriteAndNormalizeError(err: GraphQLError): GraphQLError | null { - if (this.rewriteError) { - // Before passing the error to the user-provided `rewriteError` function, - // we'll make a shadow copy of the error so the user is free to change - // the object as they see fit. - - // At this stage, this error is only for the purposes of reporting, but - // this is even more important since this is still a reference to the - // original error object and changing it would also change the error which - // is returned in the response to the client. - - // For the clone, we'll create a new object which utilizes the exact same - // prototype of the error being reported. - const clonedError = Object.assign( - Object.create(Object.getPrototypeOf(err)), - err, - ) - - const rewrittenError = this.rewriteError(clonedError) - - // Returning an explicit `null` means the user is requesting that the error - // not be reported to Apollo. - if (rewrittenError === null) { - return null - } - - // We don't want users to be inadvertently not reporting errors, so if - // they haven't returned an explicit `GraphQLError` (or `null`, handled - // above), then we'll report the error as usual. - if (!(rewrittenError instanceof GraphQLError)) { - return err - } - - // We only allow rewriteError to change the message and extensions of the - // error; we keep everything else the same. That way people don't have to - // do extra work to keep the error on the same trace node. We also keep - // extensions the same if it isn't explicitly changed (to, eg, {}). (Note - // that many of the fields of GraphQLError are not enumerable and won't - // show up in the trace (even in the json field) anyway.) - return new GraphQLError( - rewrittenError.message, - err.nodes, - err.source, - err.positions, - err.path, - err.originalError, - rewrittenError.extensions || err.extensions, - ) - } - return err - } -} - -// Converts an hrtime array (as returned from process.hrtime) to nanoseconds. -// -// ONLY CALL THIS ON VALUES REPRESENTING DELTAS, NOT ON THE RAW RETURN VALUE -// FROM process.hrtime() WITH NO ARGUMENTS. -// -// The entire point of the hrtime data structure is that the JavaScript Number -// type can't represent all int64 values without loss of precision: -// Number.MAX_SAFE_INTEGER nanoseconds is about 104 days. Calling this function -// on a duration that represents a value less than 104 days is fine. Calling -// this function on an absolute time (which is generally roughly time since -// system boot) is not a good idea. -// -// XXX We should probably use google.protobuf.Duration on the wire instead of -// ever trying to store durations in a single number. -function durationHrTimeToNanos(hrtime: [number, number]) { - return hrtime[0] * 1e9 + hrtime[1] -} - -// Convert from the linked-list ResponsePath format to a dot-joined -// string. Includes the full path (field names and array indices). -function responsePathAsString(p?: ResponsePath): string { - if (p === undefined) { - return '' - } - - // A previous implementation used `responsePathAsArray` from `graphql-js/execution`, - // however, that employed an approach that created new arrays unnecessarily. - let res = String(p.key) - - while ((p = p.prev) !== undefined) { - res = `${p.key}.${res}` - } - - return res -} - -function errorToProtobufError(error: GraphQLError): Trace.Error { - return new Trace.Error({ - message: error.message, - location: (error.locations || []).map( - ({ line, column }) => new Trace.Location({ line, column }), - ), - json: JSON.stringify(error), - }) -} - -// Converts a JS Date into a Timestamp. -export function dateToProtoTimestamp(date: Date): google.protobuf.Timestamp { - const totalMillis = +date - const millis = totalMillis % 1000 - return new google.protobuf.Timestamp({ - seconds: (totalMillis - millis) / 1000, - nanos: millis * 1e6, - }) -} diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index 4ad7e59a77..d30dd75028 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -1,7 +1,21 @@ import { isAsyncIterable, Plugin, YogaInitialContext } from 'graphql-yoga' -import { GraphQLError } from 'graphql' -import { TraceTreeBuilder } from './apolloTraceTreeBuilder' -import { Trace } from 'apollo-reporting-protobuf' +import { GraphQLError, ResponsePath } from 'graphql' +import { google, Trace } from 'apollo-reporting-protobuf' + +interface InlineTraceContext { + startHrTime: [number, number] + rootNode: Trace.Node + trace: Trace + nodes: Map + /** + * graphql-js can continue to execute more fields indefinitely after + * `execute()` resolves. That's because parallelism on a selection set + * is implemented using `Promise.all`, and as soon as one field + * throws an error, the combined Promise resolves, but there's no + * "cancellation" of the rest of Promises/fields in `Promise.all`. + */ + stopped: boolean +} export interface InlineTracePluginOptions { /** @@ -27,11 +41,7 @@ export interface InlineTracePluginOptions { export function useInlineTrace( options: InlineTracePluginOptions = {}, ): Plugin { - interface Context { - treeBuilder: TraceTreeBuilder - } - - const ctxForReq = new WeakMap() + const ctxForReq = new WeakMap() return { onRequest({ request }) { @@ -40,34 +50,72 @@ export function useInlineTrace( return } - const treeBuilder = new TraceTreeBuilder({ - rewriteError: options.rewriteError, + const startHrTime = process.hrtime() + const rootNode = new Trace.Node() + ctxForReq.set(request, { + startHrTime, + rootNode, + trace: new Trace({ + root: rootNode, + fieldExecutionWeight: 1, // Why 1? See: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L16-L23 + startTime: nowTimestamp(), + }), + nodes: new Map([[responsePathToString(), rootNode]]), + stopped: false, }) - - treeBuilder.startTiming() - - ctxForReq.set(request, { treeBuilder }) }, onResolverCalled({ context: { request }, info }) { - return ctxForReq.get(request)?.treeBuilder.willResolveField(info) + const ctx = ctxForReq.get(request) + if (!ctx) return + + // result was already shipped (see InlineTraceContext.stopped) + if (ctx.stopped) { + return () => { + // noop + } + } + + const node = newTraceNode(ctx, info.path) + node.type = info.returnType.toString() + node.parentType = info.parentType.toString() + node.startTime = hrTimeToDurationInNanos(process.hrtime(ctx.startHrTime)) + if ( + typeof info.path.key === 'string' && + info.path.key !== info.fieldName + ) { + // field was aliased, send the original field name too + node.originalFieldName = info.fieldName + } + + return () => { + node.endTime = hrTimeToDurationInNanos(process.hrtime(ctx.startHrTime)) + } }, onParse() { return ({ context: { request }, result }) => { + const ctx = ctxForReq.get(request) + if (!ctx) return + if (result instanceof GraphQLError) { - ctxForReq.get(request)?.treeBuilder.didEncounterErrors([result]) + handleErrors(ctx, [result], options.rewriteError) } else if (result instanceof Error) { - ctxForReq.get(request)?.treeBuilder.didEncounterErrors([ - new GraphQLError(result.message, { - originalError: result, - }), - ]) + handleErrors( + ctx, + [ + new GraphQLError(result.message, { + originalError: result, + }), + ], + options.rewriteError, + ) } } }, onValidate() { return ({ context: { request }, result: errors }) => { if (errors.length) { - ctxForReq.get(request)?.treeBuilder.didEncounterErrors(errors) + const ctx = ctxForReq.get(request) + if (ctx) handleErrors(ctx, errors, options.rewriteError) } } }, @@ -81,28 +129,34 @@ export function useInlineTrace( }) { // TODO: should handle streaming results? how? if (!isAsyncIterable(result) && result.errors?.length) { - ctxForReq - .get(request) - ?.treeBuilder.didEncounterErrors(result.errors) + const ctx = ctxForReq.get(request) + if (ctx) handleErrors(ctx, result.errors, options.rewriteError) } }, } }, // TODO: should track subscription errors? how? onResultProcess({ request, result }) { - const treeBuilder = ctxForReq.get(request)?.treeBuilder - if (!treeBuilder) return + const ctx = ctxForReq.get(request) + if (!ctx) return // TODO: should handle streaming results? how? if (isAsyncIterable(result)) return if (result.extensions?.ftv1 !== undefined) { - throw new Error('The `ftv1` extension was already present.') + throw new Error('The `ftv1` extension is already present') } - treeBuilder.stopTiming() + // onResultProcess will be called only once since we disallow async iterables + if (ctx.stopped) throw new Error('Trace stopped multiple times') + + ctx.stopped = true + ctx.trace.durationNs = hrTimeToDurationInNanos( + process.hrtime(ctx.startHrTime), + ) + ctx.trace.endTime = nowTimestamp() - const encodedUint8Array = Trace.encode(treeBuilder.trace).finish() + const encodedUint8Array = Trace.encode(ctx.trace).finish() const encodedBuffer = Buffer.from( encodedUint8Array, encodedUint8Array.byteOffset, @@ -116,3 +170,147 @@ export function useInlineTrace( }, } } + +/** + * Converts an hrtime array (as returned from process.hrtime) to nanoseconds. + * + * The entire point of the hrtime data structure is that the JavaScript Number + * type can't represent all int64 values without loss of precision. + * + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L269-L285 + */ +function hrTimeToDurationInNanos(hrtime: [number, number]) { + return hrtime[0] * 1e9 + hrtime[1] +} + +/** + * Current time from Date.now() as a google.protobuf.Timestamp. + * + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L315-L323 + */ +function nowTimestamp(): google.protobuf.Timestamp { + const totalMillis = Date.now() + const millis = totalMillis % 1000 + return new google.protobuf.Timestamp({ + seconds: (totalMillis - millis) / 1000, + nanos: millis * 1e6, + }) +} + +/** + * Convert from the linked-list ResponsePath format to a dot-joined + * string. Includes the full path (field names and array indices). + * + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L287-L303 + */ +function responsePathToString(path?: ResponsePath): string { + if (path === undefined) { + return '' + } + + // `responsePathAsArray` from `graphql-js/execution` created new arrays unnecessarily + let res = String(path.key) + + while ((path = path.prev) !== undefined) { + res = `${path.key}.${res}` + } + + return res +} + +function ensureParentTraceNode( + ctx: InlineTraceContext, + path: ResponsePath, +): Trace.Node { + const parentNode = ctx.nodes.get(responsePathToString(path.prev)) + if (parentNode) return parentNode + // path.prev isn't undefined because we set up the root path in ctx.nodes + return newTraceNode(ctx, path.prev!) +} + +function newTraceNode(ctx: InlineTraceContext, path: ResponsePath) { + const node = new Trace.Node() + const id = path.key + if (typeof id === 'number') { + node.index = id + } else { + node.responseName = id + } + ctx.nodes.set(responsePathToString(path), node) + const parentNode = ensureParentTraceNode(ctx, path) + parentNode.child.push(node) + return node +} + +function handleErrors( + ctx: InlineTraceContext, + errors: readonly GraphQLError[], + rewriteError: InlineTracePluginOptions['rewriteError'], +) { + if (ctx.stopped) { + throw new Error('Handling errors after tracing was stopped') + } + + for (const err of errors) { + /** + * This is an error from a federated service. We will already be reporting + * it in the nested Trace in the query plan. + * + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L133-L141 + */ + if (err.extensions?.serviceName) { + continue + } + + let errToReport = err + + // errors can be rewritten through `rewriteError` + if (rewriteError) { + // clone error to avoid users mutating the original one + const clonedErr = Object.assign( + Object.create(Object.getPrototypeOf(err)), + err, + ) + const rewrittenError = rewriteError(clonedErr) + if (!rewrittenError) { + // return nullish to skip reporting + continue + } + errToReport = rewrittenError + } + + // only message and extensions can be rewritten + errToReport = new GraphQLError(errToReport.message, { + extensions: errToReport.extensions || err.extensions, + nodes: err.nodes, + source: err.source, + positions: err.positions, + path: err.path, + originalError: err.originalError, + }) + + // put errors on the root node by default + let node = ctx.rootNode + + if (Array.isArray(errToReport.path)) { + const specificNode = ctx.nodes.get(errToReport.path.join('.')) + if (specificNode) { + node = specificNode + } else { + throw new Error( + `Could not find node with path ${errToReport.path.join('.')}`, + ) + } + } + + node.error.push( + new Trace.Error({ + message: errToReport.message, + location: (errToReport.locations || []).map( + ({ line, column }) => new Trace.Location({ line, column }), + ), + json: JSON.stringify(errToReport), + }), + ) + } +} From 3283157c2973634901b28b6519a930ef60b07313 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:18:33 +0200 Subject: [PATCH 19/30] fix import --- .../persisted-operations/__tests__/persisted-operations.spec.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts b/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts index 0dee629274..f9f319288f 100644 --- a/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts +++ b/packages/plugins/persisted-operations/__tests__/persisted-operations.spec.ts @@ -1,6 +1,6 @@ import { createYoga, createSchema } from 'graphql-yoga' import request from 'supertest' -import { usePersistedOperations } from 'packages/plugins/inline-trace/src' +import { usePersistedOperations } from '@graphql-yoga/plugin-persisted-operations' const schema = createSchema({ typeDefs: /* GraphQL */ ` From 8ee8cc10b0c44416e35e6f23de18b78aa1db5342 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:21:01 +0200 Subject: [PATCH 20/30] changeset --- .changeset/silent-ants-vanish.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/silent-ants-vanish.md diff --git a/.changeset/silent-ants-vanish.md b/.changeset/silent-ants-vanish.md new file mode 100644 index 0000000000..01d9413bdb --- /dev/null +++ b/.changeset/silent-ants-vanish.md @@ -0,0 +1,5 @@ +--- +'@graphql-yoga/inline-trace': major +--- + +Implementation of Apollo's federated inline tracing From 9f8e90cf191fb8284a55a7c4773e4aabbdc93386 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:24:01 +0200 Subject: [PATCH 21/30] adjust docs --- packages/plugins/inline-trace/src/index.ts | 20 +++++++++----------- 1 file changed, 9 insertions(+), 11 deletions(-) diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index d30dd75028..c90e15bd12 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -19,24 +19,22 @@ interface InlineTraceContext { export interface InlineTracePluginOptions { /** - * > By default, all errors from this service get included in the trace. You - * > can specify a filter function to exclude specific errors from being - * > reported by returning an explicit `null`, or you can mask certain details - * > of the error by modifying it and returning the modified error. + * Format errors before being sent for tracing. Beware that only the error + * `message` and `extensions` can be changed. * - * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts + * Return `null` to skip reporting error. */ rewriteError?: (err: GraphQLError) => GraphQLError | null } /** - * > This ftv1 plugin produces a base64'd Trace protobuf containing only the - * > durationNs, startTime, endTime, and root fields. This output is placed - * > on the `extensions`.`ftv1` property of the response. The Apollo Gateway - * > utilizes this data to construct the full trace and submit it to Apollo's - * > usage reporting ingress. + * Produces Apollo's base64 trace protocol containing timing, resolution and + * errors information. * - * https://github.com/apollographql/apollo-server/blob/main/packages/apollo-server-core/src/plugin/inlineTrace/index.ts + * The output is placed in `extensions.ftv1` of the GraphQL result. + * + * The Apollo Gateway utilizes this data to construct the full trace and submit + * it to Apollo's usage reporting ingress. */ export function useInlineTrace( options: InlineTracePluginOptions = {}, From 239f0f1ad45798d00396db61ab89c1bd654c812f Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Thu, 18 Aug 2022 14:27:08 +0200 Subject: [PATCH 22/30] should not handle subscriptions --- packages/plugins/inline-trace/src/index.ts | 1 - 1 file changed, 1 deletion(-) diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/inline-trace/src/index.ts index c90e15bd12..64c2455cdf 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/inline-trace/src/index.ts @@ -133,7 +133,6 @@ export function useInlineTrace( }, } }, - // TODO: should track subscription errors? how? onResultProcess({ request, result }) { const ctx = ctxForReq.get(request) if (!ctx) return From 99a9abbf96bd97b9178e25aa24886bf1bed8ceac Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Fri, 19 Aug 2022 11:24:06 +0200 Subject: [PATCH 23/30] useInlineTrace -> useApolloInlineTrace --- .../__tests__/apollo-inline-trace.spec.ts} | 24 +++++++++---------- .../package.json | 4 ++-- .../src/index.ts | 20 ++++++++-------- 3 files changed, 24 insertions(+), 24 deletions(-) rename packages/plugins/{inline-trace/__tests__/inline-trace.spec.ts => apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts} (95%) rename packages/plugins/{inline-trace => apollo-inline-trace}/package.json (91%) rename packages/plugins/{inline-trace => apollo-inline-trace}/src/index.ts (94%) diff --git a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts similarity index 95% rename from packages/plugins/inline-trace/__tests__/inline-trace.spec.ts rename to packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts index 8511686366..391bafb800 100644 --- a/packages/plugins/inline-trace/__tests__/inline-trace.spec.ts +++ b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts @@ -2,7 +2,7 @@ import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' import { createServer } from 'http' import { AddressInfo } from 'net' -import { useInlineTrace } from '../src' +import { useApolloInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' import { ExecutionResult, GraphQLError } from 'graphql' import EventSource from 'eventsource' @@ -52,7 +52,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -113,7 +113,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -144,7 +144,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -176,7 +176,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -215,7 +215,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -265,7 +265,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -291,7 +291,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -317,7 +317,7 @@ describe('Inline Trace', () => { const response = await request( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) .post('/graphql') @@ -348,7 +348,7 @@ describe('Inline Trace', () => { createYoga({ schema, plugins: [ - useInlineTrace({ + useApolloInlineTrace({ rewriteError: () => null, }), ], @@ -378,7 +378,7 @@ describe('Inline Trace', () => { createYoga({ schema, plugins: [ - useInlineTrace({ + useApolloInlineTrace({ rewriteError: () => new GraphQLError('bim', { extensions: { str: 'ing' } }), }), @@ -418,7 +418,7 @@ describe('Inline Trace', () => { const server = createServer( createYoga({ schema, - plugins: [useInlineTrace()], + plugins: [useApolloInlineTrace()], }), ) diff --git a/packages/plugins/inline-trace/package.json b/packages/plugins/apollo-inline-trace/package.json similarity index 91% rename from packages/plugins/inline-trace/package.json rename to packages/plugins/apollo-inline-trace/package.json index 77021b1e1b..0a6accfc2d 100644 --- a/packages/plugins/inline-trace/package.json +++ b/packages/plugins/apollo-inline-trace/package.json @@ -1,11 +1,11 @@ { - "name": "@graphql-yoga/inline-trace", + "name": "@graphql-yoga/apollo-inline-trace", "version": "0.0.0", "description": "Apollo's federated tracing plugin for GraphQL Yoga.", "repository": { "type": "git", "url": "https://github.com/dotansimha/graphql-yoga.git", - "directory": "packages/plugins/inline-trace" + "directory": "packages/plugins/apollo-inline-trace" }, "type": "module", "main": "dist/cjs/index.js", diff --git a/packages/plugins/inline-trace/src/index.ts b/packages/plugins/apollo-inline-trace/src/index.ts similarity index 94% rename from packages/plugins/inline-trace/src/index.ts rename to packages/plugins/apollo-inline-trace/src/index.ts index 64c2455cdf..928cf4a6a4 100644 --- a/packages/plugins/inline-trace/src/index.ts +++ b/packages/plugins/apollo-inline-trace/src/index.ts @@ -2,7 +2,7 @@ import { isAsyncIterable, Plugin, YogaInitialContext } from 'graphql-yoga' import { GraphQLError, ResponsePath } from 'graphql' import { google, Trace } from 'apollo-reporting-protobuf' -interface InlineTraceContext { +interface ApolloInlineTraceContext { startHrTime: [number, number] rootNode: Trace.Node trace: Trace @@ -17,7 +17,7 @@ interface InlineTraceContext { stopped: boolean } -export interface InlineTracePluginOptions { +export interface ApolloInlineTracePluginOptions { /** * Format errors before being sent for tracing. Beware that only the error * `message` and `extensions` can be changed. @@ -36,10 +36,10 @@ export interface InlineTracePluginOptions { * The Apollo Gateway utilizes this data to construct the full trace and submit * it to Apollo's usage reporting ingress. */ -export function useInlineTrace( - options: InlineTracePluginOptions = {}, +export function useApolloInlineTrace( + options: ApolloInlineTracePluginOptions = {}, ): Plugin { - const ctxForReq = new WeakMap() + const ctxForReq = new WeakMap() return { onRequest({ request }) { @@ -66,7 +66,7 @@ export function useInlineTrace( const ctx = ctxForReq.get(request) if (!ctx) return - // result was already shipped (see InlineTraceContext.stopped) + // result was already shipped (see ApolloInlineTraceContext.stopped) if (ctx.stopped) { return () => { // noop @@ -216,7 +216,7 @@ function responsePathToString(path?: ResponsePath): string { } function ensureParentTraceNode( - ctx: InlineTraceContext, + ctx: ApolloInlineTraceContext, path: ResponsePath, ): Trace.Node { const parentNode = ctx.nodes.get(responsePathToString(path.prev)) @@ -225,7 +225,7 @@ function ensureParentTraceNode( return newTraceNode(ctx, path.prev!) } -function newTraceNode(ctx: InlineTraceContext, path: ResponsePath) { +function newTraceNode(ctx: ApolloInlineTraceContext, path: ResponsePath) { const node = new Trace.Node() const id = path.key if (typeof id === 'number') { @@ -240,9 +240,9 @@ function newTraceNode(ctx: InlineTraceContext, path: ResponsePath) { } function handleErrors( - ctx: InlineTraceContext, + ctx: ApolloInlineTraceContext, errors: readonly GraphQLError[], - rewriteError: InlineTracePluginOptions['rewriteError'], + rewriteError: ApolloInlineTracePluginOptions['rewriteError'], ) { if (ctx.stopped) { throw new Error('Handling errors after tracing was stopped') From 0e0d38c812930c579539199e817bb8dcb8e906a7 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Fri, 19 Aug 2022 11:32:09 +0200 Subject: [PATCH 24/30] adjust changeset --- .changeset/silent-ants-vanish.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.changeset/silent-ants-vanish.md b/.changeset/silent-ants-vanish.md index 01d9413bdb..7ee1148a47 100644 --- a/.changeset/silent-ants-vanish.md +++ b/.changeset/silent-ants-vanish.md @@ -1,5 +1,5 @@ --- -'@graphql-yoga/inline-trace': major +'@graphql-yoga/apollo-inline-trace': major --- Implementation of Apollo's federated inline tracing From 901ce49c786f2899111c6b9eec50e3924b88f602 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Fri, 19 Aug 2022 11:48:51 +0200 Subject: [PATCH 25/30] avoid using buffer --- packages/plugins/apollo-inline-trace/src/index.ts | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/packages/plugins/apollo-inline-trace/src/index.ts b/packages/plugins/apollo-inline-trace/src/index.ts index 928cf4a6a4..965453822a 100644 --- a/packages/plugins/apollo-inline-trace/src/index.ts +++ b/packages/plugins/apollo-inline-trace/src/index.ts @@ -154,15 +154,11 @@ export function useApolloInlineTrace( ctx.trace.endTime = nowTimestamp() const encodedUint8Array = Trace.encode(ctx.trace).finish() - const encodedBuffer = Buffer.from( - encodedUint8Array, - encodedUint8Array.byteOffset, - encodedUint8Array.byteLength, - ) + const base64 = btoa(String.fromCharCode(...encodedUint8Array)) result.extensions = { ...result.extensions, - ftv1: encodedBuffer.toString('base64'), + ftv1: base64, } }, } From ffb60c9bf2635d417cab0562c32e55a4620a4a29 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Fri, 19 Aug 2022 12:05:04 +0200 Subject: [PATCH 26/30] make sure the server closes --- .../__tests__/apollo-inline-trace.spec.ts | 31 ++++++++++--------- 1 file changed, 17 insertions(+), 14 deletions(-) diff --git a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts index 391bafb800..bb68f60015 100644 --- a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts +++ b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts @@ -426,20 +426,23 @@ describe('Inline Trace', () => { const { port } = server.address() as AddressInfo const url = `http://localhost:${port}/graphql` - const result = await new Promise((resolve, reject) => { - const eventSource = new EventSource(`${url}?query=subscription{hello}`) - eventSource.onmessage = (e) => { - resolve(JSON.parse(e.data)) - eventSource.close() - } - eventSource.onerror = (e) => { - reject(e) - } - }) - - await new Promise((resolve, reject) => - server.close((err) => (err ? reject(err) : resolve())), - ) + let result + try { + result = await new Promise((resolve, reject) => { + const eventSource = new EventSource(`${url}?query=subscription{hello}`) + eventSource.onmessage = (e) => { + resolve(JSON.parse(e.data)) + eventSource.close() + } + eventSource.onerror = (e) => { + reject(e) + } + }) + } finally { + await new Promise((resolve, reject) => + server.close((err) => (err ? reject(err) : resolve())), + ) + } expect(result.data).toEqual({ hello: 'world' }) expect(result.errors).toBeUndefined() From ccceb274577e32c3992f68691d2575ecc44e3f31 Mon Sep 17 00:00:00 2001 From: enisdenjo Date: Fri, 19 Aug 2022 13:00:54 +0200 Subject: [PATCH 27/30] federated tracing example --- .../v3/docs/features/apollo-federation.mdx | 31 +++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/website/v3/docs/features/apollo-federation.mdx b/website/v3/docs/features/apollo-federation.mdx index 6f04405a4e..d4ac41287a 100644 --- a/website/v3/docs/features/apollo-federation.mdx +++ b/website/v3/docs/features/apollo-federation.mdx @@ -107,6 +107,37 @@ server.listen(4001, () => { }) ``` +## Federated tracing + +Inject additional metrics for [Apollo's federated tracing](https://www.apollographql.com/docs/federation/metrics/). + +You'll need the `@graphql-yoga/apollo-inline-trace` Yoga plugin for this. + +### Installation + + + +### Example Federated tracing + +```ts +import { createYoga } from 'graphql-yoga' +import { createServer } from 'http' +import { useApolloInlineTrace } from '@graphql-yoga/apollo-inline-trace' + +const yoga = createYoga({ + plugins: [ + useApolloInlineTrace(), + // ...rest of your Apollo federation plugins + ], +}) + +// Start the server and explore http://localhost:4000/graphql +const server = createServer(yoga) +server.listen(4000) +``` + ## Working Example Check our [working example](https://github.com/dotansimha/graphql-yoga/tree/master/examples/apollo-federation) to try it out. From 8dc8e1d5ea154aaadedf8777ed4698101dac2437 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 22 Aug 2022 14:49:24 +0300 Subject: [PATCH 28/30] Use yoga.fetch and fix ESM support --- .../__tests__/apollo-inline-trace.spec.ts | 372 ++++++++++-------- .../plugins/apollo-inline-trace/src/index.ts | 29 +- 2 files changed, 213 insertions(+), 188 deletions(-) diff --git a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts index bb68f60015..878d22b806 100644 --- a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts +++ b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts @@ -1,11 +1,7 @@ -import request from 'supertest' import { createYoga, createSchema } from 'graphql-yoga' -import { createServer } from 'http' -import { AddressInfo } from 'net' import { useApolloInlineTrace } from '../src' import { Trace } from 'apollo-reporting-protobuf' -import { ExecutionResult, GraphQLError } from 'graphql' -import EventSource from 'eventsource' +import { GraphQLError } from 'graphql' describe('Inline Trace', () => { const schema = createSchema({ @@ -48,24 +44,70 @@ describe('Inline Trace', () => { }, }) + const yoga = createYoga({ + schema, + plugins: [useApolloInlineTrace()], + }) + + const FlatQuery = /* GraphQL */ ` + query FlatQuery { + hello + } + ` + const AliasedFlatQuery = /* GraphQL */ ` + query AliasedFlatQuery { + hi: hello + } + ` + const FlatQueryWithArrayField = /* GraphQL */ ` + query FlatQueryWithArrayField { + people { + name + } + } + ` + + const NestedQuery = /* GraphQL */ ` + query NestedQuery { + person { + name + } + } + ` + const BrokenQuery = `{ he` + + const FailingQuery = /* GraphQL */ ` + query FailingQuery { + boom + } + ` + + const InvalidQuery = /* GraphQL */ ` + query InvalidQuery { + henlo + } + ` + + const FlatSubscription = /* GraphQL */ ` + subscription FlatSubscription { + hello + } + ` it('should add ftv1 tracing to result extensions', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], - }), - ) - .post('/graphql') - .set({ + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ query: FlatQuery }), + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ hello }', - }) + }, + }) + + const result = await response.json() expect(response.ok).toBeTruthy() - expect(response.body?.errors).toBeUndefined() - expect(response.body?.extensions?.ftv1).toBeDefined() + expect(result?.errors).toBeUndefined() + expect(result?.extensions?.ftv1).toBeDefined() }) function expectTrace(trace: Trace) { @@ -110,26 +152,23 @@ describe('Inline Trace', () => { } it('should have proto tracing on flat query', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], - }), - ) - .post('/graphql') - .set({ + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ query: FlatQuery }), + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ hello }', - }) + }, + }) + + const result = await response.json() expect(response.ok).toBeTruthy() - expect(response.body?.errors).toBeUndefined() + expect(result?.errors).toBeUndefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -141,26 +180,25 @@ describe('Inline Trace', () => { }) it('should have proto tracing on aliased flat query', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: AliasedFlatQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ hi: hello }', - }) + }, + }) + + const result = await response.json() expect(response.ok).toBeTruthy() - expect(response.body?.errors).toBeUndefined() + expect(result?.errors).toBeUndefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -173,26 +211,25 @@ describe('Inline Trace', () => { }) it('should have proto tracing on flat query with array field', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: FlatQueryWithArrayField, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ people { name } }', - }) + }, + }) + + const result = await response.json() expect(response.ok).toBeTruthy() - expect(response.body?.errors).toBeUndefined() + expect(result?.errors).toBeUndefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -212,26 +249,25 @@ describe('Inline Trace', () => { }) it('should have proto tracing on nested query', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: NestedQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ person { name } }', - }) + }, + }) expect(response.ok).toBeTruthy() - expect(response.body?.errors).toBeUndefined() + + const result = await response.json() + expect(result?.errors).toBeUndefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -262,25 +298,24 @@ describe('Inline Trace', () => { } it('should have proto tracing on parse fail', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: BrokenQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ he', - }) + }, + }) + + const result = await response.json() - expect(response.body?.errors).toBeDefined() + expect(result?.errors).toBeDefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -288,25 +323,24 @@ describe('Inline Trace', () => { }) it('should have proto tracing on validation fail', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: InvalidQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ henlo }', - }) + }, + }) + + const result = await response.json() - expect(response.body?.errors).toBeDefined() + expect(result?.errors).toBeDefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -314,25 +348,24 @@ describe('Inline Trace', () => { }) it('should have proto tracing on execution fail', async () => { - const response = await request( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: FailingQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ boom }', - }) + }, + }) + + const result = await response.json() - expect(response.body?.errors).toBeDefined() + expect(result?.errors).toBeDefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -344,29 +377,33 @@ describe('Inline Trace', () => { }) it('should skip tracing errors through rewriteError', async () => { - const response = await request( - createYoga({ - schema, - plugins: [ - useApolloInlineTrace({ - rewriteError: () => null, - }), - ], + const yoga = createYoga({ + schema, + plugins: [ + useApolloInlineTrace({ + rewriteError: () => null, + }), + ], + }) + + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: BrokenQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ he', - }) + }, + }) + + const result = await response.json() - expect(response.body?.errors).toBeDefined() + expect(result?.errors).toBeDefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -374,30 +411,34 @@ describe('Inline Trace', () => { }) it('should rewrite only error messages and extensions through rewriteError', async () => { - const response = await request( - createYoga({ - schema, - plugins: [ - useApolloInlineTrace({ - rewriteError: () => - new GraphQLError('bim', { extensions: { str: 'ing' } }), - }), - ], + const yoga = createYoga({ + schema, + plugins: [ + useApolloInlineTrace({ + rewriteError: () => + new GraphQLError('bim', { extensions: { str: 'ing' } }), + }), + ], + }) + + const response = await yoga.fetch('http://yoga/graphql', { + method: 'POST', + body: JSON.stringify({ + query: FailingQuery, }), - ) - .post('/graphql') - .set({ + headers: { + 'Content-Type': 'application/json', 'apollo-federation-include-trace': 'ftv1', - }) - .send({ - query: '{ boom }', - }) + }, + }) + + const result = await response.json() - expect(response.body?.errors).toBeDefined() + expect(result?.errors).toBeDefined() // - const ftv1 = response.body?.extensions?.ftv1 + const ftv1 = result?.extensions?.ftv1 const trace = Trace.decode(Buffer.from(ftv1, 'base64')) expectTrace(trace) @@ -415,38 +456,19 @@ describe('Inline Trace', () => { }) it('should not trace subscriptions', async () => { - const server = createServer( - createYoga({ - schema, - plugins: [useApolloInlineTrace()], - }), + const response = await yoga.fetch( + 'http://yoga/graphql?query=' + encodeURIComponent('subscription{hello}'), + { + headers: { + Accept: 'text/event-stream', + }, + }, ) - server.listen(0) - const { port } = server.address() as AddressInfo - const url = `http://localhost:${port}/graphql` - - let result - try { - result = await new Promise((resolve, reject) => { - const eventSource = new EventSource(`${url}?query=subscription{hello}`) - eventSource.onmessage = (e) => { - resolve(JSON.parse(e.data)) - eventSource.close() - } - eventSource.onerror = (e) => { - reject(e) - } - }) - } finally { - await new Promise((resolve, reject) => - server.close((err) => (err ? reject(err) : resolve())), - ) - } + expect(response.ok).toBe(true) - expect(result.data).toEqual({ hello: 'world' }) - expect(result.errors).toBeUndefined() - expect(result.extensions).toBeUndefined() + const result = await response.text() + expect(result).toBe('data: {"data":{"hello":"world"}}\n\n') }) }) diff --git a/packages/plugins/apollo-inline-trace/src/index.ts b/packages/plugins/apollo-inline-trace/src/index.ts index 965453822a..e3940f2740 100644 --- a/packages/plugins/apollo-inline-trace/src/index.ts +++ b/packages/plugins/apollo-inline-trace/src/index.ts @@ -1,12 +1,12 @@ import { isAsyncIterable, Plugin, YogaInitialContext } from 'graphql-yoga' import { GraphQLError, ResponsePath } from 'graphql' -import { google, Trace } from 'apollo-reporting-protobuf' +import ApolloReportingProtobuf from 'apollo-reporting-protobuf' interface ApolloInlineTraceContext { startHrTime: [number, number] - rootNode: Trace.Node - trace: Trace - nodes: Map + rootNode: ApolloReportingProtobuf.Trace.Node + trace: ApolloReportingProtobuf.Trace + nodes: Map /** * graphql-js can continue to execute more fields indefinitely after * `execute()` resolves. That's because parallelism on a selection set @@ -49,11 +49,11 @@ export function useApolloInlineTrace( } const startHrTime = process.hrtime() - const rootNode = new Trace.Node() + const rootNode = new ApolloReportingProtobuf.Trace.Node() ctxForReq.set(request, { startHrTime, rootNode, - trace: new Trace({ + trace: new ApolloReportingProtobuf.Trace({ root: rootNode, fieldExecutionWeight: 1, // Why 1? See: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L16-L23 startTime: nowTimestamp(), @@ -153,7 +153,9 @@ export function useApolloInlineTrace( ) ctx.trace.endTime = nowTimestamp() - const encodedUint8Array = Trace.encode(ctx.trace).finish() + const encodedUint8Array = ApolloReportingProtobuf.Trace.encode( + ctx.trace, + ).finish() const base64 = btoa(String.fromCharCode(...encodedUint8Array)) result.extensions = { @@ -181,10 +183,10 @@ function hrTimeToDurationInNanos(hrtime: [number, number]) { * * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L315-L323 */ -function nowTimestamp(): google.protobuf.Timestamp { +function nowTimestamp(): ApolloReportingProtobuf.google.protobuf.Timestamp { const totalMillis = Date.now() const millis = totalMillis % 1000 - return new google.protobuf.Timestamp({ + return new ApolloReportingProtobuf.google.protobuf.Timestamp({ seconds: (totalMillis - millis) / 1000, nanos: millis * 1e6, }) @@ -214,7 +216,7 @@ function responsePathToString(path?: ResponsePath): string { function ensureParentTraceNode( ctx: ApolloInlineTraceContext, path: ResponsePath, -): Trace.Node { +): ApolloReportingProtobuf.Trace.Node { const parentNode = ctx.nodes.get(responsePathToString(path.prev)) if (parentNode) return parentNode // path.prev isn't undefined because we set up the root path in ctx.nodes @@ -222,7 +224,7 @@ function ensureParentTraceNode( } function newTraceNode(ctx: ApolloInlineTraceContext, path: ResponsePath) { - const node = new Trace.Node() + const node = new ApolloReportingProtobuf.Trace.Node() const id = path.key if (typeof id === 'number') { node.index = id @@ -297,10 +299,11 @@ function handleErrors( } node.error.push( - new Trace.Error({ + new ApolloReportingProtobuf.Trace.Error({ message: errToReport.message, location: (errToReport.locations || []).map( - ({ line, column }) => new Trace.Location({ line, column }), + ({ line, column }) => + new ApolloReportingProtobuf.Trace.Location({ line, column }), ), json: JSON.stringify(errToReport), }), From 066dd3eae6ee251bd9c6d3dbfd453d1463cce8e4 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 22 Aug 2022 15:47:22 +0300 Subject: [PATCH 29/30] Fix tests and use btoa from ponyfill for Node 14 --- package.json | 2 +- packages/graphql-yoga/src/server.ts | 3 ++- .../__tests__/apollo-inline-trace.spec.ts | 13 +++++++++---- packages/plugins/apollo-inline-trace/package.json | 3 ++- packages/plugins/apollo-inline-trace/src/index.ts | 1 + yarn.lock | 8 ++++---- 6 files changed, 19 insertions(+), 11 deletions(-) diff --git a/package.json b/package.json index ac70c52871..74e111d0af 100644 --- a/package.json +++ b/package.json @@ -91,7 +91,7 @@ "weak-napi": "" }, "resolutions": { - "@whatwg-node/fetch": "0.2.9", + "@whatwg-node/fetch": "0.3.2", "@changesets/apply-release-plan": "6.0.0", "graphql": "16.6.0", "@types/react": "17.0.39", diff --git a/packages/graphql-yoga/src/server.ts b/packages/graphql-yoga/src/server.ts index 01fb2fd284..b62dbb4f83 100644 --- a/packages/graphql-yoga/src/server.ts +++ b/packages/graphql-yoga/src/server.ts @@ -509,7 +509,8 @@ export class YogaServer< }) } return response - } catch (e) { + } catch (e: any) { + this.logger.error(e) return new this.fetchAPI.Response('Internal Server Error', { status: 500, }) diff --git a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts index 878d22b806..5dc834e6c5 100644 --- a/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts +++ b/packages/plugins/apollo-inline-trace/__tests__/apollo-inline-trace.spec.ts @@ -21,16 +21,20 @@ describe('Inline Trace', () => { `, resolvers: { Query: { - hello() { + async hello() { + await new Promise((resolve) => setTimeout(resolve, 100)) return 'world' }, - boom() { + async boom() { + await new Promise((resolve) => setTimeout(resolve, 100)) throw new Error('bam') }, - person() { + async person() { + await new Promise((resolve) => setTimeout(resolve, 100)) return { name: 'John' } }, - people() { + async people() { + await new Promise((resolve) => setTimeout(resolve, 100)) return [{ name: 'John' }, { name: 'Jane' }] }, }, @@ -47,6 +51,7 @@ describe('Inline Trace', () => { const yoga = createYoga({ schema, plugins: [useApolloInlineTrace()], + maskedErrors: false, }) const FlatQuery = /* GraphQL */ ` diff --git a/packages/plugins/apollo-inline-trace/package.json b/packages/plugins/apollo-inline-trace/package.json index 0a6accfc2d..473185624a 100644 --- a/packages/plugins/apollo-inline-trace/package.json +++ b/packages/plugins/apollo-inline-trace/package.json @@ -41,7 +41,8 @@ "access": "public" }, "peerDependencies": { - "graphql-yoga": "^3.0.0" + "graphql-yoga": "^3.0.0", + "@whatwg-node/fetch": "^0.3.2" }, "dependencies": { "apollo-reporting-protobuf": "^3.3.2" diff --git a/packages/plugins/apollo-inline-trace/src/index.ts b/packages/plugins/apollo-inline-trace/src/index.ts index e3940f2740..4fece481f9 100644 --- a/packages/plugins/apollo-inline-trace/src/index.ts +++ b/packages/plugins/apollo-inline-trace/src/index.ts @@ -1,6 +1,7 @@ import { isAsyncIterable, Plugin, YogaInitialContext } from 'graphql-yoga' import { GraphQLError, ResponsePath } from 'graphql' import ApolloReportingProtobuf from 'apollo-reporting-protobuf' +import { btoa } from '@whatwg-node/fetch' interface ApolloInlineTraceContext { startHrTime: [number, number] diff --git a/yarn.lock b/yarn.lock index bed6554aac..ea50dabec7 100644 --- a/yarn.lock +++ b/yarn.lock @@ -6520,10 +6520,10 @@ "@webassemblyjs/ast" "1.11.1" "@xtuc/long" "4.2.2" -"@whatwg-node/fetch@0.2.9", "@whatwg-node/fetch@^0.2.3", "@whatwg-node/fetch@^0.2.9": - version "0.2.9" - resolved "https://registry.yarnpkg.com/@whatwg-node/fetch/-/fetch-0.2.9.tgz#0f0e72f79957a0544d2a9455082802d87be93ffe" - integrity sha512-h+ehuqE/ZqJdRy+xywHyKpBIPmST0ms8Itgf4gGSu10pJrmod3/t9DbG/GlATvLBE4pvqYHrxKAKo3NNQVJc3g== +"@whatwg-node/fetch@0.3.2", "@whatwg-node/fetch@^0.2.3", "@whatwg-node/fetch@^0.2.9": + version "0.3.2" + resolved "https://registry.yarnpkg.com/@whatwg-node/fetch/-/fetch-0.3.2.tgz#da4323795c26c135563ba01d49dc16037bec4287" + integrity sha512-Bs5zAWQs0tXsLa4mRmLw7Psps1EN78vPtgcLpw3qPY8s6UYPUM67zFZ9cy+7tZ64PXhfwzxJn+m7RH2Lq48RNQ== dependencies: "@peculiar/webcrypto" "^1.4.0" abort-controller "^3.0.0" From 9397decbeadf4d00d18c20a6745334c4d0e706e5 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 22 Aug 2022 15:55:42 +0300 Subject: [PATCH 30/30] Fix package name --- .changeset/silent-ants-vanish.md | 2 +- packages/plugins/apollo-inline-trace/package.json | 2 +- website/v3/docs/features/apollo-federation.mdx | 10 +++++++--- 3 files changed, 9 insertions(+), 5 deletions(-) diff --git a/.changeset/silent-ants-vanish.md b/.changeset/silent-ants-vanish.md index 7ee1148a47..803cc36826 100644 --- a/.changeset/silent-ants-vanish.md +++ b/.changeset/silent-ants-vanish.md @@ -1,5 +1,5 @@ --- -'@graphql-yoga/apollo-inline-trace': major +'@graphql-yoga/plugin-apollo-inline-trace': major --- Implementation of Apollo's federated inline tracing diff --git a/packages/plugins/apollo-inline-trace/package.json b/packages/plugins/apollo-inline-trace/package.json index 473185624a..f87f43bf73 100644 --- a/packages/plugins/apollo-inline-trace/package.json +++ b/packages/plugins/apollo-inline-trace/package.json @@ -1,5 +1,5 @@ { - "name": "@graphql-yoga/apollo-inline-trace", + "name": "@graphql-yoga/plugin-apollo-inline-trace", "version": "0.0.0", "description": "Apollo's federated tracing plugin for GraphQL Yoga.", "repository": { diff --git a/website/v3/docs/features/apollo-federation.mdx b/website/v3/docs/features/apollo-federation.mdx index d4ac41287a..93e22a4a70 100644 --- a/website/v3/docs/features/apollo-federation.mdx +++ b/website/v3/docs/features/apollo-federation.mdx @@ -111,12 +111,16 @@ server.listen(4001, () => { Inject additional metrics for [Apollo's federated tracing](https://www.apollographql.com/docs/federation/metrics/). -You'll need the `@graphql-yoga/apollo-inline-trace` Yoga plugin for this. +You'll need the `@graphql-yoga/plugin-apollo-inline-trace` Yoga plugin for this. ### Installation ### Example Federated tracing @@ -124,7 +128,7 @@ You'll need the `@graphql-yoga/apollo-inline-trace` Yoga plugin for this. ```ts import { createYoga } from 'graphql-yoga' import { createServer } from 'http' -import { useApolloInlineTrace } from '@graphql-yoga/apollo-inline-trace' +import { useApolloInlineTrace } from '@graphql-yoga/plugin-apollo-inline-trace' const yoga = createYoga({ plugins: [