Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor: Introduce "tracing" plugin and switch request pipeline to use it. #3991

Merged
merged 15 commits into from
May 12, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ 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.

- _Nothing yet! Stay tuned!_
- `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)
abernix marked this conversation as resolved.
Show resolved Hide resolved

### v2.13.0

Expand Down
2 changes: 1 addition & 1 deletion package-lock.json

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

7 changes: 6 additions & 1 deletion packages/apollo-server-core/src/ApolloServer.ts
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,7 @@ import {

import { Headers } from 'apollo-server-env';
import { buildServiceDefinition } from '@apollographql/apollo-tools';
import { plugin as pluginTracing } from "apollo-tracing";
import { Logger, SchemaHash } from "apollo-server-types";
import { getEngineApiKey, getEngineGraphVariant } from "apollo-engine-reporting/dist/agent";

Expand Down Expand Up @@ -765,7 +766,11 @@ export class ApolloServerBase {
// Internal plugins should be added to `pluginsToInit` here.
// User's plugins, provided as an argument to this method, will be added
// at the end of that list so they take precedence.
// A follow-up commit will actually introduce this.

// If the user has enabled it explicitly, add our tracing lugin.
if (this.config.tracing) {
pluginsToInit.push(pluginTracing())
}

pluginsToInit.push(...plugins);
this.plugins = pluginsToInit.map(plugin => {
Expand Down
6 changes: 0 additions & 6 deletions packages/apollo-server-core/src/requestPipeline.ts
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@ import {
CacheControlExtension,
CacheControlExtensionOptions,
} from 'apollo-cache-control';
import { TracingExtension } from 'apollo-tracing';
import {
ApolloError,
fromGraphQLError,
Expand Down Expand Up @@ -98,7 +97,6 @@ export interface GraphQLRequestPipelineConfig<TContext> {
dataSources?: () => DataSources<TContext>;

extensions?: Array<() => GraphQLExtension>;
tracing?: boolean;
persistedQueries?: PersistedQueryOptions;
cacheControl?: CacheControlExtensionOptions;

Expand Down Expand Up @@ -651,10 +649,6 @@ export async function processGraphQLRequest<TContext>(
// objects.
const extensions = config.extensions ? config.extensions.map(f => f()) : [];

if (config.tracing) {
extensions.push(new TracingExtension());
}

if (config.cacheControl) {
cacheControlExtension = new CacheControlExtension(config.cacheControl);
extensions.push(cacheControlExtension);
Expand Down
11 changes: 5 additions & 6 deletions packages/apollo-tracing/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -12,14 +12,13 @@ This data can be consumed by [Apollo Graph Manager](https://www.apollographql.co

Apollo Server includes built-in support for tracing from version 1.1.0 onwards.

The only code change required is to add `tracing: true` to the options passed to the Apollo Server middleware function for your framework of choice. For example, for Express:
The only code change required is to add `tracing: true` to the options passed to the `ApolloServer` constructor options for your integration of choice. For example, for [`apollo-server-express`](https://npm.im/apollo-server-express):

```javascript
app.use('/graphql', bodyParser.json(), graphqlExpress({
const { ApolloServer } = require('apollo-server-express');

const server = new ApolloServer({
schema,
context: {},
tracing: true,
}));
});
```

> If you are using `express-graphql`, we recommend you switch to Apollo Server. Both `express-graphql` and Apollo Server are based on the [`graphql-js`](https://github.com/graphql/graphql-js) reference implementation, and switching should only require changing a few lines of code.
2 changes: 1 addition & 1 deletion packages/apollo-tracing/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,7 @@
},
"dependencies": {
"apollo-server-env": "file:../apollo-server-env",
"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"
Expand Down
182 changes: 96 additions & 86 deletions packages/apollo-tracing/src/index.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,11 @@
import {
ResponsePath,
responsePathAsArray,
GraphQLResolveInfo,
GraphQLType,
} from 'graphql';
import { ApolloServerPlugin } from "apollo-server-plugin-base";

import { GraphQLExtension } from 'graphql-extensions';
const { PACKAGE_NAME } = require("../package.json").name;

export interface TracingFormat {
version: 1;
Expand Down Expand Up @@ -33,94 +33,104 @@ interface ResolverCall {
endOffset?: HighResolutionTime;
}

export class TracingExtension<TContext = any>
implements GraphQLExtension<TContext> {
private startWallTime?: Date;
private endWallTime?: Date;
private startHrTime?: HighResolutionTime;
private duration?: HighResolutionTime;

private resolverCalls: ResolverCall[] = [];

public requestDidStart() {
this.startWallTime = new Date();
this.startHrTime = process.hrtime();
}

public executionDidStart() {
// It's a little odd that we record the end time after execution rather than
// at the end of the whole request, but because we need to include our
// formatted trace in the request itself, we have to record it before the
// request is over! It's also odd that we don't do traces for parse or
// validation errors, but runQuery doesn't currently support that, as
// format() is only invoked after execution.
return () => {
this.duration = process.hrtime(this.startHrTime);
this.endWallTime = new Date();
};
}

public willResolveField(
_source: any,
_args: { [argName: string]: any },
_context: TContext,
info: GraphQLResolveInfo,
) {
const resolverCall: ResolverCall = {
path: info.path,
fieldName: info.fieldName,
parentType: info.parentType,
returnType: info.returnType,
startOffset: process.hrtime(this.startHrTime),
};
export const plugin = (_futureOptions = {}) => (): ApolloServerPlugin => ({
requestDidStart() {
let startWallTime: Date | undefined;
let endWallTime: Date | undefined;
let startHrTime: HighResolutionTime | undefined;
let duration: HighResolutionTime | undefined;
const resolverCalls: ResolverCall[] = [];

this.resolverCalls.push(resolverCall);
startWallTime = new Date();
startHrTime = process.hrtime();
abernix marked this conversation as resolved.
Show resolved Hide resolved

return () => {
resolverCall.endOffset = process.hrtime(this.startHrTime);
};
}

public format(): [string, TracingFormat] | undefined {
// In the event that we are called prior to the initialization of critical
// date metrics, we'll return undefined to signal that the extension did not
// format properly. Any undefined extension results are simply purged by
// the graphql-extensions module.
if (
typeof this.startWallTime === 'undefined' ||
typeof this.endWallTime === 'undefined' ||
typeof this.duration === 'undefined'
) {
return;
}

return [
'tracing',
{
version: 1,
startTime: this.startWallTime.toISOString(),
endTime: this.endWallTime.toISOString(),
duration: durationHrTimeToNanos(this.duration),
execution: {
resolvers: this.resolverCalls.map(resolverCall => {
const startOffset = durationHrTimeToNanos(resolverCall.startOffset);
const duration = resolverCall.endOffset
? durationHrTimeToNanos(resolverCall.endOffset) - startOffset
: 0;
return {
path: [...responsePathAsArray(resolverCall.path)],
parentType: resolverCall.parentType.toString(),
fieldName: resolverCall.fieldName,
returnType: resolverCall.returnType.toString(),
startOffset,
duration,
};
}),
return {
executionDidStart: () => ({
// It's a little odd that we record the end time after execution rather
// than at the end of the whole request, but because we need to include
// our formatted trace in the request itself, we have to record it
// before the request is over!

// Historically speaking: It's WAS odd that we don't do traces for parse
// or validation errors. Reason being: at the time that this was written
// (now a plugin but originally an extension)). That was the case
// because runQuery DIDN'T (again, at the time, when it was an
// extension) support that since format() was only invoked after
// execution.
executionDidEnd: () => {
duration = process.hrtime(startHrTime);
endWallTime = new Date();
},

willResolveField({ info }) {
const resolverCall: ResolverCall = {
path: info.path,
fieldName: info.fieldName,
parentType: info.parentType,
returnType: info.returnType,
startOffset: process.hrtime(startHrTime),
};

resolverCalls.push(resolverCall);

return () => {
resolverCall.endOffset = process.hrtime(startHrTime);
};
},
}),

willSendResponse({ response }) {
// In the event that we are called prior to the initialization of
// critical date metrics, we'll return undefined to signal that the
// extension did not format properly. Any undefined extension
// results are simply purged by the graphql-extensions module.
if (
typeof startWallTime === 'undefined' ||
typeof endWallTime === 'undefined' ||
typeof duration === 'undefined'
) {
return;
}

const extensions =
response.extensions || (response.extensions = Object.create(null));

// Be defensive and make sure nothing else (other plugin, etc.) has
// already used the `tracing` property on `extensions`.
if (typeof extensions.tracing !== 'undefined') {
throw new Error(PACKAGE_NAME + ": Could not add `tracing` to " +
"`extensions` since `tracing` was unexpectedly already present.");
}

// Set the extensions.
extensions.tracing = {
version: 1,
startTime: startWallTime.toISOString(),
endTime: endWallTime.toISOString(),
duration: durationHrTimeToNanos(duration),
execution: {
resolvers: resolverCalls.map(resolverCall => {
const startOffset = durationHrTimeToNanos(
resolverCall.startOffset,
);
const duration = resolverCall.endOffset
? durationHrTimeToNanos(resolverCall.endOffset) - startOffset
: 0;
return {
path: [...responsePathAsArray(resolverCall.path)],
abernix marked this conversation as resolved.
Show resolved Hide resolved
parentType: resolverCall.parentType.toString(),
fieldName: resolverCall.fieldName,
returnType: resolverCall.returnType.toString(),
startOffset,
duration,
};
}),
},
};
},
];
}
}
};
},
})

type HighResolutionTime = [number, number];

Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-tracing/tsconfig.json
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,6 @@
"include": ["src/**/*"],
"exclude": ["**/__tests__", "**/__mocks__"],
"references": [
{ "path": "../graphql-extensions" },
{ "path": "../apollo-server-plugin-base" },
]
}