diff --git a/CHANGELOG.md b/CHANGELOG.md index b7e9cc29be6..81a41745010 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,11 @@ The version headers in this history reflect the versions of Apollo Server itself > The changes noted within this `vNEXT` section have not been released yet. New PRs and commits which introduce changes should include an entry in this `vNEXT` section as part of their development. When a release is being prepared, a new header will be (manually) created below and the appropriate changes within that release will be moved into the new section. +- `apollo-engine-reporting`: The underlying integration of this plugin, which instruments and traces the graph's resolver performance and transmits these metrics to [Apollo Graph Manager](https://engine.apollographql.com/), has been changed from the (soon to be deprecated) `graphql-extensions` API to the new [request pipeline `plugins` API](https://www.apollographql.com/docs/apollo-server/integrations/plugins/). [PR #3998](https://github.com/apollographql/apollo-server/pull/3998) + + _This change should be purely an implementation detail for a majority of users_. There are, however, some special considerations which are worth noting: + + - The federated tracing plugin's `ftv1` response on `extensions` (which is present on the response from an implementing service to the gateway) is now placed on the `extensions` _after_ the `formatResponse` hook. Anyone leveraging the `extensions`.`ftv1` data from the `formatResponse` hook will find that it is no longer present at that phase. - `apollo-tracing`: This package's internal integration with Apollo Server has been switched from using the soon-to-be-deprecated`graphql-extensions` API to using [the request pipeline plugin API](https://www.apollographql.com/docs/apollo-server/integrations/plugins/). Behavior should remain otherwise the same. [PR #3991](https://github.com/apollographql/apollo-server/pull/3991) ### v2.13.0 diff --git a/package-lock.json b/package-lock.json index 94e3dfbdbe9..eff11b7b2ed 100644 --- a/package-lock.json +++ b/package-lock.json @@ -5654,9 +5654,9 @@ "apollo-server-caching": "file:packages/apollo-server-caching", "apollo-server-env": "file:packages/apollo-server-env", "apollo-server-errors": "file:packages/apollo-server-errors", + "apollo-server-plugin-base": "file:packages/apollo-server-plugin-base", "apollo-server-types": "file:packages/apollo-server-types", - "async-retry": "^1.2.1", - "graphql-extensions": "file:packages/graphql-extensions" + "async-retry": "^1.2.1" } }, "apollo-engine-reporting-protobuf": { diff --git a/packages/apollo-engine-reporting/package.json b/packages/apollo-engine-reporting/package.json index 90cc7285aca..d8d3be3fc01 100644 --- a/packages/apollo-engine-reporting/package.json +++ b/packages/apollo-engine-reporting/package.json @@ -18,7 +18,7 @@ "apollo-server-errors": "file:../apollo-server-errors", "apollo-server-types": "file:../apollo-server-types", "async-retry": "^1.2.1", - "graphql-extensions": "file:../graphql-extensions" + "apollo-server-plugin-base": "file:../apollo-server-plugin-base" }, "peerDependencies": { "graphql": "^0.12.0 || ^0.13.0 || ^14.0.0 || ^15.0.0" diff --git a/packages/apollo-engine-reporting/src/__tests__/extension.test.ts b/packages/apollo-engine-reporting/src/__tests__/plugin.test.ts similarity index 92% rename from packages/apollo-engine-reporting/src/__tests__/extension.test.ts rename to packages/apollo-engine-reporting/src/__tests__/plugin.test.ts index 14b50c73cfd..2a8d3313b12 100644 --- a/packages/apollo-engine-reporting/src/__tests__/extension.test.ts +++ b/packages/apollo-engine-reporting/src/__tests__/plugin.test.ts @@ -1,19 +1,11 @@ import { makeExecutableSchema, addMockFunctionsToSchema } from 'graphql-tools'; -import { - GraphQLExtensionStack, - enableGraphQLExtensions, -} from 'graphql-extensions'; import { graphql, GraphQLError } from 'graphql'; import { Request } from 'node-fetch'; -import { - EngineReportingExtension, - makeTraceDetails, - makeHTTPRequestHeaders, -} from '../extension'; +import { makeTraceDetails, makeHTTPRequestHeaders, plugin } from '../plugin'; import { Headers } from 'apollo-server-env'; -import { InMemoryLRUCache } from 'apollo-server-caching'; import { AddTraceArgs } from '../agent'; import { Trace } from 'apollo-engine-reporting-protobuf'; +import pluginTestHarness from 'apollo-server-core/dist/utils/pluginTestHarness'; it('trace construction', async () => { const typeDefs = ` @@ -53,41 +45,33 @@ it('trace construction', async () => { const schema = makeExecutableSchema({ typeDefs }); addMockFunctionsToSchema({ schema }); - enableGraphQLExtensions(schema); const traces: Array = []; async function addTrace(args: AddTraceArgs) { traces.push(args); } - const reportingExtension = new EngineReportingExtension( - {}, - addTrace, - 'schema-hash', - ); - const stack = new GraphQLExtensionStack([reportingExtension]); - const requestDidEnd = stack.requestDidStart({ - request: new Request('http://localhost:123/foo'), - queryString: query, - requestContext: { - request: { - query, - operationName: 'q', - extensions: { - clientName: 'testing suite', - }, + const pluginInstance = plugin({ /* no options!*/ }, addTrace); + + pluginTestHarness({ + pluginInstance, + schema, + graphqlRequest: { + query, + operationName: 'q', + extensions: { + clientName: 'testing suite', }, - context: {}, - cache: new InMemoryLRUCache(), + http: new Request('http://localhost:123/foo'), + }, + executor: async ({ request: { query: source }}) => { + return await graphql({ + schema, + source, + }); }, - context: {}, - }); - await graphql({ - schema, - source: query, - contextValue: { _extensionStack: stack }, }); - requestDidEnd(); + // XXX actually write some tests }); diff --git a/packages/apollo-engine-reporting/src/agent.ts b/packages/apollo-engine-reporting/src/agent.ts index efb84a4d1a8..c7e6a28d083 100644 --- a/packages/apollo-engine-reporting/src/agent.ts +++ b/packages/apollo-engine-reporting/src/agent.ts @@ -11,10 +11,11 @@ import { import { fetch, RequestAgent, Response } from 'apollo-server-env'; import retry from 'async-retry'; -import { EngineReportingExtension } from './extension'; +import { plugin } from './plugin'; import { GraphQLRequestContext, Logger, SchemaHash } from 'apollo-server-types'; import { InMemoryLRUCache } from 'apollo-server-caching'; import { defaultEngineReportingSignature } from 'apollo-graphql'; +import { ApolloServerPlugin } from "apollo-server-plugin-base"; let warnedOnDeprecatedApiKey = false; @@ -251,8 +252,8 @@ export interface AddTraceArgs { operationName: string; queryHash: string; schemaHash: SchemaHash; - queryString?: string; - documentAST?: DocumentNode; + source?: string; + document?: DocumentNode; } const serviceHeaderDefaults = { @@ -328,20 +329,16 @@ export class EngineReportingAgent { handleLegacyOptions(this.options); } - public newExtension(schemaHash: SchemaHash): EngineReportingExtension { - return new EngineReportingExtension( - this.options, - this.addTrace.bind(this), - schemaHash, - ); + public newPlugin(): ApolloServerPlugin { + return plugin(this.options, this.addTrace.bind(this)); } public async addTrace({ trace, queryHash, - documentAST, + document, operationName, - queryString, + source, schemaHash, }: AddTraceArgs): Promise { // Ignore traces that come in after stop(). @@ -368,8 +365,8 @@ export class EngineReportingAgent { const signature = await this.getTraceSignature({ queryHash, - documentAST, - queryString, + document, + source, operationName, }); @@ -534,17 +531,17 @@ export class EngineReportingAgent { private async getTraceSignature({ queryHash, operationName, - documentAST, - queryString, + document, + source, }: { queryHash: string; operationName: string; - documentAST?: DocumentNode; - queryString?: string; + document?: DocumentNode; + source?: string; }): Promise { - if (!documentAST && !queryString) { + if (!document && !source) { // This shouldn't happen: one of those options must be passed to runQuery. - throw new Error('No queryString or documentAST?'); + throw new Error('No document or source?'); } const cacheKey = signatureCacheKey(queryHash, operationName); @@ -559,7 +556,7 @@ export class EngineReportingAgent { return cachedSignature; } - if (!documentAST) { + if (!document) { // We didn't get an AST, possibly because of a parse failure. Let's just // use the full query string. // @@ -567,12 +564,12 @@ export class EngineReportingAgent { // hides literals, you might end up sending literals for queries // that fail parsing or validation. Provide some way to mask them // anyway? - return queryString as string; + return source as string; } const generatedSignature = ( this.options.calculateSignature || defaultEngineReportingSignature - )(documentAST, operationName); + )(document, operationName); // Intentionally not awaited so the cache can be written to at leisure. this.signatureCache.set(cacheKey, generatedSignature); diff --git a/packages/apollo-engine-reporting/src/extension.ts b/packages/apollo-engine-reporting/src/extension.ts deleted file mode 100644 index 1b88527d5ad..00000000000 --- a/packages/apollo-engine-reporting/src/extension.ts +++ /dev/null @@ -1,374 +0,0 @@ -import { - GraphQLRequestContext, - WithRequired, - Logger, - SchemaHash, -} from 'apollo-server-types'; -import { Request, Headers } from 'apollo-server-env'; -import { - GraphQLResolveInfo, - DocumentNode, - ExecutionArgs, - GraphQLError, -} from 'graphql'; -import { GraphQLExtension, EndHandler } from 'graphql-extensions'; -import { Trace } from 'apollo-engine-reporting-protobuf'; - -import { - EngineReportingOptions, - GenerateClientInfo, - AddTraceArgs, - VariableValueOptions, - SendValuesBaseOptions, -} from './agent'; -import { EngineReportingTreeBuilder } from './treeBuilder'; - -const clientNameHeaderKey = 'apollographql-client-name'; -const clientReferenceIdHeaderKey = 'apollographql-client-reference-id'; -const clientVersionHeaderKey = 'apollographql-client-version'; - -// EngineReportingExtension is the per-request GraphQLExtension which creates a -// trace (in protobuf Trace format) for a single request. When the request is -// done, it passes the Trace back to its associated EngineReportingAgent via the -// addTrace callback in its constructor. This class isn't for direct use; its -// constructor is a private API for communicating with EngineReportingAgent. -// Its public methods all implement the GraphQLExtension interface. -export class EngineReportingExtension - implements GraphQLExtension { - private logger: Logger = console; - private treeBuilder: EngineReportingTreeBuilder; - private explicitOperationName?: string | null; - private queryString?: string; - private documentAST?: DocumentNode; - private options: EngineReportingOptions; - private addTrace: (args: AddTraceArgs) => Promise; - private generateClientInfo: GenerateClientInfo; - - public constructor( - options: EngineReportingOptions, - addTrace: (args: AddTraceArgs) => Promise, - private schemaHash: SchemaHash, - ) { - this.options = { - ...options, - }; - if (options.logger) this.logger = options.logger; - this.addTrace = addTrace; - this.generateClientInfo = - options.generateClientInfo || defaultGenerateClientInfo; - - this.treeBuilder = new EngineReportingTreeBuilder({ - rewriteError: options.rewriteError, - logger: this.logger, - }); - } - - public requestDidStart(o: { - request: Request; - queryString?: string; - parsedQuery?: DocumentNode; - variables?: Record; - context: TContext; - extensions?: Record; - requestContext: WithRequired< - GraphQLRequestContext, - 'metrics' | 'queryHash' - >; - }): EndHandler { - this.treeBuilder.startTiming(); - o.requestContext.metrics.startHrTime = this.treeBuilder.startHrTime; - - // Generally, we'll get queryString here and not parsedQuery; we only get - // parsedQuery if you're using an OperationStore. In normal cases we'll get - // our documentAST in the execution callback after it is parsed. - const queryHash = o.requestContext.queryHash; - this.queryString = o.queryString; - this.documentAST = o.parsedQuery; - - this.treeBuilder.trace.http = new Trace.HTTP({ - method: - Trace.HTTP.Method[o.request.method as keyof typeof Trace.HTTP.Method] || - Trace.HTTP.Method.UNKNOWN, - // Host and path are not used anywhere on the backend, so let's not bother - // trying to parse request.url to get them, which is a potential - // source of bugs because integrations have different behavior here. - // On Node's HTTP module, request.url only includes the path - // (see https://nodejs.org/api/http.html#http_message_url) - // The same is true on Lambda (where we pass event.path) - // But on environments like Cloudflare we do get a complete URL. - host: null, - path: null, - }); - - if (this.options.sendHeaders) { - makeHTTPRequestHeaders( - this.treeBuilder.trace.http, - o.request.headers, - this.options.sendHeaders, - ); - } - - if (o.requestContext.metrics.persistedQueryHit) { - this.treeBuilder.trace.persistedQueryHit = true; - } - if (o.requestContext.metrics.persistedQueryRegister) { - this.treeBuilder.trace.persistedQueryRegister = true; - } - - if (o.variables) { - this.treeBuilder.trace.details = makeTraceDetails( - o.variables, - this.options.sendVariableValues, - o.queryString, - ); - } - - const clientInfo = this.generateClientInfo(o.requestContext); - if (clientInfo) { - // While clientAddress could be a part of the protobuf, we'll ignore it for - // now, since the backend does not group by it and Engine frontend will not - // support it in the short term - const { clientName, clientVersion, clientReferenceId } = clientInfo; - // the backend makes the choice of mapping clientName => clientReferenceId if - // no custom reference id is provided - this.treeBuilder.trace.clientVersion = clientVersion || ''; - this.treeBuilder.trace.clientReferenceId = clientReferenceId || ''; - this.treeBuilder.trace.clientName = clientName || ''; - } - - return () => { - this.treeBuilder.stopTiming(); - - this.treeBuilder.trace.fullQueryCacheHit = !!o.requestContext.metrics - .responseCacheHit; - this.treeBuilder.trace.forbiddenOperation = !!o.requestContext.metrics - .forbiddenOperation; - this.treeBuilder.trace.registeredOperation = !!o.requestContext.metrics - .registeredOperation; - - // If the user did not explicitly specify an operation name (which we - // would have saved in `executionDidStart`), but the request pipeline made - // it far enough to figure out what the operation name must be and store - // it on requestContext.operationName, use that name. (Note that this - // depends on the assumption that the RequestContext passed to - // requestDidStart, which does not yet have operationName, will be mutated - // to add operationName later.) - const operationName = - this.explicitOperationName || o.requestContext.operationName || ''; - const documentAST = this.documentAST || o.requestContext.document; - - // If this was a federated operation and we're the gateway, add the query plan - // to the trace. - if (o.requestContext.metrics.queryPlanTrace) { - this.treeBuilder.trace.queryPlan = - o.requestContext.metrics.queryPlanTrace; - } - - this.addTrace({ - operationName, - queryHash, - documentAST, - queryString: this.queryString || '', - trace: this.treeBuilder.trace, - schemaHash: this.schemaHash, - }); - }; - } - - public executionDidStart(o: { executionArgs: ExecutionArgs }) { - // If the operationName is explicitly provided, save it. Note: this is the - // operationName provided by the user. It might be empty if they're relying on - // the "just use the only operation I sent" behavior, even if that operation - // has a name. - // - // It's possible that execution is about to fail because this operation - // isn't actually in the document. We want to know the name in that case - // too, which is why it's important that we save the name now, and not just - // rely on requestContext.operationName (which will be null in this case). - if (o.executionArgs.operationName) { - this.explicitOperationName = o.executionArgs.operationName; - } - this.documentAST = o.executionArgs.document; - } - - public willResolveField( - _source: any, - _args: { [argName: string]: any }, - _context: TContext, - info: GraphQLResolveInfo, - ): ((error: Error | null, result: any) => void) | void { - return this.treeBuilder.willResolveField(info); - // We could save the error into the trace during the end handler, but it - // won't have all the information that graphql-js adds to it later, like - // 'locations'. - } - - public didEncounterErrors(errors: GraphQLError[]) { - this.treeBuilder.didEncounterErrors(errors); - } -} - -// Helpers for producing traces. - -function defaultGenerateClientInfo({ request }: GraphQLRequestContext) { - // Default to using the `apollo-client-x` header fields if present. - // If none are present, fallback on the `clientInfo` query extension - // for backwards compatibility. - // The default value if neither header values nor query extension is - // set is the empty String for all fields (as per protobuf defaults) - if ( - request.http && - request.http.headers && - (request.http.headers.get(clientNameHeaderKey) || - request.http.headers.get(clientVersionHeaderKey) || - request.http.headers.get(clientReferenceIdHeaderKey)) - ) { - return { - clientName: request.http.headers.get(clientNameHeaderKey), - clientVersion: request.http.headers.get(clientVersionHeaderKey), - clientReferenceId: request.http.headers.get(clientReferenceIdHeaderKey), - }; - } else if (request.extensions && request.extensions.clientInfo) { - return request.extensions.clientInfo; - } else { - return {}; - } -} - -// Creates trace details from request variables, given a specification for modifying -// values of private or sensitive variables. -// The details will include all variable names and their (possibly hidden or modified) values. -// If sendVariableValues is {all: bool}, {none: bool} or {exceptNames: Array}, the option will act similarly to -// to the to-be-deprecated options.privateVariables, except that the redacted variable -// names will still be visible in the UI even if the values are hidden. -// If sendVariableValues is null or undefined, we default to the {none: true} case. -export function makeTraceDetails( - variables: Record, - sendVariableValues?: VariableValueOptions, - operationString?: string, -): Trace.Details { - const details = new Trace.Details(); - const variablesToRecord = (() => { - if (sendVariableValues && 'transform' in sendVariableValues) { - const originalKeys = Object.keys(variables); - try { - // Custom function to allow user to specify what variablesJson will look like - const modifiedVariables = sendVariableValues.transform({ - variables: variables, - operationString: operationString, - }); - return cleanModifiedVariables(originalKeys, modifiedVariables); - } catch (e) { - // If the custom function provided by the user throws an exception, - // change all the variable values to an appropriate error message. - return handleVariableValueTransformError(originalKeys); - } - } else { - return variables; - } - })(); - - // Note: we explicitly do *not* include the details.rawQuery field. The - // Engine web app currently does nothing with this other than store it in - // the database and offer it up via its GraphQL API, and sending it means - // that using calculateSignature to hide sensitive data in the query - // string is ineffective. - Object.keys(variablesToRecord).forEach(name => { - if ( - !sendVariableValues || - ('none' in sendVariableValues && sendVariableValues.none) || - ('all' in sendVariableValues && !sendVariableValues.all) || - ('exceptNames' in sendVariableValues && - // We assume that most users will have only a few variables values to hide, - // or will just set {none: true}; we can change this - // linear-time operation if it causes real performance issues. - sendVariableValues.exceptNames.includes(name)) || - ('onlyNames' in sendVariableValues && - !sendVariableValues.onlyNames.includes(name)) - ) { - // Special case for private variables. Note that this is a different - // representation from a variable containing the empty string, as that - // will be sent as '""'. - details.variablesJson![name] = ''; - } else { - try { - details.variablesJson![name] = - typeof variablesToRecord[name] === 'undefined' - ? '' - : JSON.stringify(variablesToRecord[name]); - } catch (e) { - details.variablesJson![name] = JSON.stringify( - '[Unable to convert value to JSON]', - ); - } - } - }); - return details; -} - -function handleVariableValueTransformError( - variableNames: string[], -): Record { - const modifiedVariables = Object.create(null); - variableNames.forEach(name => { - modifiedVariables[name] = '[PREDICATE_FUNCTION_ERROR]'; - }); - return modifiedVariables; -} - -// Helper for makeTraceDetails() to enforce that the keys of a modified 'variables' -// matches that of the original 'variables' -function cleanModifiedVariables( - originalKeys: Array, - modifiedVariables: Record, -): Record { - const cleanedVariables: Record = Object.create(null); - originalKeys.forEach(name => { - cleanedVariables[name] = modifiedVariables[name]; - }); - return cleanedVariables; -} - -export function makeHTTPRequestHeaders( - http: Trace.IHTTP, - headers: Headers, - sendHeaders?: SendValuesBaseOptions, -): void { - if ( - !sendHeaders || - ('none' in sendHeaders && sendHeaders.none) || - ('all' in sendHeaders && !sendHeaders.all) - ) { - return; - } - for (const [key, value] of headers) { - const lowerCaseKey = key.toLowerCase(); - if ( - ('exceptNames' in sendHeaders && - // We assume that most users only have a few headers to hide, or will - // just set {none: true} ; we can change this linear-time - // operation if it causes real performance issues. - sendHeaders.exceptNames.some(exceptHeader => { - // Headers are case-insensitive, and should be compared as such. - return exceptHeader.toLowerCase() === lowerCaseKey; - })) || - ('onlyNames' in sendHeaders && - !sendHeaders.onlyNames.some(header => { - return header.toLowerCase() === lowerCaseKey; - })) - ) { - continue; - } - - switch (key) { - case 'authorization': - case 'cookie': - case 'set-cookie': - break; - default: - http!.requestHeaders![key] = new Trace.HTTP.Values({ - value: [value], - }); - } - } -} diff --git a/packages/apollo-engine-reporting/src/federatedExtension.ts b/packages/apollo-engine-reporting/src/federatedExtension.ts deleted file mode 100644 index 711c95fbf6e..00000000000 --- a/packages/apollo-engine-reporting/src/federatedExtension.ts +++ /dev/null @@ -1,85 +0,0 @@ -import { GraphQLResolveInfo, GraphQLError } from 'graphql'; -import { GraphQLExtension } from 'graphql-extensions'; -import { Trace } from 'apollo-engine-reporting-protobuf'; -import { GraphQLRequestContext } from 'apollo-server-types'; - -import { EngineReportingTreeBuilder } from './treeBuilder'; - -export class EngineFederatedTracingExtension - implements GraphQLExtension { - private enabled = false; - private done = false; - private treeBuilder: EngineReportingTreeBuilder; - - public constructor(options: { - rewriteError?: (err: GraphQLError) => GraphQLError | null; - }) { - this.treeBuilder = new EngineReportingTreeBuilder({ - rewriteError: options.rewriteError, - }); - } - - public requestDidStart(o: { - requestContext: GraphQLRequestContext; - }) { - // XXX Provide a mechanism to customize this logic. - const http = o.requestContext.request.http; - if ( - http && - http.headers.get('apollo-federation-include-trace') === 'ftv1' - ) { - this.enabled = true; - } - - if (this.enabled) { - this.treeBuilder.startTiming(); - } - } - - public willResolveField( - _source: any, - _args: { [argName: string]: any }, - _context: TContext, - info: GraphQLResolveInfo, - ): ((error: Error | null, result: any) => void) | void { - if (this.enabled) { - return this.treeBuilder.willResolveField(info); - } - } - - public didEncounterErrors(errors: GraphQLError[]) { - if (this.enabled) { - this.treeBuilder.didEncounterErrors(errors); - } - } - - // The ftv1 extension is a base64'd Trace protobuf containing only the - // durationNs, startTime, endTime, and root fields. - // - // Note: format() is only called after executing an operation, and - // specifically isn't called for parse or validation errors. Parse and validation - // errors in a federated backend will get reported to the end user as a downstream - // error but will not get reported to Engine (because Engine filters out downstream - // errors)! See #3091. - public format(): [string, string] | undefined { - if (!this.enabled) { - return; - } - if (this.done) { - throw Error('format called twice?'); - } - - // We record the end time at the latest possible time: right before serializing the trace. - // If we wait any longer, the time we record won't actually be sent anywhere! - this.treeBuilder.stopTiming(); - this.done = true; - - const encodedUint8Array = Trace.encode(this.treeBuilder.trace).finish(); - const encodedBuffer = Buffer.from( - encodedUint8Array, - encodedUint8Array.byteOffset, - encodedUint8Array.byteLength, - ); - return ['ftv1', encodedBuffer.toString('base64')]; - } -} diff --git a/packages/apollo-engine-reporting/src/federatedPlugin.ts b/packages/apollo-engine-reporting/src/federatedPlugin.ts new file mode 100644 index 00000000000..ce2a5580668 --- /dev/null +++ b/packages/apollo-engine-reporting/src/federatedPlugin.ts @@ -0,0 +1,69 @@ +import { Trace } from 'apollo-engine-reporting-protobuf'; +import { EngineReportingTreeBuilder } from './treeBuilder'; +import { ApolloServerPlugin } from "apollo-server-plugin-base"; +import { EngineReportingOptions } from "./agent"; + +type FederatedReportingOptions = Pick, 'rewriteError'> + +// 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 +// Graph Manager ingress. +const federatedPlugin = ( + options: FederatedReportingOptions = Object.create(null), +): ApolloServerPlugin => { + return { + requestDidStart({ request: { http } }) { + const treeBuilder: EngineReportingTreeBuilder = + new EngineReportingTreeBuilder({ + rewriteError: options.rewriteError, + }); + + // XXX Provide a mechanism to customize this logic. + if (http?.headers.get('apollo-federation-include-trace') !== 'ftv1') { + return; + } + + treeBuilder.startTiming(); + + return { + executionDidStart: () => ({ + willResolveField({ info }) { + return treeBuilder.willResolveField(info); + }, + }), + + didEncounterErrors({ errors }) { + treeBuilder.didEncounterErrors(errors); + }, + + willSendResponse({ response }) { + // We record the end time at the latest possible time: right before serializing the trace. + // If we wait any longer, the time we record won't actually be sent anywhere! + treeBuilder.stopTiming(); + + const encodedUint8Array = Trace.encode(treeBuilder.trace).finish(); + const encodedBuffer = Buffer.from( + encodedUint8Array, + encodedUint8Array.byteOffset, + encodedUint8Array.byteLength, + ); + + const extensions = + response.extensions || (response.extensions = Object.create(null)); + + // This should only happen if another plugin is using the same name- + // space within the `extensions` object and got to it before us. + if (typeof extensions.ftv1 !== "undefined") { + throw new Error("The `ftv1` extension was already present."); + } + + extensions.ftv1 = encodedBuffer.toString('base64'); + } + } + }, + } +}; + +export default federatedPlugin; diff --git a/packages/apollo-engine-reporting/src/index.ts b/packages/apollo-engine-reporting/src/index.ts index 5770edf02c3..82b73e73ad9 100644 --- a/packages/apollo-engine-reporting/src/index.ts +++ b/packages/apollo-engine-reporting/src/index.ts @@ -1,2 +1,2 @@ export { EngineReportingOptions, EngineReportingAgent } from './agent'; -export { EngineFederatedTracingExtension } from './federatedExtension'; +export { default as federatedPlugin } from './federatedPlugin'; diff --git a/packages/apollo-engine-reporting/src/plugin.ts b/packages/apollo-engine-reporting/src/plugin.ts new file mode 100644 index 00000000000..84ead380e19 --- /dev/null +++ b/packages/apollo-engine-reporting/src/plugin.ts @@ -0,0 +1,360 @@ +import { + GraphQLRequestContext, + Logger, + GraphQLRequestContextExecutionDidStart, + GraphQLRequestContextDidEncounterErrors, +} from 'apollo-server-types'; +import { Headers } from 'apollo-server-env'; +import { Trace } from 'apollo-engine-reporting-protobuf'; + +import { + EngineReportingOptions, + GenerateClientInfo, + AddTraceArgs, + VariableValueOptions, + SendValuesBaseOptions, +} from './agent'; +import { EngineReportingTreeBuilder } from './treeBuilder'; +import { ApolloServerPlugin } from "apollo-server-plugin-base"; + +const clientNameHeaderKey = 'apollographql-client-name'; +const clientReferenceIdHeaderKey = 'apollographql-client-reference-id'; +const clientVersionHeaderKey = 'apollographql-client-version'; + +// This plugin is instantiated once at server start-up. Each request that the +// server processes will invoke the `requestDidStart` method which will produce +// a trace (in protobuf Trace format) for that single request. When the request +// is done, it passes the Trace back to its associated EngineReportingAgent via +// the addTrace callback. This class isn't for direct use; its constructor is a +// private API for communicating with EngineReportingAgent. +export const plugin = ( + options: EngineReportingOptions = Object.create(null), + addTrace: (args: AddTraceArgs) => Promise, + // schemaHash: string, +): ApolloServerPlugin => { + const logger: Logger = options.logger || console; + const generateClientInfo: GenerateClientInfo = + options.generateClientInfo || defaultGenerateClientInfo; + + + return { + requestDidStart({ + logger: requestLogger, + schemaHash, + metrics, + request: { http, variables }, + }) { + const treeBuilder: EngineReportingTreeBuilder = new EngineReportingTreeBuilder( + { + rewriteError: options.rewriteError, + logger: requestLogger || logger, + }, + ); + + treeBuilder.startTiming(); + + metrics.startHrTime = treeBuilder.startHrTime; + + if (http) { + treeBuilder.trace.http = new Trace.HTTP({ + method: + Trace.HTTP.Method[http.method as keyof typeof Trace.HTTP.Method] || + Trace.HTTP.Method.UNKNOWN, + // Host and path are not used anywhere on the backend, so let's not bother + // trying to parse request.url to get them, which is a potential + // source of bugs because integrations have different behavior here. + // On Node's HTTP module, request.url only includes the path + // (see https://nodejs.org/api/http.html#http_message_url) + // The same is true on Lambda (where we pass event.path) + // But on environments like Cloudflare we do get a complete URL. + host: null, + path: null, + }); + + if (options.sendHeaders) { + makeHTTPRequestHeaders( + treeBuilder.trace.http, + http.headers, + options.sendHeaders, + ); + } + } + + let endDone: boolean = false; + function didEnd( + requestContext: + | GraphQLRequestContextExecutionDidStart + | GraphQLRequestContextDidEncounterErrors, + ) { + if (endDone) return; + endDone = true; + treeBuilder.stopTiming(); + + treeBuilder.trace.fullQueryCacheHit = !!metrics.responseCacheHit; + treeBuilder.trace.forbiddenOperation = !!metrics.forbiddenOperation; + treeBuilder.trace.registeredOperation = !!metrics.registeredOperation; + + // If operation resolution (parsing and validating the document followed + // by selecting the correct operation) resulted in the population of the + // `operationName`, we'll use that. (For anonymous operations, + // `requestContext.operationName` is null, which we represent here as + // the empty string.) + // + // If the user explicitly specified an `operationName` in their request + // but operation resolution failed (due to parse or validation errors or + // because there is no operation with that name in the document), we + // still put _that_ user-supplied `operationName` in the trace. This + // allows the error to be better understood in Graph Manager. (We are + // considering changing the behavior of `operationName` in these 3 error + // cases; https://github.com/apollographql/apollo-server/pull/3465) + const operationName = + requestContext.operationName || + requestContext.request.operationName || + ''; + + // If this was a federated operation and we're the gateway, add the query plan + // to the trace. + if (metrics.queryPlanTrace) { + treeBuilder.trace.queryPlan = metrics.queryPlanTrace; + } + + addTrace({ + operationName, + queryHash: requestContext.queryHash!, + document: requestContext.document, + source: requestContext.source, + trace: treeBuilder.trace, + schemaHash, + }); + } + + // While we start the tracing as soon as possible, we only actually report + // traces when we have resolved the source. This is largely because of + // the APQ negotiation that takes place before that resolution happens. + // This is effectively bypassing the reporting of: + // - PersistedQueryNotFoundError + // - PersistedQueryNotSupportedError + // - InvalidGraphQLRequestError + let didResolveSource: boolean = false; + + return { + didResolveSource(requestContext) { + didResolveSource = true; + + if (metrics.persistedQueryHit) { + treeBuilder.trace.persistedQueryHit = true; + } + if (metrics.persistedQueryRegister) { + treeBuilder.trace.persistedQueryRegister = true; + } + + if (variables) { + treeBuilder.trace.details = makeTraceDetails( + variables, + options.sendVariableValues, + requestContext.source, + ); + } + + const clientInfo = generateClientInfo(requestContext); + if (clientInfo) { + // While clientAddress could be a part of the protobuf, we'll ignore + // it for now, since the backend does not group by it and Graph + // Manager will not support it in the short term + const { clientName, clientVersion, clientReferenceId } = clientInfo; + // the backend makes the choice of mapping clientName => clientReferenceId if + // no custom reference id is provided + treeBuilder.trace.clientVersion = clientVersion || ''; + treeBuilder.trace.clientReferenceId = clientReferenceId || ''; + treeBuilder.trace.clientName = clientName || ''; + } + }, + + executionDidStart(requestContext) { + return { + executionDidEnd: () => didEnd(requestContext), + willResolveField({ info }) { + return treeBuilder.willResolveField(info); + // We could save the error into the trace during the end handler, but + // it won't have all the information that graphql-js adds to it later, + // like 'locations'. + }, + }; + }, + + didEncounterErrors(requestContext) { + // Search above for a comment about "didResolveSource" to see which + // of the pre-source-resolution errors we are intentionally avoiding. + if (!didResolveSource) return; + treeBuilder.didEncounterErrors(requestContext.errors); + didEnd(requestContext); + }, + }; + } + }; +}; + +// Helpers for producing traces. + +function defaultGenerateClientInfo({ request }: GraphQLRequestContext) { + // Default to using the `apollo-client-x` header fields if present. + // If none are present, fallback on the `clientInfo` query extension + // for backwards compatibility. + // The default value if neither header values nor query extension is + // set is the empty String for all fields (as per protobuf defaults) + if ( + request.http && + request.http.headers && + (request.http.headers.get(clientNameHeaderKey) || + request.http.headers.get(clientVersionHeaderKey) || + request.http.headers.get(clientReferenceIdHeaderKey)) + ) { + return { + clientName: request.http.headers.get(clientNameHeaderKey), + clientVersion: request.http.headers.get(clientVersionHeaderKey), + clientReferenceId: request.http.headers.get(clientReferenceIdHeaderKey), + }; + } else if (request.extensions && request.extensions.clientInfo) { + return request.extensions.clientInfo; + } else { + return {}; + } +} + +// Creates trace details from request variables, given a specification for modifying +// values of private or sensitive variables. +// The details will include all variable names and their (possibly hidden or modified) values. +// If sendVariableValues is {all: bool}, {none: bool} or {exceptNames: Array}, the option will act similarly to +// to the to-be-deprecated options.privateVariables, except that the redacted variable +// names will still be visible in the UI even if the values are hidden. +// If sendVariableValues is null or undefined, we default to the {none: true} case. +export function makeTraceDetails( + variables: Record, + sendVariableValues?: VariableValueOptions, + operationString?: string, +): Trace.Details { + const details = new Trace.Details(); + const variablesToRecord = (() => { + if (sendVariableValues && 'transform' in sendVariableValues) { + const originalKeys = Object.keys(variables); + try { + // Custom function to allow user to specify what variablesJson will look like + const modifiedVariables = sendVariableValues.transform({ + variables: variables, + operationString: operationString, + }); + return cleanModifiedVariables(originalKeys, modifiedVariables); + } catch (e) { + // If the custom function provided by the user throws an exception, + // change all the variable values to an appropriate error message. + return handleVariableValueTransformError(originalKeys); + } + } else { + return variables; + } + })(); + + // Note: we explicitly do *not* include the details.rawQuery field. The + // Engine web app currently does nothing with this other than store it in + // the database and offer it up via its GraphQL API, and sending it means + // that using calculateSignature to hide sensitive data in the query + // string is ineffective. + Object.keys(variablesToRecord).forEach(name => { + if ( + !sendVariableValues || + ('none' in sendVariableValues && sendVariableValues.none) || + ('all' in sendVariableValues && !sendVariableValues.all) || + ('exceptNames' in sendVariableValues && + // We assume that most users will have only a few variables values to hide, + // or will just set {none: true}; we can change this + // linear-time operation if it causes real performance issues. + sendVariableValues.exceptNames.includes(name)) || + ('onlyNames' in sendVariableValues && + !sendVariableValues.onlyNames.includes(name)) + ) { + // Special case for private variables. Note that this is a different + // representation from a variable containing the empty string, as that + // will be sent as '""'. + details.variablesJson![name] = ''; + } else { + try { + details.variablesJson![name] = + typeof variablesToRecord[name] === 'undefined' + ? '' + : JSON.stringify(variablesToRecord[name]); + } catch (e) { + details.variablesJson![name] = JSON.stringify( + '[Unable to convert value to JSON]', + ); + } + } + }); + return details; +} + +function handleVariableValueTransformError( + variableNames: string[], +): Record { + const modifiedVariables = Object.create(null); + variableNames.forEach(name => { + modifiedVariables[name] = '[PREDICATE_FUNCTION_ERROR]'; + }); + return modifiedVariables; +} + +// Helper for makeTraceDetails() to enforce that the keys of a modified 'variables' +// matches that of the original 'variables' +function cleanModifiedVariables( + originalKeys: Array, + modifiedVariables: Record, +): Record { + const cleanedVariables: Record = Object.create(null); + originalKeys.forEach(name => { + cleanedVariables[name] = modifiedVariables[name]; + }); + return cleanedVariables; +} + +export function makeHTTPRequestHeaders( + http: Trace.IHTTP, + headers: Headers, + sendHeaders?: SendValuesBaseOptions, +): void { + if ( + !sendHeaders || + ('none' in sendHeaders && sendHeaders.none) || + ('all' in sendHeaders && !sendHeaders.all) + ) { + return; + } + for (const [key, value] of headers) { + const lowerCaseKey = key.toLowerCase(); + if ( + ('exceptNames' in sendHeaders && + // We assume that most users only have a few headers to hide, or will + // just set {none: true} ; we can change this linear-time + // operation if it causes real performance issues. + sendHeaders.exceptNames.some(exceptHeader => { + // Headers are case-insensitive, and should be compared as such. + return exceptHeader.toLowerCase() === lowerCaseKey; + })) || + ('onlyNames' in sendHeaders && + !sendHeaders.onlyNames.some(header => { + return header.toLowerCase() === lowerCaseKey; + })) + ) { + continue; + } + + switch (key) { + case 'authorization': + case 'cookie': + case 'set-cookie': + break; + default: + http!.requestHeaders![key] = new Trace.HTTP.Values({ + value: [value], + }); + } + } +} diff --git a/packages/apollo-engine-reporting/src/treeBuilder.ts b/packages/apollo-engine-reporting/src/treeBuilder.ts index a10535bbe23..27bfe9376ba 100644 --- a/packages/apollo-engine-reporting/src/treeBuilder.ts +++ b/packages/apollo-engine-reporting/src/treeBuilder.ts @@ -1,10 +1,6 @@ import { GraphQLError, GraphQLResolveInfo, ResponsePath } from 'graphql'; import { Trace, google } from 'apollo-engine-reporting-protobuf'; -import { - PersistedQueryNotFoundError, - PersistedQueryNotSupportedError, -} from 'apollo-server-errors'; -import { InvalidGraphQLRequestError, Logger } from 'apollo-server-types'; +import { Logger } from 'apollo-server-types'; function internalError(message: string) { return new Error(`[internal apollo-server error] ${message}`); @@ -78,16 +74,8 @@ export class EngineReportingTreeBuilder { }; } - public didEncounterErrors(errors: GraphQLError[]) { + public didEncounterErrors(errors: readonly GraphQLError[]) { errors.forEach(err => { - if ( - err instanceof PersistedQueryNotFoundError || - err instanceof PersistedQueryNotSupportedError || - err instanceof InvalidGraphQLRequestError - ) { - return; - } - // This is an error from a federated service. We will already be reporting // it in the nested Trace in the query plan. // diff --git a/packages/apollo-engine-reporting/tsconfig.json b/packages/apollo-engine-reporting/tsconfig.json index ca382f1094c..ea64c712362 100644 --- a/packages/apollo-engine-reporting/tsconfig.json +++ b/packages/apollo-engine-reporting/tsconfig.json @@ -7,8 +7,8 @@ "include": ["src/**/*"], "exclude": ["**/__tests__", "**/__mocks__"], "references": [ - { "path": "../graphql-extensions" }, { "path": "../apollo-server-errors" }, { "path": "../apollo-server-types" }, + { "path": "../apollo-server-plugin-base" }, ] } diff --git a/packages/apollo-server-core/src/ApolloServer.ts b/packages/apollo-server-core/src/ApolloServer.ts index 720a9822a60..18181de0eb9 100644 --- a/packages/apollo-server-core/src/ApolloServer.ts +++ b/packages/apollo-server-core/src/ApolloServer.ts @@ -206,10 +206,6 @@ export class ApolloServerBase { this.parseOptions = parseOptions; this.context = context; - // Plugins will be instantiated if they aren't already, and this.plugins - // is populated accordingly. - this.ensurePluginInstantiation(plugins); - // While reading process.env is slow, a server should only be constructed // once per run, so we place the env check inside the constructor. If env // should be used outside of the constructor context, place it as a private @@ -369,6 +365,11 @@ export class ApolloServerBase { } else { throw new Error("Unexpected error: Unable to resolve a valid GraphQLSchema. Please file an issue with a reproduction of this error, if possible."); } + + // Plugins will be instantiated if they aren't already, and this.plugins + // is populated accordingly. + this.ensurePluginInstantiation(plugins); + } // used by integrations to synchronize the path with subscriptions, some @@ -518,39 +519,6 @@ export class ApolloServerBase { const extensions = []; - const schemaIsFederated = this.schemaIsFederated(schema); - const { engine } = this.config; - // Keep this extension second so it wraps everything, except error formatting - if (this.engineReportingAgent) { - if (schemaIsFederated) { - // XXX users can configure a federated Apollo Server to send metrics, but the - // Gateway should be responsible for that. It's possible that users are running - // their own gateway or running a federated service on its own. Nonetheless, in - // the likely case it was accidental, we warn users that they should only report - // metrics from the Gateway. - this.logger.warn( - "It looks like you're running a federated schema and you've configured your service " + - 'to report metrics to Apollo Graph Manager. You should only configure your Apollo gateway ' + - 'to report metrics to Apollo Graph Manager.', - ); - } - extensions.push(() => - this.engineReportingAgent!.newExtension(schemaHash), - ); - } else if (engine !== false && schemaIsFederated) { - // We haven't configured this app to use Engine directly. But it looks like - // we are a federated service backend, so we should be capable of including - // our trace in a response extension if we are asked to by the gateway. - const { - EngineFederatedTracingExtension, - } = require('apollo-engine-reporting'); - const rewriteError = - engine && typeof engine === 'object' ? engine.rewriteError : undefined; - extensions.push( - () => new EngineFederatedTracingExtension({ rewriteError }), - ); - } - // Note: doRunQuery will add its own extensions if you set tracing, // or cacheControl. extensions.push(...(_extensions || [])); @@ -781,6 +749,33 @@ export class ApolloServerBase { pluginsToInit.push(pluginCacheControl(cacheControlOptions)); } + const federatedSchema = this.schema && this.schemaIsFederated(this.schema); + const { engine } = this.config; + // Keep this extension second so it wraps everything, except error formatting + if (this.engineReportingAgent) { + if (federatedSchema) { + // XXX users can configure a federated Apollo Server to send metrics, but the + // Gateway should be responsible for that. It's possible that users are running + // their own gateway or running a federated service on its own. Nonetheless, in + // the likely case it was accidental, we warn users that they should only report + // metrics from the Gateway. + this.logger.warn( + "It looks like you're running a federated schema and you've configured your service " + + 'to report metrics to Apollo Graph Manager. You should only configure your Apollo gateway ' + + 'to report metrics to Apollo Graph Manager.', + ); + } + pluginsToInit.push(this.engineReportingAgent!.newPlugin()); + } else if (engine !== false && federatedSchema) { + // We haven't configured this app to use Engine directly. But it looks like + // we are a federated service backend, so we should be capable of including + // our trace in a response extension if we are asked to by the gateway. + const { federatedPlugin } = require('apollo-engine-reporting'); + const rewriteError = + engine && typeof engine === 'object' ? engine.rewriteError : undefined; + pluginsToInit.push(federatedPlugin({ rewriteError })); + } + pluginsToInit.push(...plugins); this.plugins = pluginsToInit.map(plugin => { @@ -869,6 +864,7 @@ export class ApolloServerBase { request, context: options.context || Object.create(null), cache: options.cache!, + metrics: {}, response: { http: { headers: new Headers(), diff --git a/packages/apollo-server-core/src/requestPipeline.ts b/packages/apollo-server-core/src/requestPipeline.ts index 7b882371665..09d4d4517fe 100644 --- a/packages/apollo-server-core/src/requestPipeline.ts +++ b/packages/apollo-server-core/src/requestPipeline.ts @@ -122,17 +122,22 @@ export async function processGraphQLRequest( // all of our own machinery will certainly set it now. const logger = requestContext.logger || console; + // If request context's `metrics` already exists, preserve it, but _ensure_ it + // exists there and shorthand it for use throughout this function. As of this + // comment, the sole known case where `metrics` already exists is when the + // `captureTraces` property is present and set to the result of the boolean + // `reporting` option on the legacy (V1) server options, here: + // https://git.io/Jfmsb. I suspect this disappears when this is the direct + // entry into request processing, rather than through, e.g. `runHttpQuery`. + const metrics = requestContext.metrics = + requestContext.metrics || Object.create(null); + const extensionStack = initializeExtensionStack(); (requestContext.context as any)._extensionStack = extensionStack; const dispatcher = initializeRequestListenerDispatcher(); await initializeDataSources(); - const metrics = requestContext.metrics || Object.create(null); - if (!requestContext.metrics) { - requestContext.metrics = metrics; - } - const request = requestContext.request; let { query, extensions } = request; diff --git a/packages/apollo-server-types/src/index.ts b/packages/apollo-server-types/src/index.ts index 9975f67fd48..3d02d315fd1 100644 --- a/packages/apollo-server-types/src/index.ts +++ b/packages/apollo-server-types/src/index.ts @@ -124,7 +124,7 @@ export interface GraphQLRequestContext> { */ readonly errors?: ReadonlyArray; - readonly metrics?: GraphQLRequestMetrics; + readonly metrics: GraphQLRequestMetrics; debug?: boolean; }