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

Defer and cache calculation of Engine reporting signature. #2670

Merged
merged 3 commits into from
May 22, 2019
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 packages/apollo-cache-control/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-cache-control",
"version": "0.6.0",
"version": "0.7.0-alpha.0",
"description": "A GraphQL extension for cache control",
"main": "./dist/index.js",
"types": "./dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-engine-reporting/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-engine-reporting",
"version": "1.1.0",
"version": "1.2.0-alpha.0",
"description": "Send reports about your GraphQL services to Apollo Engine",
"main": "./dist/index.js",
"types": "./dist/index.d.ts",
Expand Down
13 changes: 13 additions & 0 deletions packages/apollo-engine-reporting/src/__tests__/agent.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
import { signatureCacheKey } from '../agent';

describe('signature cache key', () => {
it('generates without the operationName', () => {
expect(signatureCacheKey('abc123', '')).toEqual('abc123');
});

it('generates without the operationName', () => {
expect(signatureCacheKey('abc123', 'myOperation')).toEqual(
'abc123:myOperation',
);
});
});
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,11 @@ test('trace construction', async () => {
enableGraphQLExtensions(schema);

const traces: Array<any> = [];
function addTrace(signature: string, operationName: string, trace: Trace) {
function addTrace(
signature: Promise<string | null>,
operationName: string,
trace: Trace,
) {
traces.push({ signature, operationName, trace });
}

Expand Down
131 changes: 129 additions & 2 deletions packages/apollo-engine-reporting/src/agent.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@ import {
GraphQLRequestContext,
GraphQLServiceContext,
} from 'apollo-server-core/dist/requestPipelineAPI';
import { InMemoryLRUCache } from 'apollo-server-caching';
import { defaultEngineReportingSignature } from 'apollo-graphql';

export interface ClientInfo {
clientName?: string;
Expand Down Expand Up @@ -128,6 +130,14 @@ export interface EngineReportingOptions<TContext> {
generateClientInfo?: GenerateClientInfo<TContext>;
}

export interface AddTraceArgs {
trace: Trace;
operationName: string;
queryHash: string;
queryString?: string;
documentAST?: DocumentNode;
}

const serviceHeaderDefaults = {
hostname: os.hostname(),
// tslint:disable-next-line no-var-requires
Expand All @@ -149,6 +159,7 @@ export class EngineReportingAgent<TContext = any> {
private sendReportsImmediately?: boolean;
private stopped: boolean = false;
private reportHeader: ReportHeader;
private signatureCache: InMemoryLRUCache<string>;

public constructor(
options: EngineReportingOptions<TContext> = {},
Expand All @@ -162,6 +173,11 @@ export class EngineReportingAgent<TContext = any> {
);
}

// Since calculating the signature for Engine reporting is potentially an
// expensive operation, we'll cache the signatures we generate and re-use
// them based on repeated traces for the same `queryHash`.
this.signatureCache = createSignatureCache();

this.reportHeader = new ReportHeader({
...serviceHeaderDefaults,
schemaHash,
Expand Down Expand Up @@ -196,7 +212,61 @@ export class EngineReportingAgent<TContext = any> {
);
}

public addTrace(signature: string, operationName: string, trace: Trace) {
private async getTraceSignature({
queryHash,
operationName,
documentAST,
queryString,
}: {
queryHash: string;
operationName: string;
documentAST?: DocumentNode;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If this is always either a document AST or a string, should this be a single DocumentNode | string argument?

queryString?: string;
}): Promise<string> {
if (!documentAST && !queryString) {
// This shouldn't happen: one of those options must be passed to runQuery.
throw new Error('No queryString or parsedQuery?');
}

const cacheKey = signatureCacheKey(queryHash, operationName);

// If we didn't have the signature in the cache, we'll resort to
// calculating it asynchronously. The `addTrace` method will
// `await` the `signature` if it's a Promise, prior to putting it
// on the stack of traces to deliver to the cloud.
const cachedSignature = await this.signatureCache.get(cacheKey);

if (cachedSignature) {
return cachedSignature;
}

if (!documentAST) {
// We didn't get an AST, possibly because of a parse failure. Let's just
// use the full query string.
//
// XXX This does mean that even if you use a calculateSignature which
// 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;
}

const generatedSignature = (this.options.calculateSignature ||
defaultEngineReportingSignature)(documentAST, operationName);

// Intentionally not awaited so the cache can be written to at leisure.
this.signatureCache.set(cacheKey, generatedSignature);

return generatedSignature;
}

public async addTrace({
trace,
queryHash,
documentAST,
operationName,
queryString,
}: AddTraceArgs): Promise<void> {
// Ignore traces that come in after stop().
if (this.stopped) {
return;
Expand All @@ -208,6 +278,13 @@ export class EngineReportingAgent<TContext = any> {
}
const encodedTrace = Trace.encode(trace).finish();

const signature = await this.getTraceSignature({
queryHash,
documentAST,
queryString,
operationName,
});

const statsReportKey = `# ${operationName || '-'}\n${signature}`;
if (!this.report.tracesPerQuery.hasOwnProperty(statsReportKey)) {
this.report.tracesPerQuery[statsReportKey] = new Traces();
Expand All @@ -226,7 +303,7 @@ export class EngineReportingAgent<TContext = any> {
this.reportSize >=
(this.options.maxUncompressedReportSize || 4 * 1024 * 1024)
) {
this.sendReportAndReportErrors();
await this.sendReportAndReportErrors();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The addition of this await shouldn't change execution dynamics (and I haven't changed what sendReportAndReportErrors does) since addTrace itself is never awaited, but the nested un-awaited Promise seemed a bit too wily for my liking.

}
}

Expand Down Expand Up @@ -351,3 +428,53 @@ export class EngineReportingAgent<TContext = any> {
this.reportSize = 0;
}
}

function createSignatureCache(): InMemoryLRUCache<string> {
let lastSignatureCacheWarn: Date;
let lastSignatureCacheDisposals: number = 0;
return new InMemoryLRUCache<string>({
// Calculate the length of cache objects by the JSON.stringify byteLength.
sizeCalculator(obj) {
return Buffer.byteLength(JSON.stringify(obj), 'utf8');
},
// 3MiB limit, very much approximately since we can't be sure how V8 might
// be storing these strings internally. Though this should be enough to
// store a fair amount of operation signatures (~10000?), depending on their
// overall complexity. A future version of this might expose some
// configuration option to grow the cache, but ideally, we could do that
// dynamically based on the resources available to the server, and not add
// more configuration surface area. Hopefully the warning message will allow
// us to evaluate the need with more validated input from those that receive
// it.
maxSize: Math.pow(2, 20) * 3,
onDispose() {
// Count the number of disposals between warning messages.
lastSignatureCacheDisposals++;

// Only show a message warning about the high turnover every 60 seconds.
if (
!lastSignatureCacheWarn ||
new Date().getTime() - lastSignatureCacheWarn.getTime() > 60000
) {
// Log the time that we last displayed the message.
lastSignatureCacheWarn = new Date();
console.warn(
[
'This server is processing a high number of unique operations. ',
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, this is a nice touch!

`A total of ${lastSignatureCacheDisposals} records have been `,
'ejected from the Engine Reporting signature cache in the past ',
'interval. If you see this warning frequently, please open an ',
'issue on the Apollo Server repository.',
].join(''),
);

// Reset the disposal counter for the next message interval.
lastSignatureCacheDisposals = 0;
}
},
});
}

export function signatureCacheKey(queryHash: string, operationName: string) {
return `${queryHash}${operationName && ':' + operationName}`;
}
47 changes: 19 additions & 28 deletions packages/apollo-engine-reporting/src/extension.ts
Original file line number Diff line number Diff line change
Expand Up @@ -11,8 +11,11 @@ import {
import { GraphQLExtension, EndHandler } from 'graphql-extensions';
import { Trace, google } from 'apollo-engine-reporting-protobuf';

import { EngineReportingOptions, GenerateClientInfo } from './agent';
import { defaultEngineReportingSignature } from 'apollo-graphql';
import {
EngineReportingOptions,
GenerateClientInfo,
AddTraceArgs,
} from './agent';
import { GraphQLRequestContext } from 'apollo-server-core/dist/requestPipelineAPI';

const clientNameHeaderKey = 'apollographql-client-name';
Expand Down Expand Up @@ -47,16 +50,12 @@ export class EngineReportingExtension<TContext = any>
private queryString?: string;
private documentAST?: DocumentNode;
private options: EngineReportingOptions<TContext>;
private addTrace: (
signature: string,
operationName: string,
trace: Trace,
) => void;
private addTrace: (args: AddTraceArgs) => Promise<void>;
private generateClientInfo: GenerateClientInfo<TContext>;

public constructor(
options: EngineReportingOptions<TContext>,
addTrace: (signature: string, operationName: string, trace: Trace) => void,
addTrace: (args: AddTraceArgs) => Promise<void>,
) {
this.options = {
...options,
Expand Down Expand Up @@ -102,14 +101,18 @@ export class EngineReportingExtension<TContext = any>
variables?: Record<string, any>;
context: TContext;
extensions?: Record<string, any>;
requestContext: WithRequired<GraphQLRequestContext<TContext>, 'metrics'>;
requestContext: WithRequired<
GraphQLRequestContext<TContext>,
'metrics' | 'queryHash'
>;
}): EndHandler {
this.trace.startTime = dateToTimestamp(new Date());
this.startHrTime = process.hrtime();

// 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;

Expand Down Expand Up @@ -223,26 +226,14 @@ export class EngineReportingExtension<TContext = any>
.responseCacheHit;

const operationName = this.operationName || '';
let signature;
if (this.documentAST) {
const calculateSignature =
this.options.calculateSignature || defaultEngineReportingSignature;
signature = calculateSignature(this.documentAST, operationName);
} else if (this.queryString) {
// We didn't get an AST, possibly because of a parse failure. Let's just
// use the full query string.
//
// XXX This does mean that even if you use a calculateSignature which
// hides literals, you might end up sending literals for queries
// that fail parsing or validation. Provide some way to mask them
// anyway?
signature = this.queryString;
} else {
// This shouldn't happen: one of those options must be passed to runQuery.
throw new Error('No queryString or parsedQuery?');
}

this.addTrace(signature, operationName, this.trace);
this.addTrace({
operationName,
queryHash,
documentAST: this.documentAST,
queryString: this.queryString || '',
trace: this.trace,
});
};
}

Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-azure-functions/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-azure-functions",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Azure Functions",
"keywords": [
"GraphQL",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-cloud-functions/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-cloud-functions",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Google Cloud Functions",
"keywords": [
"GraphQL",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-cloudflare/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-cloudflare",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Cloudflare workers",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-core/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-core",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Core engine for Apollo GraphQL server",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
5 changes: 4 additions & 1 deletion packages/apollo-server-core/src/requestPipeline.ts
Original file line number Diff line number Diff line change
Expand Up @@ -197,7 +197,10 @@ export async function processGraphQLRequest<TContext>(
context: requestContext.context,
persistedQueryHit: metrics.persistedQueryHit,
persistedQueryRegister: metrics.persistedQueryRegister,
requestContext,
requestContext: requestContext as WithRequired<
typeof requestContext,
'metrics' | 'queryHash'
>,
});

try {
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-express/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-express",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Express and Connect",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-fastify/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-fastify",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Fastify",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-hapi/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-hapi",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Hapi",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-integration-testsuite/package.json
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
{
"name": "apollo-server-integration-testsuite",
"private": true,
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Apollo Server Integrations testsuite",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
2 changes: 1 addition & 1 deletion packages/apollo-server-koa/package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "apollo-server-koa",
"version": "2.5.0",
"version": "2.6.0-alpha.0",
"description": "Production-ready Node.js GraphQL server for Koa",
"main": "dist/index.js",
"types": "dist/index.d.ts",
Expand Down
Loading