|
| 1 | +import { isAsyncIterable, Plugin } from '@envelop/core'; |
| 2 | +import { GraphQLError, ResponsePath } from 'graphql'; |
| 3 | +import { google, Trace } from 'apollo-reporting-protobuf'; |
| 4 | + |
| 5 | +interface ApolloInlineTracer { |
| 6 | + startHrTime: [number, number]; |
| 7 | + rootNode: Trace.Node; |
| 8 | + trace: Trace; |
| 9 | + nodes: Map<string, Trace.Node>; |
| 10 | + /** |
| 11 | + * graphql-js can continue to execute more fields indefinitely after |
| 12 | + * `execute()` resolves. That's because parallelism on a selection set |
| 13 | + * is implemented using `Promise.all`, and as soon as one field |
| 14 | + * throws an error, the combined Promise resolves, but there's no |
| 15 | + * "cancellation" of the rest of Promises/fields in `Promise.all`. |
| 16 | + */ |
| 17 | + stopped: boolean; |
| 18 | +} |
| 19 | + |
| 20 | +export interface ApolloInlineTracePluginOptions<PluginContext extends Record<string, any> = {}> { |
| 21 | + /** |
| 22 | + * Decide whether the operation should be traced. |
| 23 | + * |
| 24 | + * When dealing with HTTP requests, `apollo-federation-include-trace` header must be set to `ftv1`. |
| 25 | + */ |
| 26 | + shouldTrace(ctx: PluginContext): boolean; |
| 27 | + /** |
| 28 | + * Format errors before being sent for tracing. Beware that only the error |
| 29 | + * `message` and `extensions` can be changed. |
| 30 | + * |
| 31 | + * Return `null` to skip reporting error. |
| 32 | + */ |
| 33 | + rewriteError?: (err: GraphQLError) => GraphQLError | null; |
| 34 | +} |
| 35 | + |
| 36 | +/** |
| 37 | + * Produces Apollo's base64 trace protocol containing timing, resolution and |
| 38 | + * errors information. |
| 39 | + * |
| 40 | + * The output is placed in `extensions.ftv1` of the GraphQL result. |
| 41 | + * |
| 42 | + * The Apollo Gateway utilizes this data to construct the full trace and submit |
| 43 | + * it to Apollo's usage reporting ingress. |
| 44 | + */ |
| 45 | +export function useApolloInlineTrace<PluginContext extends Record<string, any> = {}>({ |
| 46 | + shouldTrace, |
| 47 | + rewriteError, |
| 48 | +}: ApolloInlineTracePluginOptions<PluginContext>): Plugin<PluginContext> { |
| 49 | + const tracerForCtx = new WeakMap<PluginContext, ApolloInlineTracer>(); |
| 50 | + return { |
| 51 | + onEnveloped({ context }) { |
| 52 | + if (!context) { |
| 53 | + throw new Error("Context must be set for Apollo's inline tracing plugin"); |
| 54 | + } |
| 55 | + |
| 56 | + if (shouldTrace(context)) { |
| 57 | + const startHrTime = process.hrtime(); |
| 58 | + const rootNode = new Trace.Node(); |
| 59 | + tracerForCtx.set(context, { |
| 60 | + startHrTime, |
| 61 | + rootNode, |
| 62 | + trace: new Trace({ |
| 63 | + root: rootNode, |
| 64 | + fieldExecutionWeight: 1, // Why 1? See: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L16-L23 |
| 65 | + startTime: nowTimestamp(), |
| 66 | + }), |
| 67 | + nodes: new Map([[responsePathToString(), rootNode]]), |
| 68 | + stopped: false, |
| 69 | + }); |
| 70 | + } |
| 71 | + }, |
| 72 | + onResolverCalled({ context, info }) { |
| 73 | + const tracer = tracerForCtx.get(context); |
| 74 | + if (!tracer) return; |
| 75 | + |
| 76 | + // result was already shipped (see ApolloInlineTracer.stopped) |
| 77 | + if (tracer.stopped) { |
| 78 | + return () => { |
| 79 | + // noop |
| 80 | + }; |
| 81 | + } |
| 82 | + |
| 83 | + const node = newTraceNode(tracer, info.path); |
| 84 | + node.type = info.returnType.toString(); |
| 85 | + node.parentType = info.parentType.toString(); |
| 86 | + node.startTime = hrTimeToDurationInNanos(process.hrtime(tracer.startHrTime)); |
| 87 | + if (typeof info.path.key === 'string' && info.path.key !== info.fieldName) { |
| 88 | + // field was aliased, send the original field name too |
| 89 | + node.originalFieldName = info.fieldName; |
| 90 | + } |
| 91 | + |
| 92 | + return () => { |
| 93 | + node.endTime = hrTimeToDurationInNanos(process.hrtime(tracer.startHrTime)); |
| 94 | + }; |
| 95 | + }, |
| 96 | + onParse() { |
| 97 | + return ({ context, result }) => { |
| 98 | + const tracer = tracerForCtx.get(context); |
| 99 | + if (!tracer) return; |
| 100 | + |
| 101 | + if (result instanceof GraphQLError) { |
| 102 | + handleErrors(tracer, [result], rewriteError); |
| 103 | + } else if (result instanceof Error) { |
| 104 | + handleErrors( |
| 105 | + tracer, |
| 106 | + [ |
| 107 | + new GraphQLError(result.message, { |
| 108 | + originalError: result, |
| 109 | + }), |
| 110 | + ], |
| 111 | + rewriteError |
| 112 | + ); |
| 113 | + } |
| 114 | + }; |
| 115 | + }, |
| 116 | + onValidate() { |
| 117 | + return ({ context, result: errors }) => { |
| 118 | + if (errors.length) { |
| 119 | + const tracer = tracerForCtx.get(context); |
| 120 | + if (tracer) handleErrors(tracer, errors, rewriteError); |
| 121 | + } |
| 122 | + }; |
| 123 | + }, |
| 124 | + onExecute() { |
| 125 | + return { |
| 126 | + onExecuteDone({ args: { contextValue }, result, setResult }) { |
| 127 | + const tracer = tracerForCtx.get(contextValue); |
| 128 | + if (!tracer) return; |
| 129 | + |
| 130 | + // TODO: should handle streaming results? how? |
| 131 | + if (isAsyncIterable(result)) return; |
| 132 | + |
| 133 | + if (result.extensions?.ftv1 !== undefined) { |
| 134 | + throw new Error('The `ftv1` extension is already present'); |
| 135 | + } |
| 136 | + |
| 137 | + if (result.errors?.length) { |
| 138 | + handleErrors(tracer, result.errors, rewriteError); |
| 139 | + } |
| 140 | + |
| 141 | + // onResultProcess will be called only once since we disallow async iterables |
| 142 | + if (tracer.stopped) throw new Error('Trace stopped multiple times'); |
| 143 | + |
| 144 | + tracer.stopped = true; |
| 145 | + tracer.trace.durationNs = hrTimeToDurationInNanos(process.hrtime(tracer.startHrTime)); |
| 146 | + tracer.trace.endTime = nowTimestamp(); |
| 147 | + |
| 148 | + const encodedUint8Array = Trace.encode(tracer.trace).finish(); |
| 149 | + const encodedBuffer = Buffer.from( |
| 150 | + encodedUint8Array, |
| 151 | + encodedUint8Array.byteOffset, |
| 152 | + encodedUint8Array.byteLength |
| 153 | + ); |
| 154 | + |
| 155 | + result.extensions = { |
| 156 | + ...result.extensions, |
| 157 | + ftv1: encodedBuffer.toString('base64'), |
| 158 | + }; |
| 159 | + |
| 160 | + setResult(result); |
| 161 | + }, |
| 162 | + }; |
| 163 | + }, |
| 164 | + }; |
| 165 | +} |
| 166 | + |
| 167 | +/** |
| 168 | + * Converts an hrtime array (as returned from process.hrtime) to nanoseconds. |
| 169 | + * |
| 170 | + * The entire point of the hrtime data structure is that the JavaScript Number |
| 171 | + * type can't represent all int64 values without loss of precision. |
| 172 | + * |
| 173 | + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L269-L285 |
| 174 | + */ |
| 175 | +function hrTimeToDurationInNanos(hrtime: [number, number]) { |
| 176 | + return hrtime[0] * 1e9 + hrtime[1]; |
| 177 | +} |
| 178 | + |
| 179 | +/** |
| 180 | + * Current time from Date.now() as a google.protobuf.Timestamp. |
| 181 | + * |
| 182 | + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L315-L323 |
| 183 | + */ |
| 184 | +function nowTimestamp(): google.protobuf.Timestamp { |
| 185 | + const totalMillis = Date.now(); |
| 186 | + const millis = totalMillis % 1000; |
| 187 | + return new google.protobuf.Timestamp({ |
| 188 | + seconds: (totalMillis - millis) / 1000, |
| 189 | + nanos: millis * 1e6, |
| 190 | + }); |
| 191 | +} |
| 192 | + |
| 193 | +/** |
| 194 | + * Convert from the linked-list ResponsePath format to a dot-joined |
| 195 | + * string. Includes the full path (field names and array indices). |
| 196 | + * |
| 197 | + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L287-L303 |
| 198 | + */ |
| 199 | +function responsePathToString(path?: ResponsePath): string { |
| 200 | + if (path === undefined) { |
| 201 | + return ''; |
| 202 | + } |
| 203 | + |
| 204 | + // `responsePathAsArray` from `graphql-js/execution` created new arrays unnecessarily |
| 205 | + let res = String(path.key); |
| 206 | + |
| 207 | + while ((path = path.prev) !== undefined) { |
| 208 | + res = `${path.key}.${res}`; |
| 209 | + } |
| 210 | + |
| 211 | + return res; |
| 212 | +} |
| 213 | + |
| 214 | +function ensureParentTraceNode(ctx: ApolloInlineTracer, path: ResponsePath): Trace.Node { |
| 215 | + const parentNode = ctx.nodes.get(responsePathToString(path.prev)); |
| 216 | + if (parentNode) return parentNode; |
| 217 | + // path.prev isn't undefined because we set up the root path in ctx.nodes |
| 218 | + return newTraceNode(ctx, path.prev!); |
| 219 | +} |
| 220 | + |
| 221 | +function newTraceNode(ctx: ApolloInlineTracer, path: ResponsePath) { |
| 222 | + const node = new Trace.Node(); |
| 223 | + const id = path.key; |
| 224 | + if (typeof id === 'number') { |
| 225 | + node.index = id; |
| 226 | + } else { |
| 227 | + node.responseName = id; |
| 228 | + } |
| 229 | + ctx.nodes.set(responsePathToString(path), node); |
| 230 | + const parentNode = ensureParentTraceNode(ctx, path); |
| 231 | + parentNode.child.push(node); |
| 232 | + return node; |
| 233 | +} |
| 234 | + |
| 235 | +function handleErrors( |
| 236 | + ctx: ApolloInlineTracer, |
| 237 | + errors: readonly GraphQLError[], |
| 238 | + rewriteError: ApolloInlineTracePluginOptions['rewriteError'] |
| 239 | +) { |
| 240 | + if (ctx.stopped) { |
| 241 | + throw new Error('Handling errors after tracing was stopped'); |
| 242 | + } |
| 243 | + |
| 244 | + for (const err of errors) { |
| 245 | + /** |
| 246 | + * This is an error from a federated service. We will already be reporting |
| 247 | + * it in the nested Trace in the query plan. |
| 248 | + * |
| 249 | + * Reference: https://github.com/apollographql/apollo-server/blob/9389da785567a56e989430962564afc71e93bd7f/packages/apollo-server-core/src/plugin/traceTreeBuilder.ts#L133-L141 |
| 250 | + */ |
| 251 | + if (err.extensions?.serviceName) { |
| 252 | + continue; |
| 253 | + } |
| 254 | + |
| 255 | + let errToReport = err; |
| 256 | + |
| 257 | + // errors can be rewritten through `rewriteError` |
| 258 | + if (rewriteError) { |
| 259 | + // clone error to avoid users mutating the original one |
| 260 | + const clonedErr = Object.assign(Object.create(Object.getPrototypeOf(err)), err); |
| 261 | + const rewrittenError = rewriteError(clonedErr); |
| 262 | + if (!rewrittenError) { |
| 263 | + // return nullish to skip reporting |
| 264 | + continue; |
| 265 | + } |
| 266 | + errToReport = rewrittenError; |
| 267 | + } |
| 268 | + |
| 269 | + // only message and extensions can be rewritten |
| 270 | + errToReport = new GraphQLError(errToReport.message, { |
| 271 | + extensions: errToReport.extensions || err.extensions, |
| 272 | + nodes: err.nodes, |
| 273 | + source: err.source, |
| 274 | + positions: err.positions, |
| 275 | + path: err.path, |
| 276 | + originalError: err.originalError, |
| 277 | + }); |
| 278 | + |
| 279 | + // put errors on the root node by default |
| 280 | + let node = ctx.rootNode; |
| 281 | + |
| 282 | + if (Array.isArray(errToReport.path)) { |
| 283 | + const specificNode = ctx.nodes.get(errToReport.path.join('.')); |
| 284 | + if (specificNode) { |
| 285 | + node = specificNode; |
| 286 | + } else { |
| 287 | + throw new Error(`Could not find node with path ${errToReport.path.join('.')}`); |
| 288 | + } |
| 289 | + } |
| 290 | + |
| 291 | + node.error.push( |
| 292 | + new Trace.Error({ |
| 293 | + message: errToReport.message, |
| 294 | + location: (errToReport.locations || []).map(({ line, column }) => new Trace.Location({ line, column })), |
| 295 | + json: JSON.stringify(errToReport), |
| 296 | + }) |
| 297 | + ); |
| 298 | + } |
| 299 | +} |
0 commit comments